Skip to content

Commit 37a9aa6

Browse files
anarazelanarazel
committed
Fix performance regression from session statistics.
Session statistics, as introduced by 960869d, had several shortcomings: - an additional GetCurrentTimestamp() call that also impaired the accuracy of the data collected This can be avoided by passing the current timestamp we already have in pgstat_report_stat(). - an additional statistics UDP packet sent every 500ms This is solved by adding the new statistics to PgStat_MsgTabstat. This is conceptually ugly, because session statistics are not table statistics. But the struct already contains data unrelated to tables, so there is not much damage done. Connection and disconnection are reported in separate messages, which reduces the number of additional messages to two messages per session and a slight increase in PgStat_MsgTabstat size (but the same number of table stats fit). - Session time computation could overflow on systems where long is 32 bit. Reported-By: Andres Freund <andres@anarazel.de> Author: Andres Freund <andres@anarazel.de> Author: Laurenz Albe <laurenz.albe@cybertec.at> Discussion: https://postgr.es/m/20210801205501.nyxzxoelqoo4x2qc%40alap3.anarazel.de Backpatch: 14-, where the feature was introduced.
1 parent dc89914 commit 37a9aa6

File tree

5 files changed

+158
-80
lines changed

5 files changed

+158
-80
lines changed

‎src/backend/postmaster/pgstat.c

Lines changed: 129 additions & 66 deletions
Original file line numberDiff line numberDiff line change
@@ -246,6 +246,7 @@ static int pgStatXactCommit = 0;
246246
static int pgStatXactRollback = 0;
247247
PgStat_Counter pgStatBlockReadTime = 0;
248248
PgStat_Counter pgStatBlockWriteTime = 0;
249+
static PgStat_Counter pgLastSessionReportTime = 0;
249250
PgStat_Counter pgStatActiveTime = 0;
250251
PgStat_Counter pgStatTransactionIdleTime = 0;
251252
SessionEndType pgStatSessionEndCause = DISCONNECT_NORMAL;
@@ -330,11 +331,12 @@ static bool pgstat_db_requested(Oid databaseid);
330331
static PgStat_StatReplSlotEntry *pgstat_get_replslot_entry(NameData name, bool create_it);
331332
static void pgstat_reset_replslot(PgStat_StatReplSlotEntry *slotstats, TimestampTz ts);
332333

333-
static void pgstat_send_tabstat(PgStat_MsgTabstat *tsmsg);
334+
static void pgstat_send_tabstat(PgStat_MsgTabstat *tsmsg, TimestampTz now);
334335
static void pgstat_send_funcstats(void);
335336
static void pgstat_send_slru(void);
336337
static HTAB *pgstat_collect_oids(Oid catalogid, AttrNumber anum_oid);
337-
static void pgstat_send_connstats(bool disconnect, TimestampTz last_report);
338+
static bool pgstat_should_report_connstat(void);
339+
static void pgstat_report_disconnect(Oid dboid);
338340

339341
static PgStat_TableStatus *get_tabstat_entry(Oid rel_id, bool isshared);
340342

@@ -366,7 +368,8 @@ static void pgstat_recv_funcpurge(PgStat_MsgFuncpurge *msg, int len);
366368
static void pgstat_recv_recoveryconflict(PgStat_MsgRecoveryConflict *msg, int len);
367369
static void pgstat_recv_deadlock(PgStat_MsgDeadlock *msg, int len);
368370
static void pgstat_recv_checksum_failure(PgStat_MsgChecksumFailure *msg, int len);
369-
static void pgstat_recv_connstat(PgStat_MsgConn *msg, int len);
371+
static void pgstat_recv_connect(PgStat_MsgConnect *msg, int len);
372+
static void pgstat_recv_disconnect(PgStat_MsgDisconnect *msg, int len);
370373
static void pgstat_recv_replslot(PgStat_MsgReplSlot *msg, int len);
371374
static void pgstat_recv_tempfile(PgStat_MsgTempFile *msg, int len);
372375

@@ -890,12 +893,11 @@ pgstat_report_stat(bool disconnect)
890893
!TimestampDifferenceExceeds(last_report, now, PGSTAT_STAT_INTERVAL))
891894
return;
892895

