track_io_timing logging: Don't special case 0 ms.

petergeoghegan · petergeoghegan · commit bda822554b96 · 2021-08-27T13:34:00.000-07:00
Adjust track_io_timing related logging code added by commit 94d13d4. Make it consistent with other nearby autovacuum and autoanalyze logging code by removing logic that suppressed zero millisecond outputs. log_autovacuum_min_duration log output now reliably shows "read:" and "write:" millisecond-based values in its report (when track_io_timing is enabled). Author: Peter Geoghegan <pg@bowt.ie> Reviewed-By: Stephen Frost <sfrost@snowman.net> Discussion: https://postgr.es/m/CAH2-WznW0FNxSVQMSRazAMYNfZ6DR_gr5WE78hc6E1CBkkJpzw@mail.gmail.com Backpatch: 14-, where the track_io_timing logging was introduced.
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
@@ -840,16 +840,11 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
 			}
 			if (track_io_timing)
 			{
-				appendStringInfoString(&buf, _("I/O timings:"));
-				if (pgStatBlockReadTime - startreadtime > 0)
-					appendStringInfo(&buf, _(" read: %.3f ms"),
-									 (double) (pgStatBlockReadTime - startreadtime) / 1000);
-				if ((pgStatBlockReadTime - startreadtime > 0) && (pgStatBlockWriteTime - startwritetime > 0))
-					appendStringInfoString(&buf, _(","));
-				if (pgStatBlockWriteTime - startwritetime > 0)
-					appendStringInfo(&buf, _(" write: %.3f ms"),
-									 (double) (pgStatBlockWriteTime - startwritetime) / 1000);
-				appendStringInfoChar(&buf, '\n');
+				double		read_ms = (double) (pgStatBlockReadTime - startreadtime) / 1000;
+				double		write_ms = (double) (pgStatBlockWriteTime - startwritetime) / 1000;
+
+				appendStringInfo(&buf, _("I/O timings: read: %.3f ms, write: %.3f ms\n"),
+								 read_ms, write_ms);
 			}
 			appendStringInfo(&buf, _("avg read rate: %.3f MB/s, avg write rate: %.3f MB/s\n"),
 							 read_rate, write_rate);
diff --git a/src/backend/commands/analyze.c b/src/backend/commands/analyze.c
@@ -779,16 +779,11 @@ do_analyze_rel(Relation onerel, VacuumParams *params,
 							 RelationGetRelationName(onerel));
 			if (track_io_timing)
 			{
-				appendStringInfoString(&buf, _("I/O timings:"));
-				if (pgStatBlockReadTime - startreadtime > 0)
-					appendStringInfo(&buf, _(" read: %.3f ms"),
-									 (double) (pgStatBlockReadTime - startreadtime) / 1000);
-				if ((pgStatBlockReadTime - startreadtime > 0) && (pgStatBlockWriteTime - startwritetime > 0))
-					appendStringInfoString(&buf, _(","));
-				if (pgStatBlockWriteTime - startwritetime > 0)
-					appendStringInfo(&buf, _(" write: %.3f ms"),
-									 (double) (pgStatBlockWriteTime - startwritetime) / 1000);
-				appendStringInfoChar(&buf, '\n');
+				double		read_ms = (double) (pgStatBlockReadTime - startreadtime) / 1000;
+				double		write_ms = (double) (pgStatBlockWriteTime - startwritetime) / 1000;
+
+				appendStringInfo(&buf, _("I/O timings: read: %.3f ms, write: %.3f ms\n"),
+								 read_ms, write_ms);
 			}
 			appendStringInfo(&buf, _("avg read rate: %.3f MB/s, avg write rate: %.3f MB/s\n"),
 							 read_rate, write_rate);
