v4-0003-Add-local_blk_-read-write-_time-I-O-timing-statis.patch

From d99998efc5b4fa5e6a0998ac326d263d899c3afe Mon Sep 17 00:00:00 2001
From: Nazir Bilal Yavuz <byavuz81@gmail.com>
Date: Tue, 17 Oct 2023 12:45:47 +0300
Subject: [PATCH v4 3/3] Add local_blk_{read|write}_time I/O timing statistics

There was no I/O timing statistics for counting local blocks' timings.
So, add local_blk_{read|write}_time variables for counting these. These
counters are exposed in EXPLAIN and pg_stat_statements.
pg_stat_statements is bumped to 1.12.
---
 .../expected/oldextversions.out               |  2 ++
 .../pg_stat_statements--1.10--1.11.sql        |  2 ++
 .../pg_stat_statements/pg_stat_statements.c   | 15 ++++++++++--
 doc/src/sgml/pgstatstatements.sgml            | 20 ++++++++++++++++
 src/backend/commands/explain.c                | 23 ++++++++++++++++++-
 src/backend/executor/instrument.c             |  6 +++++
 src/backend/utils/activity/pgstat_io.c        |  4 ++++
 src/include/executor/instrument.h             |  2 ++
 src/test/regress/expected/explain.out         |  4 ++++
 9 files changed, 75 insertions(+), 3 deletions(-)

diff --git a/contrib/pg_stat_statements/expected/oldextversions.out b/contrib/pg_stat_statements/expected/oldextversions.out
index c2e0140a47..5a5404bbd5 100644
--- a/contrib/pg_stat_statements/expected/oldextversions.out
+++ b/contrib/pg_stat_statements/expected/oldextversions.out
@@ -286,6 +286,8 @@ AlTER EXTENSION pg_stat_statements UPDATE TO '1.11';
  temp_blks_written      | bigint           |           |          | 
  shared_blk_read_time   | double precision |           |          | 
  shared_blk_write_time  | double precision |           |          | 
+ local_blk_read_time    | double precision |           |          | 
+ local_blk_write_time   | double precision |           |          | 
  temp_blk_read_time     | double precision |           |          | 
  temp_blk_write_time    | double precision |           |          | 
  wal_records            | bigint           |           |          | 