893-
/* for backends, send connection statistics */
894-
if (MyBackendType == B_BACKEND)
895-
pgstat_send_connstats(disconnect, last_report);
896-
897896
last_report = now;
898897

898+
if (disconnect)
899+
pgstat_report_disconnect(MyDatabaseId);
900+
899901
/*
900902
* Destroy pgStatTabHash before we start invalidating PgStat_TableEntry
901903
* entries it points to. (Should we fail partway through the loop below,
@@ -947,7 +949,7 @@ pgstat_report_stat(bool disconnect)
947949
sizeof(PgStat_TableCounts));
948950
if (++this_msg->m_nentries >= PGSTAT_NUM_TABENTRIES)
949951
{
950-
pgstat_send_tabstat(this_msg);
952+
pgstat_send_tabstat(this_msg, now);
951953
this_msg->m_nentries = 0;
952954
}
953955
}
@@ -959,13 +961,14 @@ pgstat_report_stat(bool disconnect)
959961

960962
/*
961963
* Send partial messages. Make sure that any pending xact commit/abort
962-
* gets counted, even if there are no table stats to send.
964+
* and connection stats get counted, even if there are no table stats to
965+
* send.
963966
*/
964967
if (regular_msg.m_nentries > 0 ||
965-
pgStatXactCommit > 0 || pgStatXactRollback > 0)
966-
pgstat_send_tabstat(&regular_msg);
968+
pgStatXactCommit > 0 || pgStatXactRollback > 0 || disconnect)
969+
pgstat_send_tabstat(&regular_msg, now);
967970
if (shared_msg.m_nentries > 0)
968-
pgstat_send_tabstat(&shared_msg);
971+
pgstat_send_tabstat(&shared_msg, now);
969972

970973
/* Now, send function statistics */
971974
pgstat_send_funcstats();
@@ -981,7 +984,7 @@ pgstat_report_stat(bool disconnect)
981984
* Subroutine for pgstat_report_stat: finish and send a tabstat message
982985
*/
983986
static void
984-
pgstat_send_tabstat(PgStat_MsgTabstat *tsmsg)
987+
pgstat_send_tabstat(PgStat_MsgTabstat *tsmsg, TimestampTz now)
985988
{
986989
int n;
987990
int len;
@@ -1000,17 +1003,44 @@ pgstat_send_tabstat(PgStat_MsgTabstat *tsmsg)
10001003
tsmsg->m_xact_rollback = pgStatXactRollback;
10011004
tsmsg->m_block_read_time = pgStatBlockReadTime;
10021005
tsmsg->m_block_write_time = pgStatBlockWriteTime;
1006+
1007+
if (pgstat_should_report_connstat())
1008+
{
1009+
long secs;
1010+
int usecs;
1011+
1012+
/*
1013+
* pgLastSessionReportTime is initialized to MyStartTimestamp by
1014+
* pgstat_report_connect().
1015+
*/
1016+
TimestampDifference(pgLastSessionReportTime, now, &secs, &usecs);
1017+
pgLastSessionReportTime = now;
1018+
tsmsg->m_session_time = (PgStat_Counter) secs * 1000000 + usecs;
1019+
tsmsg->m_active_time = pgStatActiveTime;
1020+
tsmsg->m_idle_in_xact_time = pgStatTransactionIdleTime;
1021+
}
1022+
else
1023+
{
1024+
tsmsg->m_session_time = 0;
1025+
tsmsg->m_active_time = 0;
1026+
tsmsg->m_idle_in_xact_time = 0;
1027+
}
10031028
pgStatXactCommit = 0;
10041029
pgStatXactRollback = 0;
10051030
pgStatBlockReadTime = 0;
10061031
pgStatBlockWriteTime = 0;
1032+
pgStatActiveTime = 0;
1033+
pgStatTransactionIdleTime = 0;
10071034
}
10081035
else
10091036
{
10101037
tsmsg->m_xact_commit = 0;
10111038
tsmsg->m_xact_rollback = 0;
10121039
tsmsg->m_block_read_time = 0;
10131040
tsmsg->m_block_write_time = 0;
1041+
tsmsg->m_session_time = 0;
1042+
tsmsg->m_active_time = 0;
1043+
tsmsg->m_idle_in_xact_time = 0;
10141044
}
10151045

