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

Commita0c217f

Browse files
author
Maksim Milyutin
committed
Apply patch to postgres core
1 parentf37f286 commita0c217f

File tree

7 files changed

+300
-28
lines changed

7 files changed

+300
-28
lines changed

‎src/backend/commands/explain.c‎

Lines changed: 129 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -667,15 +667,35 @@ report_triggers(ResultRelInfo *rInfo, bool show_relname, ExplainState *es)
667667
Instrumentation*instr=rInfo->ri_TrigInstrument+nt;
668668
char*relname;
669669
char*conname=NULL;
670+
instr_timestarttimespan;
671+
doubletotal;
672+
doublentuples;
673+
doublencalls;
670674

671-
/* Must clean up instrumentation state */
672-
InstrEndLoop(instr);
675+
if (!es->runtime)
676+
{
677+
/* Must clean up instrumentation state */
678+
InstrEndLoop(instr);
679+
}
680+
681+
/* Collect statistic variables */
682+
if (!INSTR_TIME_IS_ZERO(instr->starttime))
683+
{
684+
INSTR_TIME_SET_CURRENT(starttimespan);
685+
INSTR_TIME_SUBTRACT(starttimespan,instr->starttime);
686+
}
687+
else
688+
INSTR_TIME_SET_ZERO(starttimespan);
689+
total=instr->total+INSTR_TIME_GET_DOUBLE(instr->counter)
690+
+INSTR_TIME_GET_DOUBLE(starttimespan);
691+
ntuples=instr->ntuples+instr->tuplecount;
692+
ncalls=ntuples+ !INSTR_TIME_IS_ZERO(starttimespan);
673693

674694
/*
675695
* We ignore triggers that were never invoked; they likely aren't
676696
* relevant to the current query type.
677697
*/
678-
if (instr->ntuples==0)
698+
if (ncalls==0)
679699
continue;
680700

681701
ExplainOpenGroup("Trigger",NULL, true,es);
@@ -701,9 +721,9 @@ report_triggers(ResultRelInfo *rInfo, bool show_relname, ExplainState *es)
701721
appendStringInfo(es->str," on %s",relname);
702722
if (es->timing)
703723
appendStringInfo(es->str,": time=%.3f calls=%.0f\n",
704-
1000.0*instr->total,instr->ntuples);
724+
1000.0*total,ncalls);
705725
else
706-
appendStringInfo(es->str,": calls=%.0f\n",instr->ntuples);
726+
appendStringInfo(es->str,": calls=%.0f\n",ncalls);
707727
}
708728
else
709729
{
@@ -712,8 +732,8 @@ report_triggers(ResultRelInfo *rInfo, bool show_relname, ExplainState *es)
712732
ExplainPropertyText("Constraint Name",conname,es);
713733
ExplainPropertyText("Relation",relname,es);
714734
if (es->timing)
715-
ExplainPropertyFloat("Time",1000.0*instr->total,3,es);
716-
ExplainPropertyFloat("Calls",instr->ntuples,0,es);
735+
ExplainPropertyFloat("Time",1000.0*total,3,es);
736+
ExplainPropertyFloat("Calls",ncalls,0,es);
717737
}
718738

719739
if (conname)
@@ -1225,8 +1245,11 @@ ExplainNode(PlanState *planstate, List *ancestors,
12251245
* instrumentation results the user didn't ask for. But we do the
12261246
* InstrEndLoop call anyway, if possible, to reduce the number of cases
12271247
* auto_explain has to contend with.
1248+
*
1249+
* if flag es->stateinfo is set i.e. when printing the current execution state
1250+
* this step of cleaning up is miss
12281251
*/
1229-
if (planstate->instrument)
1252+
if (planstate->instrument&& !es->runtime)
12301253
InstrEndLoop(planstate->instrument);
12311254

12321255
if (es->analyze&&
@@ -1259,7 +1282,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
12591282
ExplainPropertyFloat("Actual Loops",nloops,0,es);
12601283
}
12611284
}
1262-
elseif (es->analyze)
1285+
elseif (es->analyze&& !es->runtime)
12631286
{
12641287
if (es->format==EXPLAIN_FORMAT_TEXT)
12651288
appendStringInfoString(es->str," (never executed)");
@@ -1275,6 +1298,75 @@ ExplainNode(PlanState *planstate, List *ancestors,
12751298
}
12761299
}
12771300