diff --git a/contrib/pg_stat_statements/pg_stat_statements--1.10--1.11.sql b/contrib/pg_stat_statements/pg_stat_statements--1.10--1.11.sql
index 448ef3682f..5fe211184b 100644
--- a/contrib/pg_stat_statements/pg_stat_statements--1.10--1.11.sql
+++ b/contrib/pg_stat_statements/pg_stat_statements--1.10--1.11.sql
@@ -43,6 +43,8 @@ CREATE FUNCTION pg_stat_statements(IN showtext boolean,
     OUT temp_blks_written int8,
     OUT shared_blk_read_time float8,
     OUT shared_blk_write_time float8,
+    OUT local_blk_read_time float8,
+    OUT local_blk_write_time float8,
     OUT temp_blk_read_time float8,
     OUT temp_blk_write_time float8,
     OUT wal_records int8,
diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c
index 9fd886596c..28c090606c 100644
--- a/contrib/pg_stat_statements/pg_stat_statements.c
+++ b/contrib/pg_stat_statements/pg_stat_statements.c
@@ -184,6 +184,10 @@ typedef struct Counters
 										 * msec */
 	double		shared_blk_write_time;	/* time spent writing shared blocks, in
 										 * msec */
+	double		local_blk_read_time;	/* time spent reading local blocks, in
+										 * msec */
+	double		local_blk_write_time;	/* time spent writing local blocks, in
+										 * msec */
 	double		temp_blk_read_time; /* time spent reading temp blocks, in msec */
 	double		temp_blk_write_time;	/* time spent writing temp blocks, in
 										 * msec */
@@ -1395,6 +1399,8 @@ pgss_store(const char *query, uint64 queryId,
 		e->counters.temp_blks_written += bufusage->temp_blks_written;
 		e->counters.shared_blk_read_time += INSTR_TIME_GET_MILLISEC(bufusage->shared_blk_read_time);
 		e->counters.shared_blk_write_time += INSTR_TIME_GET_MILLISEC(bufusage->shared_blk_write_time);
+		e->counters.local_blk_read_time += INSTR_TIME_GET_MILLISEC(bufusage->local_blk_read_time);
+		e->counters.local_blk_write_time += INSTR_TIME_GET_MILLISEC(bufusage->local_blk_write_time);
 		e->counters.temp_blk_read_time += INSTR_TIME_GET_MILLISEC(bufusage->temp_blk_read_time);
 		e->counters.temp_blk_write_time += INSTR_TIME_GET_MILLISEC(bufusage->temp_blk_write_time);
 		e->counters.usage += USAGE_EXEC(total_time);
@@ -1472,8 +1478,8 @@ pg_stat_statements_reset(PG_FUNCTION_ARGS)
 #define PG_STAT_STATEMENTS_COLS_V1_8	32
 #define PG_STAT_STATEMENTS_COLS_V1_9	33
 #define PG_STAT_STATEMENTS_COLS_V1_10	43
-#define PG_STAT_STATEMENTS_COLS_V1_11	45
-#define PG_STAT_STATEMENTS_COLS			45	/* maximum of above */
+#define PG_STAT_STATEMENTS_COLS_V1_11	47
+#define PG_STAT_STATEMENTS_COLS			47	/* maximum of above */
 
 /*
  * Retrieve statement statistics.
@@ -1828,6 +1834,11 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo,
 			values[i++] = Float8GetDatumFast(tmp.shared_blk_read_time);
 			values[i++] = Float8GetDatumFast(tmp.shared_blk_write_time);
 		}
+		if (api_version >= PGSS_V1_11)
+		{
+			values[i++] = Float8GetDatumFast(tmp.local_blk_read_time);
+			values[i++] = Float8GetDatumFast(tmp.local_blk_write_time);
+		}
 		if (api_version >= PGSS_V1_10)
 		{
 			values[i++] = Float8GetDatumFast(tmp.temp_blk_read_time);
diff --git a/doc/src/sgml/pgstatstatements.sgml b/doc/src/sgml/pgstatstatements.sgml
index 2c4e3655ff..6c7ca962f8 100644
--- a/doc/src/sgml/pgstatstatements.sgml
+++ b/doc/src/sgml/pgstatstatements.sgml
@@ -353,6 +353,26 @@
       </para></entry>
      </row>
 
+     <row>
+      <entry role="catalog_table_entry"><para role="column_definition">
+       <structfield>local_blk_read_time</structfield> <type>double precision</type>
+      </para>
+      <para>
+       Total time the statement spent reading local blocks, in milliseconds
+       (if <xref linkend="guc-track-io-timing"/> is enabled, otherwise zero)
+      </para></entry>
+     </row>
+
+     <row>
+      <entry role="catalog_table_entry"><para role="column_definition">
+       <structfield>local_blk_write_time</structfield> <type>double precision</type>
+      </para>
+      <para>
+       Total time the statement spent writing local blocks, in milliseconds
+       (if <xref linkend="guc-track-io-timing"/> is enabled, otherwise zero)
+      </para></entry>
+     </row>
+
      <row>
       <entry role="catalog_table_entry"><para role="column_definition">
        <structfield>temp_blk_read_time</structfield> <type>double precision</type>
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index d6cf948f38..83f46ed9d7 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -3564,11 +3564,14 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning)
 								usage->temp_blks_written > 0);
 		bool		has_shared_timing = (!INSTR_TIME_IS_ZERO(usage->shared_blk_read_time) ||
 										 !INSTR_TIME_IS_ZERO(usage->shared_blk_write_time));
+		bool		has_local_timing = (!INSTR_TIME_IS_ZERO(usage->local_blk_read_time) ||
+										!INSTR_TIME_IS_ZERO(usage->local_blk_write_time));
 		bool		has_temp_timing = (!INSTR_TIME_IS_ZERO(usage->temp_blk_read_time) ||
 									   !INSTR_TIME_IS_ZERO(usage->temp_blk_write_time));
 		bool		show_planning = (planning && (has_shared ||
 												  has_local || has_temp ||
 												  has_shared_timing ||
+												  has_local_timing ||
 												  has_temp_timing));
 
 		if (show_planning)
@@ -3634,7 +3637,7 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning)
 		}
 
 		/* As above, show only positive counter values. */
-		if (has_shared_timing || has_temp_timing)
+		if (has_shared_timing || has_local_timing || has_temp_timing)
 		{
 			ExplainIndentText(es);
 			appendStringInfoString(es->str, "I/O Timings:");
@@ -3651,6 +3654,18 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning)
 				if (has_temp_timing)
 					appendStringInfoChar(es->str, ',');
 			}
+			if (has_local_timing)
+			{
+				appendStringInfoString(es->str, " local");
+				if (!INSTR_TIME_IS_ZERO(usage->local_blk_read_time))
+					appendStringInfo(es->str, " read=%0.3f",
+									 INSTR_TIME_GET_MILLISEC(usage->local_blk_read_time));
+				if (!INSTR_TIME_IS_ZERO(usage->local_blk_write_time))
+					appendStringInfo(es->str, " write=%0.3f",
+									 INSTR_TIME_GET_MILLISEC(usage->local_blk_write_time));
+				if (has_temp_timing)
+					appendStringInfoChar(es->str, ',');
+			}
 			if (has_temp_timing)
 			{
 				appendStringInfoString(es->str, " temp");
@@ -3697,6 +3712,12 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning)
 			ExplainPropertyFloat("Shared I/O Write Time", "ms",
 								 INSTR_TIME_GET_MILLISEC(usage->shared_blk_write_time),
 								 3, es);
+			ExplainPropertyFloat("Local I/O Read Time", "ms",
+								 INSTR_TIME_GET_MILLISEC(usage->local_blk_read_time),
+								 3, es);
+			ExplainPropertyFloat("Local I/O Write Time", "ms",
+								 INSTR_TIME_GET_MILLISEC(usage->local_blk_write_time),
+								 3, es);
 			ExplainPropertyFloat("Temp I/O Read Time", "ms",
 								 INSTR_TIME_GET_MILLISEC(usage->temp_blk_read_time),
 								 3, es);
diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c
index ef2a24b7cf..c383f34c06 100644
--- a/src/backend/executor/instrument.c
+++ b/src/backend/executor/instrument.c
@@ -237,6 +237,8 @@ BufferUsageAdd(BufferUsage *dst, const BufferUsage *add)
 	dst->temp_blks_written += add->temp_blks_written;
 	INSTR_TIME_ADD(dst->shared_blk_read_time, add->shared_blk_read_time);
 	INSTR_TIME_ADD(dst->shared_blk_write_time, add->shared_blk_write_time);
+	INSTR_TIME_ADD(dst->local_blk_read_time, add->local_blk_read_time);
+	INSTR_TIME_ADD(dst->local_blk_write_time, add->local_blk_write_time);
 	INSTR_TIME_ADD(dst->temp_blk_read_time, add->temp_blk_read_time);
 	INSTR_TIME_ADD(dst->temp_blk_write_time, add->temp_blk_write_time);
 }
