Enhance checkpointer restartpoint statistics
authorAlexander Korotkov <akorotkov@postgresql.org>
Sun, 24 Dec 2023 22:52:42 +0000 (00:52 +0200)
committerAlexander Korotkov <akorotkov@postgresql.org>
Sun, 24 Dec 2023 23:12:36 +0000 (01:12 +0200)
Bhis commit introduces enhancements to the pg_stat_checkpointer view by adding
three new columns: restartpoints_timed, restartpoints_req, and
restartpoints_done. These additions aim to improve the visibility and
monitoring of restartpoint processes on replicas.

Previously, it was challenging to differentiate between successful and failed
restartpoint requests. This limitation arises because restartpoints on replicas
are dependent on checkpoint records from the primary, and cannot occur more
frequently than these checkpoints.

The new columns allow for clear distinction and tracking of restartpoint
requests, their triggers, and successful completions.  This enhancement aids
database administrators and developers in better understanding and diagnosing
issues related to restartpoint behavior, particularly in scenarios where
restartpoint requests may fail.

System catalog is changed.  Catversion is bumped.

Discussion: https://postgr.es/m/99b2ccd1-a77a-962a-0837-191cdf56c2b9%40inbox.ru
Author: Anton A. Melnikov
Reviewed-by: Kyotaro Horiguchi, Alexander Korotkov
doc/src/sgml/monitoring.sgml
doc/src/sgml/wal.sgml
src/backend/catalog/system_views.sql
src/backend/postmaster/checkpointer.c
src/backend/utils/activity/pgstat_checkpointer.c
src/backend/utils/adt/pgstatfuncs.c
src/include/catalog/catversion.h
src/include/catalog/pg_proc.dat
src/include/pgstat.h
src/test/regress/expected/rules.out

index 4f8058d8b1bbd725b521ea0e9574c78b6fa1d62f..b804eb8b5efa5a7d2d43efce5ff5fb43c21cd62f 100644 (file)
@@ -2982,6 +2982,33 @@ description | Waiting for a newly initialized WAL file to reach durable storage
       </para></entry>
      </row>
 
+     <row>
+      <entry role="catalog_table_entry"><para role="column_definition">
+       <structfield>restartpoints_timed</structfield> <type>bigint</type>
+      </para>
+      <para>
+       Number of scheduled restartpoints due to timeout or after a failed attempt to perform it
+      </para></entry>
+     </row>
+
+     <row>
+      <entry role="catalog_table_entry"><para role="column_definition">
+       <structfield>restartpoints_req</structfield> <type>bigint</type>
+      </para>
+      <para>
+       Number of requested restartpoints
+      </para></entry>
+     </row>
+
+     <row>
+      <entry role="catalog_table_entry"><para role="column_definition">
+       <structfield>restartpoints_done</structfield> <type>bigint</type>
+      </para>
+      <para>
+       Number of restartpoints that have been performed
+      </para></entry>
+     </row>
+
      <row>
       <entry role="catalog_table_entry"><para role="column_definition">
        <structfield>write_time</structfield> <type>double precision</type>
index 2ed4eb659db3a9f444ac03998f74b7b834207c0a..05e2a8f8be959fbc707c6c0dc88869c89ca4b3a0 100644 (file)
    directory.
    Restartpoints can't be performed more frequently than checkpoints on the
    primary because restartpoints can only be performed at checkpoint records.
