Skip to content

Commit

Permalink
NodeSummary in EXPLAIN ANALYZE
Browse files Browse the repository at this point in the history
Dumps CdbExplain_NodeSummary struct in EXPLAIN ANALYZE

`set gp_enable_explain_node_summary=on;`

`drop table if exists tt; create table tt (a int, b int) distributed randomly;`

`explain (analyze,verbose) insert into tt select * from generate_series(1,1000)a,generate_series(1,1000)b;`

`explain (analyze,verbose) select * from tt where a > b;`

```
                                                                                                               QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Gather Motion 3:1  (slice1; segments: 3)  (cost=0.00..431.00 rows=1 width=8) (actual time=33.612..78.159 rows=1000 loops=1)
   Output: a, b
   Node Summary:                  vmax       vsum       vcnt       imax
     ntuples:                     1000       1000          1         -1
     execmemused:                    0          0          0          0
     workmemused:                    0          0          0          0
     workmemwanted:                  0          0          0          0
     totalWorkfileCreated:           0          0          0          0
     peakMemBalance:             44592      44592          1         -1
     totalPartTableScanned:          0          0          0          0
     segindex0: -1
     ninst: 1
     StatInsts:
       (segN) pstype starttime counter firsttuple startup total ntuples nloops execmemused workmemused workmemwanted workfileCreated firststart peakMemBalance numPartScanned sortMethod sortSpaceType sortSpaceUsed bnotes enotes
       (seg-1) 241 0.00 0.03 0.08 1000.00 1.00 0 0 0 0 0 0 44592.00 0 0 0 0 0 0 0
   ->  Seq Scan on public.tt  (cost=0.00..431.00 rows=1 width=8) (actual time=2.512..77.640 rows=353 loops=1)
         Output: a, b
         Filter: (tt.a = 100)
         Node Summary:                  vmax       vsum       vcnt       imax
           ntuples:                      353       1000          3          0
           execmemused:                    0          0          0          0
           workmemused:                    0          0          0          0
           workmemwanted:                  0          0          0          0
           totalWorkfileCreated:           0          0          0          0
           peakMemBalance:             19072      57216          3          0
           totalPartTableScanned:          0          0          0          0
           segindex0: 0
           ninst: 3
           StatInsts:
             (segN) pstype starttime counter firsttuple startup total ntuples nloops execmemused workmemused workmemwanted workfileCreated firststart peakMemBalance numPartScanned sortMethod sortSpaceType sortSpaceUsed bnotes enotes
             (seg0) 211 0.00 0.00 0.08 353.00 1.00 0 0 0 0 0 0 19072.00 0 0 0 0 0 0 0
             (seg1) 211 0.00 0.00 0.03 330.00 1.00 0 0 0 0 0 0 19072.00 0 0 0 0 0 0 0
             (seg2) 211 0.00 0.00 0.05 317.00 1.00 0 0 0 0 0 0 19072.00 0 0 0 0 0 0 0
 Planning time: 4.514 ms
   (slice0)    Executor memory: 119K bytes.
   (slice1)    Executor memory: 27K bytes avg x 3 workers, 27K bytes max (seg0).
 Memory used:  128000kB
 Optimizer: Pivotal Optimizer (GPORCA)
 Execution time: 78.584 ms
(39 rows)
```
  • Loading branch information
robozmey committed Nov 13, 2024
1 parent ec3ecff commit 6f6849a
Show file tree
Hide file tree
Showing 8 changed files with 285 additions and 0 deletions.
3 changes: 3 additions & 0 deletions src/backend/cdb/cdbvars.c
Original file line number Diff line number Diff line change
Expand Up @@ -281,6 +281,9 @@ int gp_hashagg_groups_per_bucket = 5;
/* Analyzing aid */
int gp_motion_slice_noop = 0;

/* Greenplum Database EXPLAIN Feature GUCs */
bool gp_enable_explain_node_summary = FALSE;

/* Greenplum Database Experimental Feature GUCs */
int gp_distinct_grouping_sets_threshold = 32;
bool gp_enable_explain_rows_out = FALSE;
Expand Down
171 changes: 171 additions & 0 deletions src/backend/commands/explain_gp.c
Original file line number Diff line number Diff line change
Expand Up @@ -1454,6 +1454,44 @@ cdbexplain_formatSeg(char *outbuf, int bufsize, int segindex, int nInst)
} /* cdbexplain_formatSeg */


