Re: Add connection active, idle time to pg_stat_activity - Mailing list pgsql-hackers

From Kyotaro Horiguchi
Subject Re: Add connection active, idle time to pg_stat_activity
Date
Msg-id 20220201.135516.23011068590309830.horikyota.ntt@gmail.com
Whole thread Raw
In response to Re: Add connection active, idle time to pg_stat_activity  (Sergey Dudoladov <sergey.dudoladov@gmail.com>)
Responses Re: Add connection active, idle time to pg_stat_activity  (Sergey Dudoladov <sergey.dudoladov@gmail.com>)
List pgsql-hackers
At Mon, 31 Jan 2022 15:11:56 +0100, Sergey Dudoladov <sergey.dudoladov@gmail.com> wrote in 
> > >               if (beentry->st_state == STATE_RUNNING ||
> > >                       beentry->st_state == STATE_FASTPATH)
> > > -                     pgstat_count_conn_active_time((PgStat_Counter) secs * 1000000 + usecs);
> > > +             {
> > > +                     pgstat_count_conn_active_time((PgStat_Counter) usecs_diff);
> > > +                     beentry->st_total_active_time += usecs_diff;
> > > +             }
> > >
> > > The two lines operates exactly the same way on variables with slightly
> > > different behavior. pgStatActiveTime is reported at transaction end
> > > and reset at every tabstat reporting. st_total_active_time is reported
> > > immediately and reset at session end. Since we do the latter, the
> > > first can be omitted by remembering the last values for the local
> > > variables at every reporting.  This needs additional two exporting
> >
> > Of course it's typo(?) of "values of the shared variables".
> 
> Could you please elaborate on this idea ?
> So we have pgStatActiveTime and pgStatIdleInTransactionTime ultimately
> used to report respective metrics in pg_stat_database.
> Now beentry's st_total_active_time / st_total_transaction_idle_time
> duplicates this info, so one may get rid of  pgStat*Time counters. Is
> the idea to report  instead of them at every tabstat reporting the
> difference between the last memorized value of  st_total_*_time and
> its current value ?

Exactly. The attached first diff is the schetch of that.

> > > This needs additional two exporting
> > > function in pgstatfuncs like pgstat_get_my_queryid so others might
> > > think differently.
> 
> What would be example functions to look at ?

pgstat_get_my_queryid..


And, it seems like I forgot to mention this, but as Kuntal suggested
(in a different context and objective, though) upthraed, I think that
we can show realtime values in the two time fields by adding the time
of the current state.  See the attached second diff.

regards.

-- 
Kyotaro Horiguchi
NTT Open Source Software Center
diff --git a/src/backend/postmaster/pgstat.c b/src/backend/postmaster/pgstat.c
index 0646f53098..27419c1851 100644
--- a/src/backend/postmaster/pgstat.c
+++ b/src/backend/postmaster/pgstat.c
@@ -249,8 +249,8 @@ static int    pgStatXactRollback = 0;
 PgStat_Counter pgStatBlockReadTime = 0;
 PgStat_Counter pgStatBlockWriteTime = 0;
 static PgStat_Counter pgLastSessionReportTime = 0;
-PgStat_Counter pgStatActiveTime = 0;
-PgStat_Counter pgStatTransactionIdleTime = 0;
+PgStat_Counter pgStatLastActiveTime = 0;
+PgStat_Counter pgStatLastTransactionIdleTime = 0;
 SessionEndType pgStatSessionEndCause = DISCONNECT_NORMAL;
 
 /* Record that's written to 2PC state file when pgstat state is persisted */
@@ -1026,8 +1026,13 @@ pgstat_send_tabstat(PgStat_MsgTabstat *tsmsg, TimestampTz now)
             TimestampDifference(pgLastSessionReportTime, now, &secs, &usecs);
             pgLastSessionReportTime = now;
             tsmsg->m_session_time = (PgStat_Counter) secs * 1000000 + usecs;