@@ -261,6 +263,10 @@ BufferUsageAccumDiff(BufferUsage *dst,
 						  add->shared_blk_read_time, sub->shared_blk_read_time);
 	INSTR_TIME_ACCUM_DIFF(dst->shared_blk_write_time,
 						  add->shared_blk_write_time, sub->shared_blk_write_time);
+	INSTR_TIME_ACCUM_DIFF(dst->local_blk_read_time,
+						  add->local_blk_read_time, sub->local_blk_read_time);
+	INSTR_TIME_ACCUM_DIFF(dst->local_blk_write_time,
+						  add->local_blk_write_time, sub->local_blk_write_time);
 	INSTR_TIME_ACCUM_DIFF(dst->temp_blk_read_time,
 						  add->temp_blk_read_time, sub->temp_blk_read_time);
 	INSTR_TIME_ACCUM_DIFF(dst->temp_blk_write_time,
diff --git a/src/backend/utils/activity/pgstat_io.c b/src/backend/utils/activity/pgstat_io.c
index 297cfc15fb..490d5a9ab7 100644
--- a/src/backend/utils/activity/pgstat_io.c
+++ b/src/backend/utils/activity/pgstat_io.c
@@ -124,12 +124,16 @@ pgstat_count_io_op_time(IOObject io_object, IOContext io_context, IOOp io_op,
 			pgstat_count_buffer_write_time(INSTR_TIME_GET_MICROSEC(io_time));
 			if (io_object == IOOBJECT_RELATION)
 				INSTR_TIME_ADD(pgBufferUsage.shared_blk_write_time, io_time);
+			else if (io_object == IOOBJECT_TEMP_RELATION)
+				INSTR_TIME_ADD(pgBufferUsage.local_blk_write_time, io_time);
 		}
 		else if (io_op == IOOP_READ)
 		{
 			pgstat_count_buffer_read_time(INSTR_TIME_GET_MICROSEC(io_time));
 			if (io_object == IOOBJECT_RELATION)
 				INSTR_TIME_ADD(pgBufferUsage.shared_blk_read_time, io_time);
+			else if (io_object == IOOBJECT_TEMP_RELATION)
+				INSTR_TIME_ADD(pgBufferUsage.local_blk_read_time, io_time);
 		}
 
 		INSTR_TIME_ADD(PendingIOStats.pending_times[io_object][io_context][io_op],
diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h
index 8c3e5184fd..9233c25739 100644
--- a/src/include/executor/instrument.h
+++ b/src/include/executor/instrument.h
@@ -35,6 +35,8 @@ typedef struct BufferUsage
 	int64		temp_blks_written;	/* # of temp blocks written */
 	instr_time	shared_blk_read_time;	/* time spent reading shared blocks */
 	instr_time	shared_blk_write_time; /* time spent writing shared blocks */
+	instr_time	local_blk_read_time;	/* time spent reading local blocks */
+	instr_time	local_blk_write_time; /* time spent writing local blocks */
 	instr_time	temp_blk_read_time; /* time spent reading temp blocks */
 	instr_time	temp_blk_write_time;	/* time spent writing temp blocks */
 } BufferUsage;
diff --git a/src/test/regress/expected/explain.out b/src/test/regress/expected/explain.out
index a101886299..809655e16e 100644
--- a/src/test/regress/expected/explain.out
+++ b/src/test/regress/expected/explain.out
@@ -260,6 +260,8 @@ select explain_filter('explain (analyze, buffers, format json) select * from int
        "Temp Written Blocks": N,    +
        "Shared I/O Read Time": N.N, +
        "Shared I/O Write Time": N.N,+
+       "Local I/O Read Time": N.N,  +
+       "Local I/O Write Time": N.N, +
        "Temp I/O Read Time": N.N,   +
        "Temp I/O Write Time": N.N   +
      },                             +
@@ -276,6 +278,8 @@ select explain_filter('explain (analyze, buffers, format json) select * from int
        "Temp Written Blocks": N,    +
        "Shared I/O Read Time": N.N, +
        "Shared I/O Write Time": N.N,+
+       "Local I/O Read Time": N.N,  +
+       "Local I/O Write Time": N.N, +
        "Temp I/O Read Time": N.N,   +
        "Temp I/O Write Time": N.N   +
      },                             +
-- 
2.42.0