Re: Monitoring time of fsyncing WALs

[Michael Paquier]

On Wed, Jun 27, 2018 at 07:32:18PM +0300, Konstantin Knizhnik wrote:
> I wonder why we are monitoring time of writing to WAL, but not time of
> fsyncing WAL segments?
> Is there are principle reason for it or just because nobody added it yet?
> If so, please find very small patch which adding WAIT_EVENT_WAL_FSYNC event
> type.

Let's name it WAIT_EVENT_WAL_SYNC as it is more consistent with the
other wait events of the same type, and also list the wait event
alphabetically everywhere this is added.  I have also reworded the
documentation to be more consistent.

> Our engineers in PgPro complain me that there is no information about time
> spent in syncing WALs...
> Unfortunately Postgres still is not able to aggregate this statistic. But at
> least we have pg_wait_sampling extension for it:
> https://github.com/postgrespro/pg_wait_sampling

Complain justified.  It is a bit too late for v11 I think though, so
let's wait for v12 to open for business, and then I'll apply the patch
at if there are no objections until then.

Attached is an updated patch.
--
Michael

diff --git a/doc/src/sgml/monitoring.sgml b/doc/src/sgml/monitoring.sgml
index c2adb22dff..36d393d329 100644
--- a/doc/src/sgml/monitoring.sgml
+++ b/doc/src/sgml/monitoring.sgml
@@ -1674,6 +1674,10 @@ postgres   27093  0.0  0.0  30096  2752 ?        Ss   11:34   0:00 postgres: ser
          <entry><literal>WALSenderTimelineHistoryRead</literal></entry>
          <entry>Waiting for a read from a timeline history file during walsender timeline command.</entry>
         </row>
+        <row>
+         <entry><literal>WALSync</literal></entry>
+         <entry>Waiting for a WAL file to reach stable storage.</entry>
+        </row>
         <row>
          <entry><literal>WALSyncMethodAssign</literal></entry>
          <entry>Waiting for data to reach stable storage while assigning WAL sync method.</entry>
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 1a419aa49b..6aae426744 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -10156,6 +10156,7 @@ assign_xlog_sync_method(int new_sync_method, void *extra)
 void
 issue_xlog_fsync(int fd, XLogSegNo segno)
 {
+	pgstat_report_wait_start(WAIT_EVENT_WAL_SYNC);
 	switch (sync_method)
 	{
 		case SYNC_METHOD_FSYNC:
@@ -10191,6 +10192,7 @@ issue_xlog_fsync(int fd, XLogSegNo segno)
 			elog(PANIC, "unrecognized wal_sync_method: %d", sync_method);
 			break;
 	}
+	pgstat_report_wait_end();
 }
 
 /*
diff --git a/src/backend/postmaster/pgstat.c b/src/backend/postmaster/pgstat.c
index 084573e77c..bbe73618c7 100644
--- a/src/backend/postmaster/pgstat.c
+++ b/src/backend/postmaster/pgstat.c
@@ -3925,6 +3925,9 @@ pgstat_get_wait_io(WaitEventIO w)
 		case WAIT_EVENT_WAL_READ:
 			event_name = "WALRead";
 			break;
+		case WAIT_EVENT_WAL_SYNC:
+			event_name = "WALSync";
+			break;
 		case WAIT_EVENT_WAL_SYNC_METHOD_ASSIGN:
 			event_name = "WALSyncMethodAssign";
 			break;
diff --git a/src/include/pgstat.h b/src/include/pgstat.h
index be2f59239b..d59c24ae23 100644
--- a/src/include/pgstat.h
+++ b/src/include/pgstat.h
@@ -921,6 +921,7 @@ typedef enum
 	WAIT_EVENT_WAL_INIT_SYNC,
 	WAIT_EVENT_WAL_INIT_WRITE,
 	WAIT_EVENT_WAL_READ,
+	WAIT_EVENT_WAL_SYNC,
 	WAIT_EVENT_WAL_SYNC_METHOD_ASSIGN,
 	WAIT_EVENT_WAL_WRITE
 } WaitEventIO;

signature.asc
Description: PGP signature