Movatterモバイル変換

[0]ホーム
URL:

Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

 Sign up
Appearance settings

Commit16bc2d1

Browse files
author
Maksim Milyutin
committed
Apply patches for pg_query_state extension
1 parent18061a5 commit16bc2d1

File tree

9 files changed

+282
-27
lines changed

9 files changed

+282
-27
lines changed

‎src/backend/commands/explain.c

Lines changed: 126 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -653,15 +653,35 @@ report_triggers(ResultRelInfo *rInfo, bool show_relname, ExplainState *es)
653653
Instrumentation*instr=rInfo->ri_TrigInstrument+nt;
654654
char*relname;
655655
char*conname=NULL;
656+
instr_timestarttimespan;
657+
doubletotal;
658+
doublentuples;
659+
doublencalls;
656660

657-
/* Must clean up instrumentation state */
658-
InstrEndLoop(instr);
661+
if (!es->runtime)
662+
{
663+
/* Must clean up instrumentation state */
664+
InstrEndLoop(instr);
665+
}
666+
667+
/* Collect statistic variables */
668+
if (!INSTR_TIME_IS_ZERO(instr->starttime))
669+
{
670+
INSTR_TIME_SET_CURRENT(starttimespan);
671+
INSTR_TIME_SUBTRACT(starttimespan,instr->starttime);
672+
}
673+
else
674+
INSTR_TIME_SET_ZERO(starttimespan);
675+
total=instr->total+INSTR_TIME_GET_DOUBLE(instr->counter)
676+
+INSTR_TIME_GET_DOUBLE(starttimespan);
677+
ntuples=instr->ntuples+instr->tuplecount;
678+
ncalls=ntuples+ !INSTR_TIME_IS_ZERO(starttimespan);
659679

660680
/*
661681
* We ignore triggers that were never invoked; they likely aren't
662682
* relevant to the current query type.
663683
*/
664-
if (instr->ntuples==0)
684+
if (ncalls==0)
665685
continue;
666686

667687
ExplainOpenGroup("Trigger",NULL, true,es);
@@ -687,9 +707,9 @@ report_triggers(ResultRelInfo *rInfo, bool show_relname, ExplainState *es)
687707
appendStringInfo(es->str," on %s",relname);
688708
if (es->timing)
689709
appendStringInfo(es->str,": time=%.3f calls=%.0f\n",
690-
1000.0*instr->total,instr->ntuples);
710+
1000.0*total,ncalls);
691711
else
692-
appendStringInfo(es->str,": calls=%.0f\n",instr->ntuples);
712+
appendStringInfo(es->str,": calls=%.0f\n",ncalls);
693713
}
694714
else
695715
{
@@ -698,8 +718,8 @@ report_triggers(ResultRelInfo *rInfo, bool show_relname, ExplainState *es)
698718
ExplainPropertyText("Constraint Name",conname,es);
699719
ExplainPropertyText("Relation",relname,es);
700720
if (es->timing)
701-
ExplainPropertyFloat("Time",1000.0*instr->total,3,es);
702-
ExplainPropertyFloat("Calls",instr->ntuples,0,es);
721+
ExplainPropertyFloat("Time",1000.0*total,3,es);
722+
ExplainPropertyFloat("Calls",ncalls,0,es);
703723
}
704724

705725
if (conname)
@@ -1247,8 +1267,11 @@ ExplainNode(PlanState *planstate, List *ancestors,
12471267
* instrumentation results the user didn't ask for. But we do the
12481268
* InstrEndLoop call anyway, if possible, to reduce the number of cases
12491269
* auto_explain has to contend with.
1270+
*
1271+
* if flag es->stateinfo is set i.e. when printing the current execution state
1272+
* this step of cleaning up is miss
12501273
*/
1251-
if (planstate->instrument)
1274+
if (planstate->instrument&& !es->runtime)
12521275
InstrEndLoop(planstate->instrument);
12531276

12541277
if (es->analyze&&
@@ -1281,7 +1304,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
12811304
ExplainPropertyFloat("Actual Loops",nloops,0,es);
12821305
}
12831306
}
1284-
elseif (es->analyze)
1307+
elseif (es->analyze&& !es->runtime)
12851308
{
12861309
if (es->format==EXPLAIN_FORMAT_TEXT)
12871310
appendStringInfoString(es->str," (never executed)");
@@ -1297,6 +1320,75 @@ ExplainNode(PlanState *planstate, List *ancestors,
12971320
}
12981321
}
12991322

