Skip to content

Commit 5cbbe70

Browse files
committed
Flush the IO statistics of active WAL senders more frequently
WAL senders do not flush their statistics until they exit, limiting the monitoring possible for live processes. This is penalizing when WAL senders are running for a long time, like in streaming or logical replication setups, because it is not possible to know the amount of IO they generate while running. This commit makes WAL senders more aggressive with their statistics flush, using an internal of 1 second, with the flush timing calculated based on the existing GetCurrentTimestamp() done before the sleeps done to wait for some activity. Note that the sleep done for logical and physical WAL senders happens in two different code paths, so the stats flushes need to happen in these two places. One test is added for the physical WAL sender case, and one for the logical WAL sender case. This can be done in a stable fashion by relying on the WAL generated by the TAP tests in combination with a stats reset while a server is running, but only on HEAD as WAL data has been added to pg_stat_io in a051e71. This issue exists since a9c70b4 and the introduction of pg_stat_io, so backpatch down to v16. Author: Bertrand Drouvot <bertranddrouvot.pg@gmail.com> Reviewed-by: vignesh C <vignesh21@gmail.com> Reviewed-by: Xuneng Zhou <xunengzhou@gmail.com> Discussion: https://postgr.es/m/Z73IsKBceoVd4t55@ip-10-97-1-34.eu-west-3.compute.internal Backpatch-through: 16
1 parent 4c1d853 commit 5cbbe70

File tree

1 file changed

+32
-2
lines changed

1 file changed

+32
-2
lines changed

src/backend/replication/walsender.c

Lines changed: 32 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -90,10 +90,14 @@
9090
#include "utils/guc.h"
9191
#include "utils/memutils.h"
9292
#include "utils/pg_lsn.h"
93+
#include "utils/pgstat_internal.h"
9394
#include "utils/ps_status.h"
9495
#include "utils/timeout.h"
9596
#include "utils/timestamp.h"
9697

98+
/* Minimum interval used by walsender for stats flushes, in ms */
99+
#define WALSENDER_STATS_FLUSH_INTERVAL 1000
100+
97101
/*
98102
* Maximum data payload in a WAL data message. Must be >= XLOG_BLCKSZ.
99103
*
@@ -1820,6 +1824,7 @@ WalSndWaitForWal(XLogRecPtr loc)
18201824
int wakeEvents;
18211825
uint32 wait_event = 0;
18221826
static XLogRecPtr RecentFlushPtr = InvalidXLogRecPtr;
1827+
TimestampTz last_flush = 0;
18231828

18241829
/*
18251830
* Fast path to avoid acquiring the spinlock in case we already know we
@@ -1840,6 +1845,7 @@ WalSndWaitForWal(XLogRecPtr loc)
18401845
{
18411846
bool wait_for_standby_at_stop = false;
18421847
long sleeptime;
1848+
TimestampTz now;
18431849

18441850
/* Clear any already-pending wakeups */
18451851
ResetLatch(MyLatch);
@@ -1950,7 +1956,8 @@ WalSndWaitForWal(XLogRecPtr loc)
19501956
* new WAL to be generated. (But if we have nothing to send, we don't
19511957
* want to wake on socket-writable.)
19521958
*/
1953-
sleeptime = WalSndComputeSleeptime(GetCurrentTimestamp());
1959+
now = GetCurrentTimestamp();
1960+
sleeptime = WalSndComputeSleeptime(now);
19541961

19551962
wakeEvents = WL_SOCKET_READABLE;
19561963

@@ -1959,6 +1966,14 @@ WalSndWaitForWal(XLogRecPtr loc)
19591966

19601967
Assert(wait_event != 0);
19611968

1969+
/* Report IO statistics, if needed */
1970+
if (TimestampDifferenceExceeds(last_flush, now,
1971+
WALSENDER_STATS_FLUSH_INTERVAL))
1972+
{
1973+
pgstat_flush_io(false);
1974+
last_flush = now;
1975+
}
1976+
19621977
WalSndWait(wakeEvents, sleeptime, wait_event);
19631978
}
19641979

@@ -2766,6 +2781,8 @@ WalSndCheckTimeOut(void)
27662781
static void
27672782
WalSndLoop(WalSndSendDataCallback send_data)
27682783
{
2784+
TimestampTz last_flush = 0;
2785+
27692786
/*
27702787
* Initialize the last reply timestamp. That enables timeout processing
27712788
* from hereon.
@@ -2860,13 +2877,17 @@ WalSndLoop(WalSndSendDataCallback send_data)
28602877
* WalSndWaitForWal() handle any other blocking; idle receivers need
28612878
* its additional actions. For physical replication, also block if
28622879
* caught up; its send_data does not block.
2880+
*
2881+
* The IO statistics are reported in WalSndWaitForWal() for the
2882+
* logical WAL senders.
28632883
*/
28642884
if ((WalSndCaughtUp && send_data != XLogSendLogical &&
28652885
!streamingDoneSending) ||
28662886
pq_is_send_pending())
28672887
{
28682888
long sleeptime;
28692889
int wakeEvents;
2890+
TimestampTz now;
28702891

28712892
if (!streamingDoneReceiving)
28722893
wakeEvents = WL_SOCKET_READABLE;
@@ -2877,11 +2898,20 @@ WalSndLoop(WalSndSendDataCallback send_data)
28772898
* Use fresh timestamp, not last_processing, to reduce the chance
28782899
* of reaching wal_sender_timeout before sending a keepalive.
28792900
*/
2880-
sleeptime = WalSndComputeSleeptime(GetCurrentTimestamp());
2901+
now = GetCurrentTimestamp();
2902+
sleeptime = WalSndComputeSleeptime(now);
28812903

28822904
if (pq_is_send_pending())
28832905
wakeEvents |= WL_SOCKET_WRITEABLE;
28842906

2907+
/* Report IO statistics, if needed */
2908+
if (TimestampDifferenceExceeds(last_flush, now,
2909+
WALSENDER_STATS_FLUSH_INTERVAL))
2910+
{
2911+
pgstat_flush_io(false);
2912+
last_flush = now;
2913+
}
2914+
28852915
/* Sleep until something happens or we time out */
28862916
WalSndWait(wakeEvents, sleeptime, WAIT_EVENT_WAL_SENDER_MAIN);
28872917
}

0 commit comments

Comments
 (0)