Fix some inconsistencies in EXPLAIN output
authorDavid Rowley <drowley@postgresql.org>
Thu, 16 May 2024 00:50:16 +0000 (12:50 +1200)
committerDavid Rowley <drowley@postgresql.org>
Thu, 16 May 2024 00:50:16 +0000 (12:50 +1200)
06286709e added a SERIALIZE option to EXPLAIN which included showing the
amount of kilobytes serialized.  The calculation to convert bytes into
kilobytes wasn't consistent with how that's done in the rest of EXPLAIN.
Traditionally we round up to the nearest kB, but the new code rounded to
the nearest kB.

To fix this, invent a macro that does the conversion and use that macro
everywhere that requires this conversion.

Additionally, 5de890e36 added EXPLAIN (MEMORY) but included the memory
sizes in bytes.  Convert these values to kilobytes to align with the
other memory related outputs.

In passing, swap out a "long" type in show_hash_info() and use a uint64
instead.  We do support platforms where sizeof(Size) == 8 and
sizeof(long) == 4, so using a long there is questionable.

Reported-by: jian he
Reviewed-by: jian he
Discussion: https://www.postgresql.org/message-id/CACJufxE4Sp7xvgOwhqtFx5hS85AxMKobPWDo-xZHZVTpK3EBjA@mail.gmail.com

src/backend/commands/explain.c
src/test/regress/expected/explain.out

index c0c73aa3c9c742ba60a586bff8e8845f3615450c..94511a5a02490d03c80f1ef188a2a9674f1dcdb4 100644 (file)
@@ -62,6 +62,12 @@ typedef struct SerializeMetrics
 #define X_CLOSE_IMMEDIATE 2
 #define X_NOWHITESPACE 4
 
+/*
+ * Various places within need to convert bytes to kilobytes.  Round these up
+ * to the next whole kilobyte.
+ */
+#define BYTES_TO_KILOBYTES(b) (((b) + 1023) / 1024)
+
 static void ExplainOneQuery(Query *query, int cursorOptions,
                                                        IntoClause *into, ExplainState *es,
                                                        const char *queryString, ParamListInfo params,
@@ -1120,11 +1126,11 @@ ExplainPrintSerialize(ExplainState *es, SerializeMetrics *metrics)
                if (es->timing)
                        appendStringInfo(es->str, "Serialization: time=%.3f ms  output=" UINT64_FORMAT "kB  format=%s\n",
                                                         1000.0 * INSTR_TIME_GET_DOUBLE(metrics->timeSpent),
-                                                        (metrics->bytesSent + 512) / 1024,
+                                                        BYTES_TO_KILOBYTES(metrics->bytesSent),
                                                         format);
                else
                        appendStringInfo(es->str, "Serialization: output=" UINT64_FORMAT "kB  format=%s\n",
-                                                        (metrics->bytesSent + 512) / 1024,
+                                                        BYTES_TO_KILOBYTES(metrics->bytesSent),
                                                         format);
 
                if (es->buffers && peek_buffer_usage(es, &metrics->bufferUsage))
@@ -1141,7 +1147,7 @@ ExplainPrintSerialize(ExplainState *es, SerializeMetrics *metrics)
                                                                 1000.0 * INSTR_TIME_GET_DOUBLE(metrics->timeSpent),
                                                                 3, es);
                ExplainPropertyUInteger("Output Volume", "kB",
-                                                               (metrics->bytesSent + 512) / 1024, es);
+                                                               BYTES_TO_KILOBYTES(metrics->bytesSent), es);
                ExplainPropertyText("Format", format, es);
                if (es->buffers)
                        show_buffer_usage(es, &metrics->bufferUsage);