1323+
/*
1324+
* print the progress of node execution at current loop
1325+
*/
1326+
if (planstate->instrument&&es->analyze&&es->runtime)
1327+
{
1328+
instr_timestarttimespan;
1329+
doublestartup_sec;
1330+
doubletotal_sec;
1331+
doublerows;
1332+
doubleloop_num;
1333+
boolfinished;
1334+
1335+
if (!INSTR_TIME_IS_ZERO(planstate->instrument->starttime))
1336+
{
1337+
INSTR_TIME_SET_CURRENT(starttimespan);
1338+
INSTR_TIME_SUBTRACT(starttimespan,planstate->instrument->starttime);
1339+
}
1340+
else
1341+
INSTR_TIME_SET_ZERO(starttimespan);
1342+
startup_sec=1000.0*planstate->instrument->firsttuple;
1343+
total_sec=1000.0* (INSTR_TIME_GET_DOUBLE(planstate->instrument->counter)
1344+
+INSTR_TIME_GET_DOUBLE(starttimespan));
1345+
rows=planstate->instrument->tuplecount;
1346+
loop_num=planstate->instrument->nloops+1;
1347+
1348+
finished=planstate->instrument->nloops>0
1349+
&& !planstate->instrument->running
1350+
&&INSTR_TIME_IS_ZERO(starttimespan);
1351+
1352+
if (!finished)
1353+
{
1354+
ExplainOpenGroup("Current loop","Current loop", true,es);
1355+
if (es->format==EXPLAIN_FORMAT_TEXT)
1356+
{
1357+
if (es->timing)
1358+
{
1359+
if (planstate->instrument->running)
1360+
appendStringInfo(es->str,
1361+
" (Current loop: actual time=%.3f..%.3f rows=%.0f, loop number=%.0f)",
1362+
startup_sec,total_sec,rows,loop_num);
1363+
else
1364+
appendStringInfo(es->str,
1365+
" (Current loop: running time=%.3f actual rows=0, loop number=%.0f)",
1366+
total_sec,loop_num);
1367+
}
1368+
else
1369+
appendStringInfo(es->str,
1370+
" (Current loop: actual rows=%.0f, loop number=%.0f)",
1371+
rows,loop_num);
1372+
}
1373+
else
1374+
{
1375+
ExplainPropertyFloat("Actual Loop Number",loop_num,0,es);
1376+
if (es->timing)
1377+
{
1378+
if (planstate->instrument->running)
1379+
{
1380+
ExplainPropertyFloat("Actual Startup Time",startup_sec,3,es);
1381+
ExplainPropertyFloat("Actual Total Time",total_sec,3,es);
1382+
}
1383+
else
1384+
ExplainPropertyFloat("Running Time",total_sec,3,es);
1385+
}
1386+
ExplainPropertyFloat("Actual Rows",rows,0,es);
1387+
}
1388+
ExplainCloseGroup("Current loop","Current loop", true,es);
1389+
}
1390+
}
1391+
13001392
/* in text format, first line ends here */
13011393
if (es->format==EXPLAIN_FORMAT_TEXT)
13021394
appendStringInfoChar(es->str,'\n');
@@ -2293,20 +2385,17 @@ show_instrumentation_count(const char *qlabel, int which,
22932385
if (!es->analyze|| !planstate->instrument)
22942386
return;
22952387

2388+
nloops=planstate->instrument->nloops;
22962389
if (which==2)
2297-
nfiltered=planstate->instrument->nfiltered2;
2390+
nfiltered= ((nloops>0) ?planstate->instrument->accum_nfiltered2 /nloops :0)
2391+
+planstate->instrument->nfiltered2;
22982392
else
2299-
nfiltered=planstate->instrument->nfiltered1;
2300-
nloops=planstate->instrument->nloops;
2393+
nfiltered=((nloops>0) ?planstate->instrument->accum_nfiltered1 /nloops :0)
2394+
+planstate->instrument->nfiltered1;
23012395

23022396
/* In text mode, suppress zero counts; they're not interesting enough */
23032397
if (nfiltered>0||es->format!=EXPLAIN_FORMAT_TEXT)
2304-
{
2305-
if (nloops>0)
2306-
ExplainPropertyFloat(qlabel,nfiltered /nloops,0,es);
2307-
else
2308-
ExplainPropertyFloat(qlabel,0.0,0,es);
2309-
}
2398+
ExplainPropertyFloat(qlabel,nfiltered,0,es);
23102399
}
23112400