/*
* cdbexplain_formatAgg
* Convert CdbExplain_Agg to string.
*
* outbuf: [output] pointer to a char buffer to be filled
* bufsize: [input] maximum number of characters to write to outbuf (must be set by the caller)
* CdbExplain_Agg: [input] pointer to a struct CdbExplain_Agg
*/
static void
cdbexplain_formatAgg(char *outbuf, int bufsize, CdbExplain_Agg agg)
{
Assert(outbuf != NULL && "CDBEXPLAIN: char buffer is null");
Assert(bufsize > 0 && "CDBEXPLAIN: size of char buffer is zero");
/* check if truncation occurs */
#ifdef USE_ASSERT_CHECKING
int nchars_written =
#endif /* USE_ASSERT_CHECKING */
snprintf(outbuf, bufsize, "%10.0f %10.0f %10d %10d", agg.vmax, agg.vsum, agg.vcnt, agg.imax);

Assert(nchars_written < bufsize &&
"CDBEXPLAIN: size of char buffer is smaller than the required number of chars");
} /* cdbexplain_formatAgg */


static void
ExplainPropertyAgg(const char *qlabel, CdbExplain_Agg agg, ExplainState *es)
{
ExplainOpenGroup(qlabel, qlabel, true, es);

ExplainPropertyFloat("vmax", agg.vmax, 0, es);
ExplainPropertyFloat("vsum", agg.vsum, 0, es);
ExplainPropertyInteger("vcnt", agg.vcnt, es);
ExplainPropertyInteger("imax", agg.imax, es);

ExplainCloseGroup(qlabel, qlabel, true, es);
}


/*
* cdbexplain_showExecStatsBegin
* Called by qDisp process to create a CdbExplain_ShowStatCtx structure
Expand Down Expand Up @@ -1526,6 +1564,133 @@ nodeSupportWorkfileCaching(PlanState *planstate)
IsA(planstate, MaterialState));
}

void
cdbexplain_NodeSummary(ExplainState *es, CdbExplain_NodeSummary *ns) {
int i;
char aggbuf[100];

if (es->format == EXPLAIN_FORMAT_TEXT)
{
/*
* create a header for all stats: separate each individual stat by an
* underscore, separate the grouped stats for each node by a slash
*/
appendStringInfoSpaces(es->str, es->indent * 2);
appendStringInfoString(es->str, "Node Summary: vmax vsum vcnt imax\n");

int ns_spaces = es->indent * 2 + 2;

appendStringInfoSpaces(es->str, ns_spaces);
cdbexplain_formatAgg(aggbuf, sizeof(aggbuf), ns->ntuples);
appendStringInfo(es->str, "ntuples: %s\n", aggbuf);

appendStringInfoSpaces(es->str, ns_spaces);
cdbexplain_formatAgg(aggbuf, sizeof(aggbuf), ns->execmemused);
appendStringInfo(es->str, "execmemused: %s\n", aggbuf);

appendStringInfoSpaces(es->str, ns_spaces);
cdbexplain_formatAgg(aggbuf, sizeof(aggbuf), ns->workmemused);
appendStringInfo(es->str, "workmemused: %s\n", aggbuf);

appendStringInfoSpaces(es->str, ns_spaces);
cdbexplain_formatAgg(aggbuf, sizeof(aggbuf), ns->workmemwanted);
appendStringInfo(es->str, "workmemwanted: %s\n", aggbuf);

appendStringInfoSpaces(es->str, ns_spaces);
cdbexplain_formatAgg(aggbuf, sizeof(aggbuf), ns->totalWorkfileCreated);
appendStringInfo(es->str, "totalWorkfileCreated: %s\n", aggbuf);

appendStringInfoSpaces(es->str, ns_spaces);
cdbexplain_formatAgg(aggbuf, sizeof(aggbuf), ns->peakMemBalance);
appendStringInfo(es->str, "peakMemBalance: %s\n", aggbuf);

appendStringInfoSpaces(es->str, ns_spaces);
cdbexplain_formatAgg(aggbuf, sizeof(aggbuf), ns->totalPartTableScanned);
appendStringInfo(es->str, "totalPartTableScanned: %s\n", aggbuf);

appendStringInfoSpaces(es->str, ns_spaces);
appendStringInfo(es->str, "segindex0: %d\n", ns->segindex0);

appendStringInfoSpaces(es->str, ns_spaces);
appendStringInfo(es->str, "ninst: %d\n", ns->ninst);