@@ -3275,7 +3281,7 @@ show_hash_info(HashState *hashstate, ExplainState *es)
 
        if (hinstrument.nbatch > 0)
        {
-               long            spacePeakKb = (hinstrument.space_peak + 1023) / 1024;
+               uint64          spacePeakKb = BYTES_TO_KILOBYTES(hinstrument.space_peak);
 
                if (es->format != EXPLAIN_FORMAT_TEXT)
                {
@@ -3287,15 +3293,15 @@ show_hash_info(HashState *hashstate, ExplainState *es)
                                                                   hinstrument.nbatch, es);
                        ExplainPropertyInteger("Original Hash Batches", NULL,
                                                                   hinstrument.nbatch_original, es);
-                       ExplainPropertyInteger("Peak Memory Usage", "kB",
-                                                                  spacePeakKb, es);
+                       ExplainPropertyUInteger("Peak Memory Usage", "kB",
+                                                                       spacePeakKb, es);
                }
                else if (hinstrument.nbatch_original != hinstrument.nbatch ||
                                 hinstrument.nbuckets_original != hinstrument.nbuckets)
                {
                        ExplainIndentText(es);
                        appendStringInfo(es->str,
-                                                        "Buckets: %d (originally %d)  Batches: %d (originally %d)  Memory Usage: %ldkB\n",
+                                                        "Buckets: %d (originally %d)  Batches: %d (originally %d)  Memory Usage: " UINT64_FORMAT "kB\n",
                                                         hinstrument.nbuckets,
                                                         hinstrument.nbuckets_original,
                                                         hinstrument.nbatch,
@@ -3306,7 +3312,7 @@ show_hash_info(HashState *hashstate, ExplainState *es)
                {
                        ExplainIndentText(es);
                        appendStringInfo(es->str,
-                                                        "Buckets: %d  Batches: %d  Memory Usage: %ldkB\n",
+                                                        "Buckets: %d  Batches: %d  Memory Usage: " UINT64_FORMAT "kB\n",
                                                         hinstrument.nbuckets, hinstrument.nbatch,
                                                         spacePeakKb);
                }
@@ -3376,9 +3382,9 @@ show_memoize_info(MemoizeState *mstate, List *ancestors, ExplainState *es)
                 * when mem_peak is 0.
                 */
                if (mstate->stats.mem_peak > 0)
-                       memPeakKb = (mstate->stats.mem_peak + 1023) / 1024;
+                       memPeakKb = BYTES_TO_KILOBYTES(mstate->stats.mem_peak);
                else
-                       memPeakKb = (mstate->mem_used + 1023) / 1024;
+                       memPeakKb = BYTES_TO_KILOBYTES(mstate->mem_used);
 
                if (es->format != EXPLAIN_FORMAT_TEXT)
                {
@@ -3427,7 +3433,7 @@ show_memoize_info(MemoizeState *mstate, List *ancestors, ExplainState *es)
                 * MemoizeInstrumentation.mem_peak field for us.  No need to do the
                 * zero checks like we did for the serial case above.
                 */
-               memPeakKb = (si->mem_peak + 1023) / 1024;
+               memPeakKb = BYTES_TO_KILOBYTES(si->mem_peak);
 
                if (es->format == EXPLAIN_FORMAT_TEXT)
                {
@@ -3464,7 +3470,7 @@ static void
 show_hashagg_info(AggState *aggstate, ExplainState *es)
 {
        Agg                *agg = (Agg *) aggstate->ss.ps.plan;
-       int64           memPeakKb = (aggstate->hash_mem_peak + 1023) / 1024;
+       int64           memPeakKb = BYTES_TO_KILOBYTES(aggstate->hash_mem_peak);
 
        if (agg->aggstrategy != AGG_HASHED &&
                agg->aggstrategy != AGG_MIXED)
@@ -3545,7 +3551,7 @@ show_hashagg_info(AggState *aggstate, ExplainState *es)
                                continue;
                        hash_disk_used = sinstrument->hash_disk_used;
                        hash_batches_used = sinstrument->hash_batches_used;
-                       memPeakKb = (sinstrument->hash_mem_peak + 1023) / 1024;
+                       memPeakKb = BYTES_TO_KILOBYTES(sinstrument->hash_mem_peak);
 
                        if (es->workers_state)
                                ExplainOpenWorker(n, es);
@@ -3942,22 +3948,22 @@ show_wal_usage(ExplainState *es, const WalUsage *usage)
 static void
 show_memory_counters(ExplainState *es, const MemoryContextCounters *mem_counters)
 {
+       int64           memUsedkB = BYTES_TO_KILOBYTES(mem_counters->totalspace -
+                                                                                          mem_counters->freespace);
+       int64           memAllocatedkB = BYTES_TO_KILOBYTES(mem_counters->totalspace);
+
        if (es->format == EXPLAIN_FORMAT_TEXT)
        {
                ExplainIndentText(es);
                appendStringInfo(es->str,
-                                                "Memory: used=%lld bytes  allocated=%lld bytes",
-                                                (long long) (mem_counters->totalspace - mem_counters->freespace),
-                                                (long long) mem_counters->totalspace);
+                                                "Memory: used=" INT64_FORMAT "kB  allocated=" INT64_FORMAT "kB",
+                                                memUsedkB, memAllocatedkB);
                appendStringInfoChar(es->str, '\n');
        }
        else
        {
-               ExplainPropertyInteger("Memory Used", "bytes",
-                                                          mem_counters->totalspace - mem_counters->freespace,
-                                                          es);
-               ExplainPropertyInteger("Memory Allocated", "bytes",
-                                                          mem_counters->totalspace, es);
+               ExplainPropertyInteger("Memory Used", "kB", memUsedkB, es);
+               ExplainPropertyInteger("Memory Allocated", "kB", memAllocatedkB, es);
        }
 }
 
index 703800d856dc72358995ed67bbe0dc26e0453088..6585c6a69efe45d4eefd674425762df69dfd9bef 100644 (file)
@@ -345,14 +345,14 @@ select explain_filter('explain (memory) select * from int8_tbl i8');
                      explain_filter                      
 ---------------------------------------------------------
  Seq Scan on int8_tbl i8  (cost=N.N..N.N rows=N width=N)
-   Memory: used=N bytes  allocated=N bytes
+   Memory: used=NkB  allocated=NkB
 (2 rows)
 
 select explain_filter('explain (memory, analyze) select * from int8_tbl i8');
                                         explain_filter                                         
 -----------------------------------------------------------------------------------------------
  Seq Scan on int8_tbl i8  (cost=N.N..N.N rows=N width=N) (actual time=N.N..N.N rows=N loops=N)
-   Memory: used=N bytes  allocated=N bytes
+   Memory: used=NkB  allocated=NkB
  Planning Time: N.N ms
  Execution Time: N.N ms
 (4 rows)
@@ -413,7 +413,7 @@ select explain_filter('explain (memory) execute int8_query');
                      explain_filter                      
 ---------------------------------------------------------
  Seq Scan on int8_tbl i8  (cost=N.N..N.N rows=N width=N)
-   Memory: used=N bytes  allocated=N bytes
+   Memory: used=NkB  allocated=NkB
 (2 rows)
 
 -- Test EXPLAIN (GENERIC_PLAN) with partition pruning