10161046
n = tsmsg->m_nentries;
@@ -1378,49 +1408,6 @@ pgstat_drop_relation(Oid relid)
13781408
}
13791409
#endif /* NOT_USED */
13801410

1381-
1382-
/* ----------
1383-
* pgstat_send_connstats() -
1384-
*
1385-
* Tell the collector about session statistics.
1386-
* The parameter "disconnect" will be true when the backend exits.
1387-
* "last_report" is the last time we were called (0 if never).
1388-
* ----------
1389-
*/
1390-
static void
1391-
pgstat_send_connstats(bool disconnect, TimestampTz last_report)
1392-
{
1393-
PgStat_MsgConn msg;
1394-
long secs;
1395-
int usecs;
1396-
1397-
if (pgStatSock == PGINVALID_SOCKET || !pgstat_track_counts)
1398-
return;
1399-
1400-
pgstat_setheader(&msg.m_hdr, PGSTAT_MTYPE_CONNECTION);
1401-
msg.m_databaseid = MyDatabaseId;
1402-
1403-
/* session time since the last report */
1404-
TimestampDifference(((last_report == 0) ? MyStartTimestamp : last_report),
1405-
GetCurrentTimestamp(),
1406-
&secs, &usecs);
1407-
msg.m_session_time = secs * 1000000 + usecs;
1408-
1409-
msg.m_disconnect = disconnect ? pgStatSessionEndCause : DISCONNECT_NOT_YET;
1410-
1411-
msg.m_active_time = pgStatActiveTime;
1412-
pgStatActiveTime = 0;
1413-
1414-
msg.m_idle_in_xact_time = pgStatTransactionIdleTime;
1415-
pgStatTransactionIdleTime = 0;
1416-
1417-
/* report a new session only the first time */
1418-
msg.m_count = (last_report == 0) ? 1 : 0;
1419-
1420-
pgstat_send(&msg, sizeof(PgStat_MsgConn));
1421-
}
1422-
1423-
14241411
/* ----------
14251412
* pgstat_reset_counters() -
14261413
*
@@ -1759,6 +1746,63 @@ pgstat_report_tempfile(size_t filesize)
17591746
pgstat_send(&msg, sizeof(msg));
17601747
}
17611748

1749+
/* --------
1750+
* pgstat_report_connect() -
1751+
*
1752+
* Tell the collector about a new connection.
1753+
* --------
1754+
*/
1755+
void
1756+
pgstat_report_connect(Oid dboid)
1757+
{
1758+
PgStat_MsgConnect msg;
1759+
1760+
if (!pgstat_should_report_connstat())
1761+
return;
1762+
1763+
pgLastSessionReportTime = MyStartTimestamp;
1764+
1765+
pgstat_setheader(&msg.m_hdr, PGSTAT_MTYPE_CONNECT);
1766+
msg.m_databaseid = MyDatabaseId;
1767+
pgstat_send(&msg, sizeof(PgStat_MsgConnect));
1768+
}
1769+
1770+
/* --------
1771+
* pgstat_report_disconnect() -
1772+
*
1773+
* Tell the collector about a disconnect.
1774+
* --------
1775+
*/
1776+
static void
1777+
pgstat_report_disconnect(Oid dboid)
1778+
{
1779+
PgStat_MsgDisconnect msg;
1780+
1781+
if (!pgstat_should_report_connstat())
1782+
return;
1783+
1784+
pgstat_setheader(&msg.m_hdr, PGSTAT_MTYPE_DISCONNECT);
1785+
msg.m_databaseid = MyDatabaseId;
1786+
msg.m_cause = pgStatSessionEndCause;
1787+
pgstat_send(&msg, sizeof(PgStat_MsgDisconnect));
1788+
}
1789+
1790+
/* --------
1791+
* pgstat_should_report_connstats() -
1792+
*
1793+
* We report session statistics only for normal backend processes. Parallel
1794+
* workers run in parallel, so they don't contribute to session times, even
1795+
* though they use CPU time. Walsender processes could be considered here,
1796+
* but they have different session characteristics from normal backends (for
1797+
* example, they are always "active"), so they would skew session statistics.
1798+
* ----------
1799+
*/
1800+
static bool
1801+
pgstat_should_report_connstat(void)
1802+
{
1803+
return MyBackendType == B_BACKEND;
1804+
}
1805+
17621806
/* ----------
17631807
* pgstat_report_replslot() -
17641808
*
@@ -3465,8 +3509,12 @@ PgstatCollectorMain(int argc, char *argv[])
34653509
pgstat_recv_replslot(&msg.msg_replslot, len);
34663510
break;
34673511

3468-
case PGSTAT_MTYPE_CONNECTION:
3469-
pgstat_recv_connstat(&msg.msg_conn, len);
3512+
case PGSTAT_MTYPE_CONNECT:
3513+
pgstat_recv_connect(&msg.msg_connect, len);
3514+
break;
3515+
3516+
case PGSTAT_MTYPE_DISCONNECT:
3517+
pgstat_recv_disconnect(&msg.msg_disconnect, len);
34703518
break;
34713519

34723520
default:
@@ -4904,6 +4952,10 @@ pgstat_recv_tabstat(PgStat_MsgTabstat *msg, int len)
49044952
dbentry->n_block_read_time += msg->m_block_read_time;
49054953
dbentry->n_block_write_time += msg->m_block_write_time;
49064954

4955+
dbentry->total_session_time += msg->m_session_time;
4956+
dbentry->total_active_time += msg->m_active_time;
4957+
dbentry->total_idle_in_xact_time += msg->m_idle_in_xact_time;
4958+
49074959
/*
49084960
* Process all table entries in the message.
49094961
*/
@@ -5568,23 +5620,34 @@ pgstat_recv_replslot(PgStat_MsgReplSlot *msg, int len)
55685620
}
55695621