23122401
/*
@@ -2658,14 +2747,28 @@ show_modifytable_info(ModifyTableState *mtstate, List *ancestors,
26582747
doubleinsert_path;
26592748
doubleother_path;
26602749

2661-
InstrEndLoop(mtstate->mt_plans[0]->instrument);
2750+
if (!es->runtime)
2751+
InstrEndLoop(mtstate->mt_plans[0]->instrument);
26622752

26632753
/* count the number of source rows */
2664-
total=mtstate->mt_plans[0]->instrument->ntuples;
2665-
other_path=mtstate->ps.instrument->nfiltered2;
2666-
insert_path=total-other_path;
2754+
other_path=mtstate->ps.instrument->accum_nfiltered2
2755+
+mtstate->ps.instrument->nfiltered2;
2756+
2757+
/*
2758+
* Insert occurs after extracting row from subplan and in runtime mode
2759+
* we can appear between these two operations - situation when
2760+
* total > insert_path + other_path. Therefore we don't know exactly
2761+
* whether last row from subplan is inserted.
2762+
* We don't print inserted tuples in runtime mode in order to not print
2763+
* inconsistent data
2764+
*/
2765+
if (!es->runtime)
2766+
{
2767+
total=mtstate->mt_plans[0]->instrument->ntuples;
2768+
insert_path=total-other_path;
2769+
ExplainPropertyFloat("Tuples Inserted",insert_path,0,es);
2770+
}
26672771

2668-
ExplainPropertyFloat("Tuples Inserted",insert_path,0,es);
26692772
ExplainPropertyFloat("Conflicting Tuples",other_path,0,es);
26702773
}
26712774
}

‎src/backend/executor/execProcnode.c

Lines changed: 13 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -115,7 +115,6 @@
115115
#include"executor/nodeWorktablescan.h"
116116
#include"miscadmin.h"
117117

118-
119118
/* ------------------------------------------------------------------------
120119
*ExecInitNode
121120
*
@@ -356,6 +355,9 @@ ExecInitNode(Plan *node, EState *estate, int eflags)
356355
returnresult;
357356
}
358357

358+
/* Hooks for plugins to pre/post process ExecProcNode */
359+
PreExecProcNode_hook_typepreExecProcNode_hook=NULL;
360+
PostExecProcNode_hook_typepostExecProcNode_hook=NULL;
359361

360362
/* ----------------------------------------------------------------
361363
*ExecProcNode
@@ -374,7 +376,12 @@ ExecProcNode(PlanState *node)
374376
ExecReScan(node);/* let ReScan handle this */
375377

376378
if (node->instrument)
379+
{
380+
if (preExecProcNode_hook)
381+
preExecProcNode_hook(node);
382+
377383
InstrStartNode(node->instrument);
384+
}
378385

379386
switch (nodeTag(node))
380387
{
@@ -527,8 +534,13 @@ ExecProcNode(PlanState *node)
527534
}
528535

529536
if (node->instrument)
537+
{
530538
InstrStopNode(node->instrument,TupIsNull(result) ?0.0 :1.0);
531539

540+
if (postExecProcNode_hook)
541+
postExecProcNode_hook(node,result);
542+
}
543+
532544
returnresult;
533545
}
534546

‎src/backend/executor/instrument.c

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -118,13 +118,17 @@ InstrEndLoop(Instrumentation *instr)
118118
instr->total+=totaltime;
119119
instr->ntuples+=instr->tuplecount;
120120
instr->nloops+=1;
121+
instr->accum_nfiltered1+=instr->nfiltered1;
122+
instr->accum_nfiltered2+=instr->nfiltered2;
121123

122124
/* Reset for next cycle (if any) */
123125
instr->running= false;
124126
INSTR_TIME_SET_ZERO(instr->starttime);
125127
INSTR_TIME_SET_ZERO(instr->counter);
126128
instr->firsttuple=0;
127129
instr->tuplecount=0;
130+
instr->nfiltered1=0;
131+
instr->nfiltered2=0;
128132
}
129133

130134
/* dst += add - sub */

0 commit comments

Comments
 (0)
[8]ページ先頭
©2009-2025 Movatter.jp