appendStringInfoSpaces(es->str, ns_spaces);
appendStringInfoString(es->str, "StatInsts:\n");
appendStringInfoSpaces(es->str, ns_spaces + 2);
appendStringInfoString(es->str, "(segN) pstype starttime counter firsttuple startup total ntuples nloops execmemused workmemused workmemwanted workfileCreated firststart peakMemBalance numPartScanned sortMethod sortSpaceType sortSpaceUsed bnotes enotes\n");
}
else {
ExplainOpenGroup("CdbExplain_NodeSummary", "CdbExplain_NodeSummary", true, es);

ExplainPropertyAgg("ntuples", ns->ntuples, es);
ExplainPropertyAgg("execmemused", ns->execmemused, es);
ExplainPropertyAgg("workmemused", ns->workmemused, es);
ExplainPropertyAgg("workmemwanted", ns->workmemwanted, es);
ExplainPropertyAgg("totalWorkfileCreated", ns->totalWorkfileCreated, es);
ExplainPropertyAgg("peakMemBalance", ns->peakMemBalance, es);
ExplainPropertyAgg("totalPartTableScanned", ns->totalPartTableScanned, es);

ExplainPropertyInteger("segindex0", ns->segindex0, es);
ExplainPropertyInteger("ninst", ns->ninst, es);

ExplainOpenGroup("CdbExplain_StatInsts", "CdbExplain_StatInsts", false, es);
}
for (i = 0; i < ns->ninst; i++)
{
CdbExplain_StatInst *nsi = &ns->insts[i];

if (es->format == EXPLAIN_FORMAT_TEXT)
{
int nsi_spaces = es->indent * 2 + 4;

appendStringInfoSpaces(es->str, nsi_spaces);

appendStringInfo(es->str, "(seg%d) %d %.2f %.2f %.2f %.2f %.2f %.0f %.0f %.0f %.0f %.0f %d %.2f %.0f %d %d %d %ld %d %d\n",
ns->segindex0 + i,
nsi->pstype,
nsi->starttime.tv_sec, nsi->counter.tv_sec, nsi->firsttuple, nsi->startup, nsi->total,
nsi->ntuples, nsi->nloops, nsi->execmemused, nsi->workmemused, nsi->workmemwanted,
nsi->workfileCreated,
nsi->firststart.tv_sec,
nsi->peakMemBalance,
nsi->numPartScanned, nsi->sortMethod, nsi->sortSpaceType,
nsi->sortSpaceUsed,
nsi->bnotes, nsi->enotes);
}
else
{
ExplainOpenGroup("CdbExplain_StatInst", NULL, true, es);
ExplainPropertyInteger("Segment", ns->segindex0 + i, es);
ExplainPropertyInteger("pstype", nsi->pstype, es);
ExplainPropertyFloat("starttime", nsi->starttime.tv_sec, 2, es);
ExplainPropertyFloat("counter", nsi->counter.tv_sec, 2, es);
ExplainPropertyFloat("firsttuple", nsi->firsttuple, 2, es);
ExplainPropertyFloat("startup", nsi->startup, 2, es);
ExplainPropertyFloat("total", nsi->total, 2, es);
ExplainPropertyFloat("ntuples", nsi->ntuples, 0, es);
ExplainPropertyFloat("nloops", nsi->nloops, 0, es);
ExplainPropertyFloat("execmemused", nsi->execmemused, 0, es);
ExplainPropertyFloat("workmemused", nsi->workmemused, 0, es);
ExplainPropertyFloat("workmemwanted", nsi->workmemwanted, 0, es);
ExplainPropertyInteger("workfileCreated", nsi->workfileCreated, es);
ExplainPropertyFloat("firststart", nsi->firststart.tv_sec, 2, es);
ExplainPropertyFloat("peakMemBalance", nsi->peakMemBalance, 0, es);
ExplainPropertyInteger("numPartScanned", nsi->numPartScanned, es);
ExplainPropertyInteger("sortMethod", nsi->sortMethod, es);
ExplainPropertyInteger("sortSpaceType", nsi->sortSpaceType, es);
ExplainPropertyLong("sortSpaceUsed", nsi->sortSpaceUsed, es);
ExplainPropertyInteger("bnotes", nsi->bnotes, es);
ExplainPropertyInteger("enotes", nsi->enotes, es);
ExplainCloseGroup("CdbExplain_StatInst", NULL, true, es);
}
}

if (es->format != EXPLAIN_FORMAT_TEXT) {
ExplainCloseGroup("CdbExplain_StatInsts", "CdbExplain_StatInsts", false, es);
ExplainCloseGroup("CdbExplain_NodeSummary", "CdbExplain_NodeSummary", true, es);
}
} /* cdbexplain_NodeSummary */