1301+
/*
1302+
* print the progress of node execution at current loop
1303+
*/
1304+
if (planstate->instrument&&es->analyze&&es->runtime)
1305+
{
1306+
instr_timestarttimespan;
1307+
doublestartup_sec;
1308+
doubletotal_sec;
1309+
doublerows;
1310+
doubleloop_num;
1311+
boolfinished;
1312+
1313+
if (!INSTR_TIME_IS_ZERO(planstate->instrument->starttime))
1314+
{
1315+
INSTR_TIME_SET_CURRENT(starttimespan);
1316+
INSTR_TIME_SUBTRACT(starttimespan,planstate->instrument->starttime);
1317+
}
1318+
else
1319+
INSTR_TIME_SET_ZERO(starttimespan);
1320+
startup_sec=1000.0*planstate->instrument->firsttuple;
1321+
total_sec=1000.0* (INSTR_TIME_GET_DOUBLE(planstate->instrument->counter)
1322+
+INSTR_TIME_GET_DOUBLE(starttimespan));
1323+
rows=planstate->instrument->tuplecount;
1324+
loop_num=planstate->instrument->nloops+1;
1325+
1326+
finished=planstate->instrument->nloops>0
1327+
&& !planstate->instrument->running
1328+
&&INSTR_TIME_IS_ZERO(starttimespan);
1329+
1330+
if (!finished)
1331+
{
1332+
ExplainOpenGroup("Current loop","Current loop", true,es);
1333+
if (es->format==EXPLAIN_FORMAT_TEXT)
1334+
{
1335+
if (es->timing)
1336+
{
1337+
if (planstate->instrument->running)
1338+
appendStringInfo(es->str,
1339+
" (Current loop: actual time=%.3f..%.3f rows=%.0f, loop number=%.0f)",
1340+
startup_sec,total_sec,rows,loop_num);
1341+
else
1342+
appendStringInfo(es->str,
1343+
" (Current loop: running time=%.3f actual rows=0, loop number=%.0f)",
1344+
total_sec,loop_num);
1345+
}
1346+
else
1347+
appendStringInfo(es->str,
1348+
" (Current loop: actual rows=%.0f, loop number=%.0f)",
1349+
rows,loop_num);
1350+
}
1351+
else
1352+
{
1353+
ExplainPropertyFloat("Actual Loop Number",loop_num,0,es);
1354+
if (es->timing)
1355+
{
1356+
if (planstate->instrument->running)
1357+
{
1358+
ExplainPropertyFloat("Actual Startup Time",startup_sec,3,es);
1359+
ExplainPropertyFloat("Actual Total Time",total_sec,3,es);
1360+
}
1361+
else
1362+
ExplainPropertyFloat("Running Time",total_sec,3,es);
1363+
}
1364+
ExplainPropertyFloat("Actual Rows",rows,0,es);
1365+
}
1366+
ExplainCloseGroup("Current loop","Current loop", true,es);
1367+
}
1368+
}
1369+
12781370
/* in text format, first line ends here */
12791371
if (es->format==EXPLAIN_FORMAT_TEXT)
12801372
appendStringInfoChar(es->str,'\n');
@@ -1508,8 +1600,9 @@ ExplainNode(PlanState *planstate, List *ancestors,
15081600
if (es->buffers&&planstate->instrument)
15091601
show_buffer_usage(es,&planstate->instrument->bufusage);
15101602

1511-
/* Show worker detail */
1512-
if (es->analyze&&es->verbose&&planstate->worker_instrument)
1603+
/* Show worker detail after query execution */
1604+
if (es->analyze&&es->verbose&&planstate->worker_instrument
1605+
&& !es->runtime)
15131606
{
15141607
WorkerInstrumentation*w=planstate->worker_instrument;
15151608
boolopened_group= false;
@@ -2269,20 +2362,17 @@ show_instrumentation_count(const char *qlabel, int which,
22692362
if (!es->analyze|| !planstate->instrument)
22702363
return;
22712364

2365+
nloops=planstate->instrument->nloops;
22722366
if (which==2)
2273-
nfiltered=planstate->instrument->nfiltered2;
2367+
nfiltered= ((nloops>0) ?planstate->instrument->accum_nfiltered2 /nloops :0)
2368+
+planstate->instrument->nfiltered2;
22742369
else
2275-
nfiltered=planstate->instrument->nfiltered1;
2276-
nloops=planstate->instrument->nloops;
2370+
nfiltered=((nloops>0) ?planstate->instrument->accum_nfiltered1 /nloops :0)
2371+
+planstate->instrument->nfiltered1;
22772372

22782373
/* In text mode, suppress zero counts; they're not interesting enough */
22792374
if (nfiltered>0||es->format!=EXPLAIN_FORMAT_TEXT)
2280-
{
2281-
if (nloops>0)
2282-
ExplainPropertyFloat(qlabel,nfiltered /nloops,0,es);
2283-
else
2284-
ExplainPropertyFloat(qlabel,0.0,0,es);
2285-
}
2375+
ExplainPropertyFloat(qlabel,nfiltered,0,es);
22862376
}
22872377

22882378
/*
@@ -2754,14 +2844,28 @@ show_modifytable_info(ModifyTableState *mtstate, List *ancestors,
27542844
doubleinsert_path;
27552845
doubleother_path;
27562846

2757-
InstrEndLoop(mtstate->mt_plans[0]->instrument);
2847+
if (!es->runtime)
2848+
InstrEndLoop(mtstate->mt_plans[0]->instrument);
27582849

27592850
/* count the number of source rows */
2760-
total=mtstate->mt_plans[0]->instrument->ntuples;
2761-
other_path=mtstate->ps.instrument->nfiltered2;
2762-
insert_path=total-other_path;
2851+
other_path=mtstate->ps.instrument->accum_nfiltered2
2852+
+mtstate->ps.instrument->nfiltered2;
2853+
2854+
/*
2855+
* Insert occurs after extracting row from subplan and in runtime mode
2856+
* we can appear between these two operations - situation when
2857+
* total > insert_path + other_path. Therefore we don't know exactly
2858+
* whether last row from subplan is inserted.
2859+
* We don't print inserted tuples in runtime mode in order to not print
2860+
* inconsistent data
2861+
*/
2862+
if (!es->runtime)
2863+
{
2864+
total=mtstate->mt_plans[0]->instrument->ntuples;
2865+
insert_path=total-other_path;
2866+
ExplainPropertyFloat("Tuples Inserted",insert_path,0,es);
2867+
}
27632868

2764-
ExplainPropertyFloat("Tuples Inserted",insert_path,0,es);
27652869
ExplainPropertyFloat("Conflicting Tuples",other_path,0,es);
27662870
}
27672871
}

‎src/backend/executor/instrument.c‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -129,13 +129,17 @@ InstrEndLoop(Instrumentation *instr)
129129
instr->total+=totaltime;
130130
instr->ntuples+=instr->tuplecount;
131131
instr->nloops+=1;
132+
instr->accum_nfiltered1+=instr->nfiltered1;
133+
instr->accum_nfiltered2+=instr->nfiltered2;
132134

133135
/* Reset for next cycle (if any) */
134136
instr->running= false;
135137
INSTR_TIME_SET_ZERO(instr->starttime);
136138
INSTR_TIME_SET_ZERO(instr->counter);
137139
instr->firsttuple=0;
138140
instr->tuplecount=0;
141+
instr->nfiltered1=0;
142+
instr->nfiltered2=0;
139143
}
140144

141145
/* aggregate instrumentation information */

0 commit comments

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