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

Commited7a509

Browse files
committed
Include information on buffer usage during planning phase, in EXPLAIN output.
When BUFFERS option is enabled, EXPLAIN command includes the informationon buffer usage during each plan node, in its output. In addition to that,this commit makes EXPLAIN command include also the information onbuffer usage during planning phase, in its output. This feature makes iteasier to discern the cases where lots of buffer access happen duringplanning.Author: Julien Rouhaud, slightly revised by Fujii MasaoReviewed-by: Justin PryzbyDiscussion:https://postgr.es/m/16109-26a1a88651e90608@postgresql.org
1 parentac44367 commited7a509

File tree

4 files changed

+95
-8
lines changed

4 files changed

+95
-8
lines changed

‎src/backend/commands/explain.c

Lines changed: 30 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -372,7 +372,11 @@ ExplainOneQuery(Query *query, int cursorOptions,
372372
PlannedStmt*plan;
373373
instr_timeplanstart,
374374
planduration;
375+
BufferUsagebufusage_start,
376+
bufusage;
375377

378+
if (es->buffers)
379+
bufusage_start=pgBufferUsage;
376380
INSTR_TIME_SET_CURRENT(planstart);
377381

378382
/* plan the query */
@@ -381,9 +385,16 @@ ExplainOneQuery(Query *query, int cursorOptions,
381385
INSTR_TIME_SET_CURRENT(planduration);
382386
INSTR_TIME_SUBTRACT(planduration,planstart);
383387

388+
/* calc differences of buffer counters. */
389+
if (es->buffers)
390+
{
391+
memset(&bufusage,0,sizeof(BufferUsage));
392+
BufferUsageAccumDiff(&bufusage,&pgBufferUsage,&bufusage_start);
393+
}
394+
384395
/* run it (if needed) and produce output */
385396
ExplainOnePlan(plan,into,es,queryString,params,queryEnv,
386-
&planduration);
397+
&planduration, (es->buffers ?&bufusage :NULL));
387398
}
388399
}
389400