/*
* cdbexplain_showExecStats
* Called by qDisp process to format a node's EXPLAIN ANALYZE statistics.
Expand Down Expand Up @@ -1974,6 +2139,12 @@ cdbexplain_showExecStats(struct PlanState *planstate, ExplainState *es)
else
ExplainCloseGroup("Allstat", "Allstat", true, es);
}
/*
* Dump CdbExplain_NodeSummary
*/
if (gp_enable_explain_node_summary) {
cdbexplain_NodeSummary(es, ns);
}
} /* cdbexplain_showExecStats */

/*
Expand Down
11 changes: 11 additions & 0 deletions src/backend/utils/misc/guc_gp.c
Original file line number Diff line number Diff line change
Expand Up @@ -891,6 +891,17 @@ struct config_bool ConfigureNamesBool_gp[] =
NULL, NULL, NULL
},

{
{"gp_enable_explain_node_summary", PGC_USERSET, CLIENT_CONN_OTHER,
gettext_noop("Dump CdbExplain_NodeSummary for every node in EXPLAIN ANALYZE."),
NULL,
GUC_NO_SHOW_ALL | GUC_NOT_IN_SAMPLE
},
&gp_enable_explain_node_summary,
false,
NULL, NULL, NULL
},

{
{"gp_enable_sort_limit", PGC_USERSET, QUERY_TUNING_METHOD,
gettext_noop("Enable LIMIT operation to be performed while sorting."),
Expand Down
6 changes: 6 additions & 0 deletions src/include/cdb/cdbvars.h
Original file line number Diff line number Diff line change
Expand Up @@ -754,6 +754,12 @@ extern bool gp_enable_explain_rows_out;
*/
extern bool gp_enable_explain_allstat;

/* May Greenplum dump node summary from CdbExplain_NodeSummary
* during EXPLAIN ANALYZE?
*
*/
extern bool gp_enable_explain_node_summary;