55705622
/* ----------
5571-
* pgstat_recv_connstat() -
5623+
* pgstat_recv_connect() -
55725624
*
5573-
* Process connection information.
5625+
* Process a CONNECT message.
55745626
* ----------
55755627
*/
55765628
static void
5577-
pgstat_recv_connstat(PgStat_MsgConn *msg, int len)
5629+
pgstat_recv_connect(PgStat_MsgConnect *msg, int len)
55785630
{
55795631
PgStat_StatDBEntry *dbentry;
55805632

55815633
dbentry = pgstat_get_db_entry(msg->m_databaseid, true);
5634+
dbentry->n_sessions++;
5635+
}
55825636

5583-
dbentry->n_sessions += msg->m_count;
5584-
dbentry->total_session_time += msg->m_session_time;
5585-
dbentry->total_active_time += msg->m_active_time;
5586-
dbentry->total_idle_in_xact_time += msg->m_idle_in_xact_time;
5587-
switch (msg->m_disconnect)
5637+
/* ----------
5638+
* pgstat_recv_disconnect() -
5639+
*
5640+
* Process a DISCONNECT message.
5641+
* ----------
5642+
*/
5643+
static void
5644+
pgstat_recv_disconnect(PgStat_MsgDisconnect *msg, int len)
5645+
{
5646+
PgStat_StatDBEntry *dbentry;
5647+
5648+
dbentry = pgstat_get_db_entry(msg->m_databaseid, true);
5649+
5650+
switch (msg->m_cause)
55885651
{
55895652
case DISCONNECT_NOT_YET:
55905653
case DISCONNECT_NORMAL:

‎src/backend/tcop/postgres.c

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4116,6 +4116,8 @@ PostgresMain(int argc, char *argv[],
41164116
if (IsUnderPostmaster && Log_disconnections)
41174117
on_proc_exit(log_disconnections, 0);
41184118

4119+
pgstat_report_connect(MyDatabaseId);
4120+
41194121
/* Perform initialization specific to a WAL sender process. */
41204122
if (am_walsender)
41214123
InitWalSender();

‎src/backend/utils/activity/backend_status.c

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -590,9 +590,9 @@ pgstat_report_activity(BackendState state, const char *cmd_str)
590590

591591
if (beentry->st_state == STATE_RUNNING ||
592592
beentry->st_state == STATE_FASTPATH)
593-
pgstat_count_conn_active_time(secs * 1000000 + usecs);
593+
pgstat_count_conn_active_time((PgStat_Counter) secs * 1000000 + usecs);
594594
else
595-
pgstat_count_conn_txn_idle_time(secs * 1000000 + usecs);
595+
pgstat_count_conn_txn_idle_time((PgStat_Counter) secs * 1000000 + usecs);
596596
}
597597

598598
/*

0 commit comments

Comments
 (0)