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

Commitadb1a6e

Browse files
committed
Improve EXPLAIN ANALYZE to show the time spent in each trigger when
executing a statement that fires triggers. Formerly this time wasincluded in "Total runtime" but not otherwise accounted for.As a side benefit, we avoid re-opening relations when firing non-deferredAFTER triggers, because the trigger code can re-use the main executor'sResultRelInfo data structure.
1 parent08890b4 commitadb1a6e

File tree

16 files changed

+406
-146
lines changed

16 files changed

+406
-146
lines changed

‎doc/src/sgml/perform.sgml

Lines changed: 14 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
<!--
2-
$PostgreSQL: pgsql/doc/src/sgml/perform.sgml,v 1.50 2005/02/03 07:12:37 neilc Exp $
2+
$PostgreSQL: pgsql/doc/src/sgml/perform.sgml,v 1.51 2005/03/25 21:57:57 tgl Exp $
33
-->
44

55
<chapter id="performance-tips">
@@ -320,16 +320,19 @@ EXPLAIN ANALYZE SELECT * FROM tenk1 t1, tenk2 t2 WHERE t1.unique1 &lt; 50 AND t1
320320
</para>
321321

322322
<para>
323-
The <literal>Total runtime</literal> shown by <command>EXPLAIN ANALYZE</command> includes
324-
executor start-up and shut-down time, as well as time spent processing
325-
the result rows. It does not include parsing, rewriting, or planning
326-
time. For a <command>SELECT</> query, the total run time will normally be just a
327-
little larger than the total time reported for the top-level plan node.
328-
For <command>INSERT</>, <command>UPDATE</>, and <command>DELETE</> commands, the total run time may be
329-
considerably larger, because it includes the time spent processing the
330-
result rows. In these commands, the time for the top plan node
331-
essentially is the time spent computing the new rows and/or locating
332-
the old ones, but it doesn't include the time spent making the changes.
323+
The <literal>Total runtime</literal> shown by <command>EXPLAIN
324+
ANALYZE</command> includes executor start-up and shut-down time, as well
325+
as time spent processing the result rows. It does not include parsing,
326+
rewriting, or planning time. For a <command>SELECT</> query, the total
327+
run time will normally be just a little larger than the total time
328+
reported for the top-level plan node. For <command>INSERT</>,
329+
<command>UPDATE</>, and <command>DELETE</> commands, the total run time
330+
may be considerably larger, because it includes the time spent processing
331+
the result rows. In these commands, the time for the top plan node
332+
essentially is the time spent computing the new rows and/or locating the
333+
old ones, but it doesn't include the time spent making the changes.
334+
Time spent firing triggers, if any, is also outside the top plan node,
335+
and is shown separately for each trigger.
333336
</para>
334337

335338
<para>

‎src/backend/catalog/pg_constraint.c

Lines changed: 95 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,7 @@
88
*
99
*
1010
* IDENTIFICATION
11-
* $PostgreSQL: pgsql/src/backend/catalog/pg_constraint.c,v 1.22 2004/12/31 21:59:38 pgsql Exp $
11+
* $PostgreSQL: pgsql/src/backend/catalog/pg_constraint.c,v 1.23 2005/03/25 21:57:57 tgl Exp $
1212
*
1313
*-------------------------------------------------------------------------
1414
*/
@@ -21,12 +21,14 @@
2121
#include"catalog/dependency.h"
2222
#include"catalog/indexing.h"
2323
#include"catalog/pg_constraint.h"
24+
#include"catalog/pg_depend.h"
2425
#include"catalog/pg_type.h"
2526
#include"commands/defrem.h"
2627
#include"miscadmin.h"
2728
#include"utils/array.h"
2829
#include"utils/builtins.h"
2930
#include"utils/fmgroids.h"
31+
#include"utils/lsyscache.h"
3032
#include"utils/syscache.h"
3133

3234