@@ -476,7 +487,8 @@ ExplainOneUtility(Node *utilityStmt, IntoClause *into, ExplainState *es,
476487
void
477488
ExplainOnePlan(PlannedStmt*plannedstmt,IntoClause*into,ExplainState*es,
478489
constchar*queryString,ParamListInfoparams,
479-
QueryEnvironment*queryEnv,constinstr_time*planduration)
490+
QueryEnvironment*queryEnv,constinstr_time*planduration,
491+
constBufferUsage*bufusage)
480492
{
481493
DestReceiver*dest;
482494
QueryDesc*queryDesc;
@@ -560,13 +572,29 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
560572
/* Create textual dump of plan tree */
561573
ExplainPrintPlan(es,queryDesc);
562574

575+
if (es->summary&& (planduration||bufusage))
576+
ExplainOpenGroup("Planning","Planning", true,es);
577+
563578
if (es->summary&&planduration)
564579
{
565580
doubleplantime=INSTR_TIME_GET_DOUBLE(*planduration);
566581

567582
ExplainPropertyFloat("Planning Time","ms",1000.0*plantime,3,es);
568583
}
569584

585+
/* Show buffer usage */
586+
if (es->summary&&bufusage)
587+
{
588+
if (es->format==EXPLAIN_FORMAT_TEXT)
589+
es->indent++;
590+
show_buffer_usage(es,bufusage);
591+
if (es->format==EXPLAIN_FORMAT_TEXT)
592+
es->indent--;
593+
}
594+
595+
if (es->summary&& (planduration||bufusage))
596+
ExplainCloseGroup("Planning","Planning", true,es);
597+
570598
/* Print info about runtime of triggers */
571599
if (es->analyze)
572600
ExplainPrintTriggers(es,queryDesc);

‎src/backend/commands/prepare.c

Lines changed: 12 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -616,7 +616,11 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
616616
EState*estate=NULL;
617617
instr_timeplanstart;
618618
instr_timeplanduration;
619+
BufferUsagebufusage_start,
620+
bufusage;
619621

622+
if (es->buffers)
623+
bufusage_start=pgBufferUsage;
620624
INSTR_TIME_SET_CURRENT(planstart);
621625

622626
/* Look it up in the hash table */
@@ -654,6 +658,13 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
654658
INSTR_TIME_SET_CURRENT(planduration);
655659
INSTR_TIME_SUBTRACT(planduration,planstart);
656660

661+
/* calc differences of buffer counters. */
662+
if (es->buffers)
663+
{
664+
memset(&bufusage,0,sizeof(BufferUsage));
665+
BufferUsageAccumDiff(&bufusage,&pgBufferUsage,&bufusage_start);
666+
}
667+
657668
plan_list=cplan->stmt_list;
658669

659670
/* Explain each query */
@@ -663,7 +674,7 @@ ExplainExecuteQuery(ExecuteStmt *execstmt, IntoClause *into, ExplainState *es,
663674

664675
if (pstmt->commandType!=CMD_UTILITY)
665676
ExplainOnePlan(pstmt,into,es,query_string,paramLI,queryEnv,
666-
&planduration);
677+
&planduration, (es->buffers ?&bufusage :NULL));
667678
else
668679
ExplainOneUtility(pstmt->utilityStmt,into,es,query_string,
669680
paramLI,queryEnv);

‎src/include/commands/explain.h

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -89,7 +89,8 @@ extern void ExplainOneUtility(Node *utilityStmt, IntoClause *into,
8989
externvoidExplainOnePlan(PlannedStmt*plannedstmt,IntoClause*into,
9090
ExplainState*es,constchar*queryString,
9191
ParamListInfoparams,QueryEnvironment*queryEnv,
92-
constinstr_time*planduration);
92+
constinstr_time*planduration,
93+
constBufferUsage*bufusage);
9394

9495
externvoidExplainPrintPlan(ExplainState*es,QueryDesc*queryDesc);
9596
externvoidExplainPrintTriggers(ExplainState*es,QueryDesc*queryDesc);

‎src/test/regress/expected/explain.out

Lines changed: 51 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -105,7 +105,19 @@ select explain_filter('explain (analyze, buffers, format json) select * from int
105105
"Temp Read Blocks": N, +
106106
"Temp Written Blocks": N +
107107
}, +
108-
"Planning Time": N.N, +
108+
"Planning": { +
109+
"Planning Time": N.N, +
110+
"Shared Hit Blocks": N, +
111+
"Shared Read Blocks": N, +
112+
"Shared Dirtied Blocks": N, +
113+
"Shared Written Blocks": N, +
114+
"Local Hit Blocks": N, +
115+
"Local Read Blocks": N, +
116+
"Local Dirtied Blocks": N, +
117+
"Local Written Blocks": N, +
118+
"Temp Read Blocks": N, +
119+
"Temp Written Blocks": N +
120+
}, +
109121
"Triggers": [ +
110122
], +
111123
"Execution Time": N.N +
@@ -142,7 +154,19 @@ select explain_filter('explain (analyze, buffers, format xml) select * from int8
142154
<Temp-Read-Blocks>N</Temp-Read-Blocks> +
143155
<Temp-Written-Blocks>N</Temp-Written-Blocks> +
144156
</Plan> +
145-
<Planning-Time>N.N</Planning-Time> +
157+
<Planning> +
158+
<Planning-Time>N.N</Planning-Time> +
159+
<Shared-Hit-Blocks>N</Shared-Hit-Blocks> +
160+
<Shared-Read-Blocks>N</Shared-Read-Blocks> +
161+
<Shared-Dirtied-Blocks>N</Shared-Dirtied-Blocks>+
162+
<Shared-Written-Blocks>N</Shared-Written-Blocks>+
163+
<Local-Hit-Blocks>N</Local-Hit-Blocks> +
164+
<Local-Read-Blocks>N</Local-Read-Blocks> +
165+
<Local-Dirtied-Blocks>N</Local-Dirtied-Blocks> +
166+
<Local-Written-Blocks>N</Local-Written-Blocks> +
167+
<Temp-Read-Blocks>N</Temp-Read-Blocks> +
168+
<Temp-Written-Blocks>N</Temp-Written-Blocks> +
169+
</Planning> +
146170
<Triggers> +
147171
</Triggers> +
148172
<Execution-Time>N.N</Execution-Time> +
@@ -176,7 +200,18 @@ select explain_filter('explain (analyze, buffers, format yaml) select * from int
176200
Local Written Blocks: N +
177201
Temp Read Blocks: N +
178202
Temp Written Blocks: N +
179-
Planning Time: N.N +
203+
Planning: +
204+
Planning Time: N.N +
205+
Shared Hit Blocks: N +
206+
Shared Read Blocks: N +
207+
Shared Dirtied Blocks: N +
208+
Shared Written Blocks: N +
209+
Local Hit Blocks: N +
210+
Local Read Blocks: N +
211+
Local Dirtied Blocks: N +
212+
Local Written Blocks: N +
213+
Temp Read Blocks: N +
214+
Temp Written Blocks: N +
180215
Triggers: +
181216
Execution Time: N.N
182217
(1 row)
@@ -366,9 +401,21 @@ select jsonb_pretty(
366401
"Shared Dirtied Blocks": 0, +
367402
"Shared Written Blocks": 0 +
368403
}, +
404+
"Planning": { +
405+
"Planning Time": 0.0, +
406+
"Local Hit Blocks": 0, +
407+
"Temp Read Blocks": 0, +
408+
"Local Read Blocks": 0, +
409+
"Shared Hit Blocks": 0, +
410+
"Shared Read Blocks": 0, +
411+
"Temp Written Blocks": 0, +
412+
"Local Dirtied Blocks": 0, +
413+
"Local Written Blocks": 0, +
414+
"Shared Dirtied Blocks": 0, +
415+
"Shared Written Blocks": 0 +
416+
}, +
369417
"Triggers": [ +
370418
], +
371-
"Planning Time": 0.0, +
372419
"Execution Time": 0.0 +
373420
} +
374421
]

0 commit comments

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