-            tsmsg->m_active_time = pgStatActiveTime;
-            tsmsg->m_idle_in_xact_time = pgStatTransactionIdleTime;
+
+            /* send the difference since the last report */
+            tsmsg->m_active_time =
+                pgstat_get_my_active_time() - pgStatLastActiveTime;
+            tsmsg->m_idle_in_xact_time =
+                pgstat_get_my_transaction_idle_time() -
+                pgStatLastTransactionIdleTime;
         }
         else
         {
@@ -1039,8 +1044,8 @@ pgstat_send_tabstat(PgStat_MsgTabstat *tsmsg, TimestampTz now)
         pgStatXactRollback = 0;
         pgStatBlockReadTime = 0;
         pgStatBlockWriteTime = 0;
-        pgStatActiveTime = 0;
-        pgStatTransactionIdleTime = 0;
+        pgStatLastActiveTime = pgstat_get_my_active_time();
+        pgStatLastTransactionIdleTime =  pgstat_get_my_transaction_idle_time();
     }
     else
     {
diff --git a/src/backend/utils/activity/backend_status.c b/src/backend/utils/activity/backend_status.c
index 5f15dcdc05..8b6836a662 100644
--- a/src/backend/utils/activity/backend_status.c
+++ b/src/backend/utils/activity/backend_status.c
@@ -613,15 +613,9 @@ pgstat_report_activity(BackendState state, const char *cmd_str)
          */
         if (beentry->st_state == STATE_RUNNING ||
             beentry->st_state == STATE_FASTPATH)
-        {
-            pgstat_count_conn_active_time((PgStat_Counter) usecs_diff);
             active_time_diff = usecs_diff;
-        }
         else
-        {
-            pgstat_count_conn_txn_idle_time((PgStat_Counter) usecs_diff);
             transaction_idle_time_diff = usecs_diff;
-        }
     }
 
     /*
@@ -1078,6 +1072,48 @@ pgstat_get_my_query_id(void)
 }
 
 
+/* ----------
+ * pgstat_get_my_active_time() -
+ *
+ * Return current backend's accumulated active time.
+ */
+uint64
+pgstat_get_my_active_time(void)
+{
+    if (!MyBEEntry)
+        return 0;
+
+    /*
+     * There's no need for a lock around pgstat_begin_read_activity /
+     * pgstat_end_read_activity here as it's only called from
+     * pg_stat_get_activity which is already protected, or from the same
+     * backend which means that there won't be concurrent writes.
+     */
+    return MyBEEntry->st_total_active_time;
+}
+
+
+/* ----------
+ * pgstat_get_my_transaction_idle_time() -
+ *
+ * Return current backend's accumulated in-transaction idel time.
+ */
+uint64
+pgstat_get_my_transaction_idle_time(void)
+{
+    if (!MyBEEntry)
+        return 0;
+
+    /*
+     * There's no need for a lock around pgstat_begin_read_activity /
+     * pgstat_end_read_activity here as it's only called from
+     * pg_stat_get_activity which is already protected, or from the same
+     * backend which means that there won't be concurrent writes.
+     */
+    return MyBEEntry->st_total_transaction_idle_time;
+}
+
+
 /* ----------
  * pgstat_fetch_stat_beentry() -
  *
diff --git a/src/include/pgstat.h b/src/include/pgstat.h
index e10d20222a..382d7202c1 100644
--- a/src/include/pgstat.h
+++ b/src/include/pgstat.h
@@ -1185,10 +1185,6 @@ extern void pgstat_initstats(Relation rel);
     (pgStatBlockReadTime += (n))
 #define pgstat_count_buffer_write_time(n)                            \
     (pgStatBlockWriteTime += (n))
-#define pgstat_count_conn_active_time(n)                            \
-    (pgStatActiveTime += (n))
-#define pgstat_count_conn_txn_idle_time(n)                            \
-    (pgStatTransactionIdleTime += (n))
 
 extern void pgstat_count_heap_insert(Relation rel, PgStat_Counter n);
 extern void pgstat_count_heap_update(Relation rel, bool hot);
diff --git a/src/include/utils/backend_status.h b/src/include/utils/backend_status.h
index 96d432ce49..1791dd6842 100644
--- a/src/include/utils/backend_status.h
+++ b/src/include/utils/backend_status.h
@@ -309,6 +309,8 @@ extern const char *pgstat_get_backend_current_activity(int pid, bool checkUser);
 extern const char *pgstat_get_crashed_backend_activity(int pid, char *buffer,
                                                        int buflen);
 extern uint64 pgstat_get_my_query_id(void);
+extern uint64 pgstat_get_my_active_time(void);
+extern uint64 pgstat_get_my_transaction_idle_time(void);
 
 
 /* ----------
diff --git a/src/backend/utils/activity/backend_status.c b/src/backend/utils/activity/backend_status.c
index 8b6836a662..996f4e88d7 100644
--- a/src/backend/utils/activity/backend_status.c
+++ b/src/backend/utils/activity/backend_status.c
@@ -587,10 +587,7 @@ pgstat_report_activity(BackendState state, const char *cmd_str)
      * If the state has changed from "active" or "idle in transaction",
      * calculate the duration.
      */