@@ -510,3 +512,95 @@ RemoveConstraintById(Oid conId)
510512
systable_endscan(conscan);
511513
heap_close(conDesc,RowExclusiveLock);
512514
}
515+
516+
/*
517+
* GetConstraintNameForTrigger
518+
*Get the name of the constraint owning a trigger, if any
519+
*
520+
* Returns a palloc'd string, or NULL if no constraint can be found
521+
*/
522+
char*
523+
GetConstraintNameForTrigger(OidtriggerId)
524+
{
525+
char*result;
526+
OidconstraintId=InvalidOid;
527+
Oidpg_trigger_id;
528+
Oidpg_constraint_id;
529+
RelationdepRel;
530+
RelationconRel;
531+
ScanKeyDatakey[2];
532+
SysScanDescscan;
533+
HeapTupletup;
534+
535+
pg_trigger_id=get_system_catalog_relid(TriggerRelationName);
536+
pg_constraint_id=get_system_catalog_relid(ConstraintRelationName);
537+
538+
/*
539+
* We must grovel through pg_depend to find the owning constraint.
540+
* Perhaps pg_trigger should have a column for the owning constraint ...
541+
* but right now this is not performance-critical code.
542+
*/
543+
depRel=heap_openr(DependRelationName,AccessShareLock);
544+
545+
ScanKeyInit(&key[0],
546+
Anum_pg_depend_classid,
547+
BTEqualStrategyNumber,F_OIDEQ,
548+
ObjectIdGetDatum(pg_trigger_id));
549+
ScanKeyInit(&key[1],
550+
Anum_pg_depend_objid,
551+
BTEqualStrategyNumber,F_OIDEQ,
552+
ObjectIdGetDatum(triggerId));
553+
/* assume we can ignore objsubid for a trigger */
554+
555+
scan=systable_beginscan(depRel,DependDependerIndex, true,
556+
SnapshotNow,2,key);
557+
558+
while (HeapTupleIsValid(tup=systable_getnext(scan)))
559+
{
560+
Form_pg_dependfoundDep= (Form_pg_depend)GETSTRUCT(tup);
561+
562+
if (foundDep->refclassid==pg_constraint_id&&
563+
foundDep->deptype==DEPENDENCY_INTERNAL)
564+
{
565+
constraintId=foundDep->refobjid;
566+
break;
567+
}
568+
}
569+
570+
systable_endscan(scan);
571+
572+
heap_close(depRel,AccessShareLock);
573+
574+
if (!OidIsValid(constraintId))
575+
returnNULL;/* no owning constraint found */
576+
577+
conRel=heap_openr(ConstraintRelationName,AccessShareLock);
578+
579+
ScanKeyInit(&key[0],
580+
ObjectIdAttributeNumber,
581+
BTEqualStrategyNumber,F_OIDEQ,
582+
ObjectIdGetDatum(constraintId));
583+
584+
scan=systable_beginscan(conRel,ConstraintOidIndex, true,
585+
SnapshotNow,1,key);
586+
587+
tup=systable_getnext(scan);
588+
589+
if (HeapTupleIsValid(tup))
590+
{
591+
Form_pg_constraintcon= (Form_pg_constraint)GETSTRUCT(tup);
592+
593+
result=pstrdup(NameStr(con->conname));
594+
}
595+
else
596+
{
597+
/* This arguably should be an error, but we'll just return NULL */
598+
result=NULL;
599+
}
600+
601+
systable_endscan(scan);
602+
603+
heap_close(conRel,AccessShareLock);
604+
605+
returnresult;
606+
}

‎src/backend/commands/copy.c