-   A restartpoint is triggered when a checkpoint record is reached if at
-   least <varname>checkpoint_timeout</varname> seconds have passed since the last
-   restartpoint, or if WAL size is about to exceed
-   <varname>max_wal_size</varname>. However, because of limitations on when a
-   restartpoint can be performed, <varname>max_wal_size</varname> is often exceeded
-   during recovery, by up to one checkpoint cycle's worth of WAL.
+   A restartpoint can be demanded by a schedule or by an external request.
+   The <structfield>restartpoints_timed</structfield> counter in the
+   <link linkend="monitoring-pg-stat-checkpointer-view"><structname>pg_stat_checkpointer</structname></link>
+   view counts the first ones while the <structfield>restartpoints_req</structfield>
+   the second.
+   A restartpoint is triggered by schedule when a checkpoint record is reached
+   if at least <xref linkend="guc-checkpoint-timeout"/> seconds have passed since
+   the last performed restartpoint or when the previous attempt to perform
+   the restartpoint has failed. In the last case, the next restartpoint
+   will be scheduled in 15 seconds.
+   A restartpoint is triggered by request due to similar reasons like checkpoint
+   but mostly if WAL size is about to exceed <xref linkend="guc-max-wal-size"/>
+   However, because of limitations on when a restartpoint can be performed,
+   <varname>max_wal_size</varname> is often exceeded during recovery,
+   by up to one checkpoint cycle's worth of WAL.
    (<varname>max_wal_size</varname> is never a hard limit anyway, so you should
    always leave plenty of headroom to avoid running out of disk space.)
+   The <structfield>restartpoints_done</structfield> counter in the
+   <link linkend="monitoring-pg-stat-checkpointer-view"><structname>pg_stat_checkpointer</structname></link>
+   view counts the restartpoints that have really been performed.
+  </para>
+
+  <para>
+   In some cases, when the WAL size on the primary increases quickly,
+   for instance during massive INSERT,
+   the <structfield>restartpoints_req</structfield> counter on the standby
+   may demonstrate a peak growth.
+   This occurs because requests to create a new restartpoint due to increased
+   XLOG consumption cannot be performed because the safe checkpoint record
+   since the last restartpoint has not yet been replayed on the standby.
+   This behavior is normal and does not lead to an increase in system resource
+   consumption.
+   Only the <structfield>restartpoints_done</structfield>
+   counter among the restartpoint-related ones indicates that noticeable system
+   resources have been spent.
   </para>
 
   <para>
index 11d18ed9dd618ba01796744efcc01ab05e6d2ae4..058fc47c919a9977fb4de6ea75dce5eeca927af6 100644 (file)
@@ -1141,6 +1141,9 @@ CREATE VIEW pg_stat_checkpointer AS
     SELECT
         pg_stat_get_checkpointer_num_timed() AS num_timed,
         pg_stat_get_checkpointer_num_requested() AS num_requested,
+        pg_stat_get_checkpointer_restartpoints_timed() AS restartpoints_timed,
+        pg_stat_get_checkpointer_restartpoints_requested() AS restartpoints_req,
+        pg_stat_get_checkpointer_restartpoints_performed() AS restartpoints_done,
         pg_stat_get_checkpointer_write_time() AS write_time,
         pg_stat_get_checkpointer_sync_time() AS sync_time,
         pg_stat_get_checkpointer_buffers_written() AS buffers_written,
index dc2da5a2cd8ab55d73426fce01f66cc8b433765a..67ecb177e7e843f2e75522c84e9757787f478b83 100644 (file)
@@ -340,6 +340,8 @@ CheckpointerMain(void)
        pg_time_t   now;
        int         elapsed_secs;
        int         cur_timeout;
+       bool        chkpt_or_rstpt_requested = false;
+       bool        chkpt_or_rstpt_timed = false;
 
        /* Clear any already-pending wakeups */
        ResetLatch(MyLatch);