/* May Greenplum restrict ORDER BY sorts to the first N rows if the ORDER BY
* is wrapped by a LIMIT clause (where N=OFFSET+LIMIT)?
*
Expand Down
1 change: 1 addition & 0 deletions src/include/utils/unsync_guc_name.h
Original file line number Diff line number Diff line change
Expand Up @@ -174,6 +174,7 @@
"gp_enable_exchange_default_partition",
"gp_enable_explain_rows_out",
"gp_enable_explain_allstat",
"gp_enable_explain_node_summary",
"gp_enable_fast_sri",
"gp_enable_global_deadlock_detector",
"gp_enable_gpperfmon",
Expand Down
44 changes: 44 additions & 0 deletions src/test/regress/expected/gp_explain.out
Original file line number Diff line number Diff line change
Expand Up @@ -349,6 +349,50 @@ explain analyze SELECT * FROM explaintest;
(8 rows)

set gp_enable_explain_rows_out=DEFAULT;
-- Test explain node summary.
set gp_enable_explain_node_summary=on;
explain analyze SELECT * FROM explaintest;
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Gather Motion 3:1 (slice1; segments: 3) (cost=0.00..431.00 rows=10 width=4) (actual time=0.476..0.484 rows=10 loops=1)
Node Summary: vmax vsum vcnt imax
ntuples: 10 10 1 -1
execmemused: 0 0 0 0
workmemused: 0 0 0 0
workmemwanted: 0 0 0 0
totalWorkfileCreated: 0 0 0 0
peakMemBalance: 5336 5336 1 -1
totalPartTableScanned: 0 0 0 0
segindex0: -1
ninst: 1
StatInsts:
(segN) pstype starttime counter firsttuple startup total ntuples nloops execmemused workmemused workmemwanted workfileCreated firststart peakMemBalance numPartScanned sortMethod sortSpaceType sortSpaceUsed bnotes enotes
(seg-1) 241 0.00 0.00 0.00 10.00 1.00 0 0 0 0 0 0 5336.00 0 0 0 0 0 0 0
-> Seq Scan on explaintest (cost=0.00..431.00 rows=4 width=4) (actual time=0.017..0.018 rows=5 loops=1)
Node Summary: vmax vsum vcnt imax
ntuples: 5 10 3 0
execmemused: 0 0 0 0
workmemused: 0 0 0 0
workmemwanted: 0 0 0 0
totalWorkfileCreated: 0 0 0 0
peakMemBalance: 15872 47616 3 0
totalPartTableScanned: 0 0 0 0
segindex0: 0
ninst: 3
StatInsts:
(segN) pstype starttime counter firsttuple startup total ntuples nloops execmemused workmemused workmemwanted workfileCreated firststart peakMemBalance numPartScanned sortMethod sortSpaceType sortSpaceUsed bnotes enotes
(seg0) 211 0.00 0.00 0.00 5.00 1.00 0 0 0 0 0 0 15872.00 0 0 0 0 0 0 0
(seg1) 211 0.00 0.00 0.00 1.00 1.00 0 0 0 0 0 0 15872.00 0 0 0 0 0 0 0
(seg2) 211 0.00 0.00 0.00 4.00 1.00 0 0 0 0 0 0 15872.00 0 0 0 0 0 0 0
Planning time: 6.834 ms
(slice0) Executor memory: 27K bytes.
(slice1) Executor memory: 25K bytes avg x 3 workers, 25K bytes max (seg0).
Memory used: 128000kB
Optimizer: Pivotal Optimizer (GPORCA)
Execution time: 0.900 ms
(36 rows)

set gp_enable_explain_node_summary=DEFAULT;
--
-- Test output of EXPLAIN ANALYZE for Bitmap index scan's actual rows.
--
Expand Down
44 changes: 44 additions & 0 deletions src/test/regress/expected/gp_explain_optimizer.out
Original file line number Diff line number Diff line change
Expand Up @@ -380,6 +380,50 @@ explain analyze SELECT * FROM explaintest;
(8 rows)

set gp_enable_explain_rows_out=DEFAULT;
-- Test explain node summary.
set gp_enable_explain_node_summary=on;
explain analyze SELECT * FROM explaintest;
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Gather Motion 3:1 (slice1; segments: 3) (cost=0.00..431.00 rows=10 width=4) (actual time=0.476..0.484 rows=10 loops=1)
Node Summary: vmax vsum vcnt imax
ntuples: 10 10 1 -1
execmemused: 0 0 0 0
workmemused: 0 0 0 0
workmemwanted: 0 0 0 0
totalWorkfileCreated: 0 0 0 0
peakMemBalance: 5336 5336 1 -1
totalPartTableScanned: 0 0 0 0
segindex0: -1
ninst: 1
StatInsts:
(segN) pstype starttime counter firsttuple startup total ntuples nloops execmemused workmemused workmemwanted workfileCreated firststart peakMemBalance numPartScanned sortMethod sortSpaceType sortSpaceUsed bnotes enotes
(seg-1) 241 0.00 0.00 0.00 10.00 1.00 0 0 0 0 0 0 5336.00 0 0 0 0 0 0 0
-> Seq Scan on explaintest (cost=0.00..431.00 rows=4 width=4) (actual time=0.017..0.018 rows=5 loops=1)
Node Summary: vmax vsum vcnt imax
ntuples: 5 10 3 0
execmemused: 0 0 0 0
workmemused: 0 0 0 0
workmemwanted: 0 0 0 0
totalWorkfileCreated: 0 0 0 0
peakMemBalance: 15872 47616 3 0
totalPartTableScanned: 0 0 0 0
segindex0: 0
ninst: 3
StatInsts:
(segN) pstype starttime counter firsttuple startup total ntuples nloops execmemused workmemused workmemwanted workfileCreated firststart peakMemBalance numPartScanned sortMethod sortSpaceType sortSpaceUsed bnotes enotes
(seg0) 211 0.00 0.00 0.00 5.00 1.00 0 0 0 0 0 0 15872.00 0 0 0 0 0 0 0
(seg1) 211 0.00 0.00 0.00 1.00 1.00 0 0 0 0 0 0 15872.00 0 0 0 0 0 0 0
(seg2) 211 0.00 0.00 0.00 4.00 1.00 0 0 0 0 0 0 15872.00 0 0 0 0 0 0 0
Planning time: 6.834 ms
(slice0) Executor memory: 27K bytes.
(slice1) Executor memory: 25K bytes avg x 3 workers, 25K bytes max (seg0).
Memory used: 128000kB
Optimizer: Pivotal Optimizer (GPORCA)
Execution time: 0.900 ms
(36 rows)

set gp_enable_explain_node_summary=DEFAULT;
--
-- Test output of EXPLAIN ANALYZE for Bitmap index scan's actual rows.
--
Expand Down
5 changes: 5 additions & 0 deletions src/test/regress/sql/gp_explain.sql
Original file line number Diff line number Diff line change
Expand Up @@ -161,6 +161,11 @@ set gp_enable_explain_rows_out=on;
explain analyze SELECT * FROM explaintest;
set gp_enable_explain_rows_out=DEFAULT;

-- Test explain node summary.
set gp_enable_explain_node_summary=on;
explain analyze SELECT * FROM explaintest;
set gp_enable_explain_node_summary=DEFAULT;

--
-- Test output of EXPLAIN ANALYZE for Bitmap index scan's actual rows.
--
Expand Down

0 comments on commit 6f6849a

Please sign in to comment.