Lines changed: 6 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,7 @@
88
*
99
*
1010
* IDENTIFICATION
11-
* $PostgreSQL: pgsql/src/backend/commands/copy.c,v 1.238 2005/03/16 21:38:05 tgl Exp $
11+
* $PostgreSQL: pgsql/src/backend/commands/copy.c,v 1.239 2005/03/25 21:57:57 tgl Exp $
1212
*
1313
*-------------------------------------------------------------------------
1414
*/
@@ -1510,6 +1510,10 @@ CopyFrom(Relation rel, List *attnumlist, bool binary, bool oids,
15101510
resultRelInfo->ri_RangeTableIndex=1;/* dummy */
15111511
resultRelInfo->ri_RelationDesc=rel;
15121512
resultRelInfo->ri_TrigDesc=CopyTriggerDesc(rel->trigdesc);
1513+
if (resultRelInfo->ri_TrigDesc)
1514+
resultRelInfo->ri_TrigFunctions= (FmgrInfo*)
1515+
palloc0(resultRelInfo->ri_TrigDesc->numtriggers*sizeof(FmgrInfo));
1516+
resultRelInfo->ri_TrigInstrument=NULL;
15131517

15141518
ExecOpenIndices(resultRelInfo);
15151519

@@ -1974,7 +1978,7 @@ CopyFrom(Relation rel, List *attnumlist, bool binary, bool oids,
19741978
/*
19751979
* Handle queued AFTER triggers
19761980
*/
1977-
AfterTriggerEndQuery();
1981+
AfterTriggerEndQuery(estate);
19781982

19791983
pfree(values);
19801984
pfree(nulls);

‎src/backend/commands/explain.c

Lines changed: 67 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -7,14 +7,15 @@
77
* Portions Copyright (c) 1994-5, Regents of the University of California
88
*
99
* IDENTIFICATION
10-
* $PostgreSQL: pgsql/src/backend/commands/explain.c,v 1.130 2005/03/20 22:27:51 tgl Exp $
10+
* $PostgreSQL: pgsql/src/backend/commands/explain.c,v 1.131 2005/03/25 21:57:58 tgl Exp $
1111
*
1212
*-------------------------------------------------------------------------
1313
*/
1414
#include"postgres.h"
1515

1616
#include"access/genam.h"
1717
#include"access/heapam.h"
18+
#include"catalog/pg_constraint.h"
1819
#include"catalog/pg_type.h"
1920
#include"commands/explain.h"
2021
#include"commands/prepare.h"
@@ -272,16 +273,76 @@ ExplainOnePlan(QueryDesc *queryDesc, ExplainStmt *stmt,
272273
}
273274

274275
/*
275-
* Close down the query and free resources; also run any queued
276-
* AFTER triggers. Include time for this in the total runtime.
276+
* If we ran the command, run any AFTER triggers it queued. (Note this
277+
* will not include DEFERRED triggers; since those don't run until end of
278+
* transaction, we can't measure them.) Include into total runtime.
279+
*/
280+
if (stmt->analyze)
281+
{
282+
INSTR_TIME_SET_CURRENT(starttime);
283+
AfterTriggerEndQuery(queryDesc->estate);
284+
totaltime+=elapsed_time(&starttime);
285+
}
286+
287+
/* Print info about runtime of triggers */
288+
if (es->printAnalyze)
289+
{
290+
ResultRelInfo*rInfo;
291+
intnumrels=queryDesc->estate->es_num_result_relations;
292+
intnr;
293+
294+
rInfo=queryDesc->estate->es_result_relations;
295+
for (nr=0;nr<numrels;rInfo++,nr++)
296+
{
297+
intnt;
298+
299+
if (!rInfo->ri_TrigDesc)
300+
continue;
301+
for (nt=0;nt<rInfo->ri_TrigDesc->numtriggers;nt++)
302+
{
303+
Trigger*trig=rInfo->ri_TrigDesc->triggers+nt;
304+
Instrumentation*instr=rInfo->ri_TrigInstrument+nt;
305+
char*conname;
306+
307+
/* Must clean up instrumentation state */
308+
InstrEndLoop(instr);
309+
310+
/*
311+
* We ignore triggers that were never invoked; they likely
312+
* aren't relevant to the current query type.
313+
*/
314+
if (instr->ntuples==0)
315+
continue;
316+
317+
if (trig->tgisconstraint&&
318+
(conname=GetConstraintNameForTrigger(trig->tgoid))!=NULL)
319+
{
320+
appendStringInfo(str,"Trigger for constraint %s",
321+
conname);
322+
pfree(conname);
323+
}
324+
else
325+
appendStringInfo(str,"Trigger %s",trig->tgname);
326+
327+
if (numrels>1)
328+
appendStringInfo(str," on %s",
329+
RelationGetRelationName(rInfo->ri_RelationDesc));
330+
331+
appendStringInfo(str,": time=%.3f calls=%.0f\n",
332+
1000.0*instr->total,
333+
instr->ntuples);
334+
}
335+
}
336+
}
337+
338+
/*
339+
* Close down the query and free resources. Include time for this
340+
* in the total runtime (although it should be pretty minimal).
277341
*/
278342
INSTR_TIME_SET_CURRENT(starttime);
279343

280344
ExecutorEnd(queryDesc);
281345

282-
if (stmt->analyze)
283-
AfterTriggerEndQuery();
284-
285346
FreeQueryDesc(queryDesc);
286347

287348
/* We need a CCI just in case query expanded to multiple plans */

‎src/backend/commands/portalcmds.c

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -14,7 +14,7 @@
1414
*
1515
*
1616
* IDENTIFICATION
17-
* $PostgreSQL: pgsql/src/backend/commands/portalcmds.c,v 1.38 2004/12/31 21:59:41 pgsql Exp $
17+
* $PostgreSQL: pgsql/src/backend/commands/portalcmds.c,v 1.39 2005/03/25 21:57:58 tgl Exp $
1818
*
1919
*-------------------------------------------------------------------------
2020
*/
@@ -281,8 +281,8 @@ PortalCleanup(Portal portal)
281281
PG_TRY();
282282
{
283283
CurrentResourceOwner=portal->resowner;
284-
ExecutorEnd(queryDesc);
285284
/* we do not need AfterTriggerEndQuery() here */
285+
ExecutorEnd(queryDesc);
286286
}
287287
PG_CATCH();
288288
{
@@ -382,8 +382,8 @@ PersistHoldablePortal(Portal portal)
382382
* Now shut down the inner executor.
383383
*/
384384
portal->queryDesc=NULL;/* prevent double shutdown */
385-
ExecutorEnd(queryDesc);
386385
/* we do not need AfterTriggerEndQuery() here */
386+
ExecutorEnd(queryDesc);
387387

388388
/*
389389
* Reset the position in the result set: ideally, this could be

0 commit comments

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