@@ -358,7 +360,7 @@ CheckpointerMain(void)
        if (((volatile CheckpointerShmemStruct *) CheckpointerShmem)->ckpt_flags)
        {
            do_checkpoint = true;
-           PendingCheckpointerStats.num_requested++;
+           chkpt_or_rstpt_requested = true;
        }
 
        /*
@@ -372,7 +374,7 @@ CheckpointerMain(void)
        if (elapsed_secs >= CheckPointTimeout)
        {
            if (!do_checkpoint)
-               PendingCheckpointerStats.num_timed++;
+               chkpt_or_rstpt_timed = true;
            do_checkpoint = true;
            flags |= CHECKPOINT_CAUSE_TIME;
        }
@@ -408,6 +410,24 @@ CheckpointerMain(void)
            if (flags & CHECKPOINT_END_OF_RECOVERY)
                do_restartpoint = false;
 
+           if (chkpt_or_rstpt_timed)
+           {
+               chkpt_or_rstpt_timed = false;
+               if (do_restartpoint)
+                   PendingCheckpointerStats.restartpoints_timed++;
+               else
+                   PendingCheckpointerStats.num_timed++;
+           }
+
+           if (chkpt_or_rstpt_requested)
+           {
+               chkpt_or_rstpt_requested = false;
+               if (do_restartpoint)
+                   PendingCheckpointerStats.restartpoints_requested++;
+               else
+                   PendingCheckpointerStats.num_requested++;
+           }
+
            /*
             * We will warn if (a) too soon since last checkpoint (whatever
             * caused it) and (b) somebody set the CHECKPOINT_CAUSE_XLOG flag
@@ -471,6 +491,9 @@ CheckpointerMain(void)
                 * checkpoints happen at a predictable spacing.
                 */
                last_checkpoint_time = now;
+
+               if (do_restartpoint)
+                   PendingCheckpointerStats.restartpoints_performed++;
            }
            else
            {
index 301a0bc7bd3211bc2454e33ca903f9db8fbc1932..6ee258f240258d2e469fe6180408d7edbfcef819 100644 (file)
@@ -49,6 +49,9 @@ pgstat_report_checkpointer(void)
 #define CHECKPOINTER_ACC(fld) stats_shmem->stats.fld += PendingCheckpointerStats.fld
    CHECKPOINTER_ACC(num_timed);
    CHECKPOINTER_ACC(num_requested);
+   CHECKPOINTER_ACC(restartpoints_timed);
+   CHECKPOINTER_ACC(restartpoints_requested);
+   CHECKPOINTER_ACC(restartpoints_performed);
    CHECKPOINTER_ACC(write_time);
    CHECKPOINTER_ACC(sync_time);
    CHECKPOINTER_ACC(buffers_written);
@@ -116,6 +119,9 @@ pgstat_checkpointer_snapshot_cb(void)
 #define CHECKPOINTER_COMP(fld) pgStatLocal.snapshot.checkpointer.fld -= reset.fld;
    CHECKPOINTER_COMP(num_timed);
    CHECKPOINTER_COMP(num_requested);
+   CHECKPOINTER_COMP(restartpoints_timed);
+   CHECKPOINTER_COMP(restartpoints_requested);
+   CHECKPOINTER_COMP(restartpoints_performed);
    CHECKPOINTER_COMP(write_time);
    CHECKPOINTER_COMP(sync_time);
    CHECKPOINTER_COMP(buffers_written);
index 0cea320c00e0ebefa2ab097838d41c3608fe7d5b..e65cbf41e9f16165d28840f92759b118cf73f327 100644 (file)
@@ -1193,6 +1193,24 @@ pg_stat_get_checkpointer_num_requested(PG_FUNCTION_ARGS)
    PG_RETURN_INT64(pgstat_fetch_stat_checkpointer()->num_requested);
 }
 