-    if ((beentry->st_state == STATE_RUNNING ||
-         beentry->st_state == STATE_FASTPATH ||
-         beentry->st_state == STATE_IDLEINTRANSACTION ||
-         beentry->st_state == STATE_IDLEINTRANSACTION_ABORTED) &&
+    if ((PGSTAT_IS_ACTIVE(beentry) || PGSTAT_IS_IDLEINTRANSACTION(beentry)) &&
         state != beentry->st_state)
     {
         long        secs;
@@ -611,8 +608,7 @@ pgstat_report_activity(BackendState state, const char *cmd_str)
          * 2. The latter values are reset to 0 once the data has been sent
          * to the statistics collector.
          */
-        if (beentry->st_state == STATE_RUNNING ||
-            beentry->st_state == STATE_FASTPATH)
+        if (PGSTAT_IS_ACTIVE(beentry))
             active_time_diff = usecs_diff;
         else
             transaction_idle_time_diff = usecs_diff;
diff --git a/src/backend/utils/adt/pgstatfuncs.c b/src/backend/utils/adt/pgstatfuncs.c
index 7c2776c14c..48c0ffa33a 100644
--- a/src/backend/utils/adt/pgstatfuncs.c
+++ b/src/backend/utils/adt/pgstatfuncs.c
@@ -675,6 +675,7 @@ pg_stat_get_activity(PG_FUNCTION_ARGS)
         {
             SockAddr    zero_clientaddr;
             char       *clipped_activity;
+            int64        tmp_time;
 
             switch (beentry->st_state)
             {
@@ -917,9 +918,25 @@ pg_stat_get_activity(PG_FUNCTION_ARGS)
             else
                 values[29] = UInt64GetDatum(beentry->st_query_id);
 
-            /* convert to msec for display */
-            values[30] = Float8GetDatum(beentry->st_total_active_time / 1000.0) ;
-            values[31] = Float8GetDatum(beentry->st_total_transaction_idle_time / 1000.0);
+            tmp_time = beentry->st_total_active_time;
+
+            /* add the realtime value to the counter if needed */
+            if (PGSTAT_IS_ACTIVE(beentry))
+                tmp_time +=
+                    GetCurrentTimestamp() - beentry->st_state_start_timestamp;
+
+            /* convert it to msec */
+            values[30] = Float8GetDatum(tmp_time / 1000.0) ;
+
+            tmp_time = beentry->st_total_transaction_idle_time;
+
+            /* add the realtime value to the counter if needed */
+            if (PGSTAT_IS_IDLEINTRANSACTION(beentry))
+                tmp_time +=
+                    GetCurrentTimestamp() - beentry->st_state_start_timestamp;
+
+            /* convert it to msec */
+            values[31] = Float8GetDatum(tmp_time);
         }
         else
         {
diff --git a/src/include/utils/backend_status.h b/src/include/utils/backend_status.h
index 1791dd6842..a03225c4f0 100644
--- a/src/include/utils/backend_status.h
+++ b/src/include/utils/backend_status.h
@@ -235,6 +235,12 @@ typedef struct PgBackendStatus
     ((before_changecount) == (after_changecount) && \
      ((before_changecount) & 1) == 0)
 
+/* macros to identify the states for time accounting */
+#define PGSTAT_IS_ACTIVE(s)                                                \
+    ((s)->st_state == STATE_RUNNING || (s)->st_state == STATE_FASTPATH)
+#define PGSTAT_IS_IDLEINTRANSACTION(s)             \
+    ((s)->st_state == STATE_IDLEINTRANSACTION ||        \
+     (s)->st_state == STATE_IDLEINTRANSACTION_ABORTED)
 
 /* ----------
  * LocalPgBackendStatus

pgsql-hackers by date:

Previous
From: Julien Rouhaud
Date:
Subject: Re: Extensible Rmgr for Table AMs
Next
From: Thomas Munro
Date:
Subject: Re: Why is src/test/modules/committs/t/002_standby.pl flaky?