+Datum
+pg_stat_get_checkpointer_restartpoints_timed(PG_FUNCTION_ARGS)
+{
+   PG_RETURN_INT64(pgstat_fetch_stat_checkpointer()->restartpoints_timed);
+}
+
+Datum
+pg_stat_get_checkpointer_restartpoints_requested(PG_FUNCTION_ARGS)
+{
+   PG_RETURN_INT64(pgstat_fetch_stat_checkpointer()->restartpoints_requested);
+}
+
+Datum
+pg_stat_get_checkpointer_restartpoints_performed(PG_FUNCTION_ARGS)
+{
+   PG_RETURN_INT64(pgstat_fetch_stat_checkpointer()->restartpoints_performed);
+}
+
 Datum
 pg_stat_get_checkpointer_buffers_written(PG_FUNCTION_ARGS)
 {
index ae1bee42a9ad901c9900b5bc413eba4b70cab5c1..2fd601add0f431d532cfb421b123e4f95ee6b9ee 100644 (file)
@@ -57,6 +57,6 @@
  */
 
 /*                         yyyymmddN */
-#define CATALOG_VERSION_NO 202312211
+#define CATALOG_VERSION_NO 202312251
 
 #endif
index b8b26c263dbc1e5831b3815ac04732bb30e32cd4..9052f5262a2ddec6fd97e17faabf03b9eede41b3 100644 (file)
   proname => 'pg_stat_get_checkpointer_num_requested', provolatile => 's',
   proparallel => 'r', prorettype => 'int8', proargtypes => '',
   prosrc => 'pg_stat_get_checkpointer_num_requested' },
+{ oid => '8743',
+  descr => 'statistics: number of timed restartpoints started by the checkpointer',
+  proname => 'pg_stat_get_checkpointer_restartpoints_timed', provolatile => 's',
+  proparallel => 'r', prorettype => 'int8', proargtypes => '',
+  prosrc => 'pg_stat_get_checkpointer_restartpoints_timed' },
+{ oid => '8744',
+  descr => 'statistics: number of backend requested restartpoints started by the checkpointer',
+  proname => 'pg_stat_get_checkpointer_restartpoints_requested', provolatile => 's',
+  proparallel => 'r', prorettype => 'int8', proargtypes => '',
+  prosrc => 'pg_stat_get_checkpointer_restartpoints_requested' },
+{ oid => '8745',
+  descr => 'statistics: number of backend performed restartpoints',
+  proname => 'pg_stat_get_checkpointer_restartpoints_performed', provolatile => 's',
+  proparallel => 'r', prorettype => 'int8', proargtypes => '',
+  prosrc => 'pg_stat_get_checkpointer_restartpoints_performed' },
 { oid => '2771',
   descr => 'statistics: number of buffers written by the checkpointer',
   proname => 'pg_stat_get_checkpointer_buffers_written', provolatile => 's',
index fc93d0d731daa6c21634f800a5229f0b0663c173..ab91b3b367da026e8476a17228aec680bae55ac7 100644 (file)
@@ -262,6 +262,9 @@ typedef struct PgStat_CheckpointerStats
 {
    PgStat_Counter num_timed;
    PgStat_Counter num_requested;
+   PgStat_Counter restartpoints_timed;
+   PgStat_Counter restartpoints_requested;
+   PgStat_Counter restartpoints_performed;
    PgStat_Counter write_time;  /* times in milliseconds */
    PgStat_Counter sync_time;
    PgStat_Counter buffers_written;
index 05070393b996efb806bab474befa628b14827418..f645e8486bf38dae7a07af0a5bcd636d8b7797d3 100644 (file)
@@ -1822,6 +1822,9 @@ pg_stat_bgwriter| SELECT pg_stat_get_bgwriter_buf_written_clean() AS buffers_cle
     pg_stat_get_bgwriter_stat_reset_time() AS stats_reset;
 pg_stat_checkpointer| SELECT pg_stat_get_checkpointer_num_timed() AS num_timed,
     pg_stat_get_checkpointer_num_requested() AS num_requested,
+    pg_stat_get_checkpointer_restartpoints_timed() AS restartpoints_timed,
+    pg_stat_get_checkpointer_restartpoints_requested() AS restartpoints_req,
+    pg_stat_get_checkpointer_restartpoints_performed() AS restartpoints_done,
     pg_stat_get_checkpointer_write_time() AS write_time,
     pg_stat_get_checkpointer_sync_time() AS sync_time,
     pg_stat_get_checkpointer_buffers_written() AS buffers_written,