WIP: make EXPLAIN ANALYZE show time spent in triggers - Mailing list pgsql-patches

From Tom Lane
Subject WIP: make EXPLAIN ANALYZE show time spent in triggers
Date
Msg-id 20693.1111732761@sss.pgh.pa.us
Whole thread Raw
Responses Re: WIP: make EXPLAIN ANALYZE show time spent in triggers  (Christopher Kings-Lynne <chriskl@familyhealth.com.au>)
Re: WIP: make EXPLAIN ANALYZE show time spent in triggers  (Christopher Kings-Lynne <chriskl@familyhealth.com.au>)
List pgsql-patches
The attached patch allows EXPLAIN ANALYZE to break out the time spent in
triggers when EXPLAINing a statement that can fire triggers.  Formerly
this time was included in "Total runtime" but not otherwise accounted
for.

An example is

regression=# explain analyze delete from foo;
                                               QUERY PLAN
--------------------------------------------------------------------------------------------------------
 Seq Scan on foo  (cost=0.00..172.70 rows=11770 width=6) (actual time=0.063..86.650 rows=10000 loops=1)
 Trigger RI_ConstraintTrigger_60781: time=3899.609 calls=10000
 Total runtime: 4218.309 ms
(3 rows)

The trigger display text probably still needs some work --- in
particular I'm wondering if RI triggers couldn't be displayed in some
more intelligent fashion than just the internal trigger name.

What I'm actually more interested in right now is comments on the
infrastructure changes.  To make this work, I modified the executor's
ResultRelInfo structs to include provisions to store per-trigger
Instrumentation nodes, and changed AfterTriggerEndQuery to receive the
query's EState in which it could look up the ResultRelInfos.  A nifty
side benefit is that the after-event trigger code doesn't have to open
result relations for itself anymore for non-deferred triggers: it can
use the executor's main copies of the relations.  I had to change the
call order so that AfterTriggerEndQuery is called before instead of
after ExecutorEnd (because ExecutorEnd closes down all this state).
I don't see any downside to that, but am I missing something?

            regards, tom lane

*** src/backend/commands/copy.c.orig    Wed Mar 16 16:38:05 2005
--- src/backend/commands/copy.c    Thu Mar 24 23:29:32 2005
***************
*** 1510,1515 ****
--- 1510,1519 ----
      resultRelInfo->ri_RangeTableIndex = 1;        /* dummy */
      resultRelInfo->ri_RelationDesc = rel;
      resultRelInfo->ri_TrigDesc = CopyTriggerDesc(rel->trigdesc);
+     if (resultRelInfo->ri_TrigDesc)
+         resultRelInfo->ri_TrigFunctions = (FmgrInfo *)
+             palloc0(resultRelInfo->ri_TrigDesc->numtriggers * sizeof(FmgrInfo));
+     resultRelInfo->ri_TrigInstrument = NULL;

      ExecOpenIndices(resultRelInfo);

***************
*** 1974,1980 ****
      /*
       * Handle queued AFTER triggers
       */
!     AfterTriggerEndQuery();

      pfree(values);
      pfree(nulls);
--- 1978,1984 ----
      /*
       * Handle queued AFTER triggers
       */
!     AfterTriggerEndQuery(estate);

      pfree(values);
      pfree(nulls);
*** src/backend/commands/explain.c.orig    Sun Mar 20 17:27:51 2005
--- src/backend/commands/explain.c    Fri Mar 25 00:46:44 2005
***************
*** 272,286 ****
      }

      /*
!      * Close down the query and free resources; also run any queued
!      * AFTER triggers.  Include time for this in the total runtime.
       */
      INSTR_TIME_SET_CURRENT(starttime);

      ExecutorEnd(queryDesc);
-
-     if (stmt->analyze)
-         AfterTriggerEndQuery();

      FreeQueryDesc(queryDesc);

--- 272,337 ----
      }

      /*
!      * If we ran the command, run any AFTER triggers it queued.  (Note this
!      * will not include DEFERRED triggers; since those don't run until end of
!      * transaction, we can't measure them.)  Include into total runtime.
!      */
!     if (stmt->analyze)
!     {
!         INSTR_TIME_SET_CURRENT(starttime);
!         AfterTriggerEndQuery(queryDesc->estate);
!         totaltime += elapsed_time(&starttime);
!     }
!
!     /* Print info about runtime of triggers */
!     if (es->printAnalyze)
!     {
!         ResultRelInfo *rInfo;
!         int        numrels = queryDesc->estate->es_num_result_relations;
!         int        nr;
!
!         rInfo = queryDesc->estate->es_result_relations;
!         for (nr = 0; nr < numrels; rInfo++, nr++)
!         {
!             int        nt;
!
!             if (!rInfo->ri_TrigDesc)
!                 continue;
!             for (nt = 0; nt < rInfo->ri_TrigDesc->numtriggers; nt++)
!             {
!                 Trigger *trig = rInfo->ri_TrigDesc->triggers + nt;
!                 Instrumentation *instr = rInfo->ri_TrigInstrument + nt;
!
!                 /* Must clean up instrumentation state */
!                 InstrEndLoop(instr);
!
!                 /*
!                  * We ignore triggers that were never invoked; they likely
!                  * aren't relevant to the current query type.
!                  */
!                 if (instr->ntuples == 0)
!                     continue;
!
!                 appendStringInfo(str, "Trigger %s", trig->tgname);
!
!                 if (numrels > 1)
!                     appendStringInfo(str, " on %s",
!                                      RelationGetRelationName(rInfo->ri_RelationDesc));
!
!                 appendStringInfo(str, ": time=%.3f calls=%.0f\n",
!                                  1000.0 * instr->total,
!                                  instr->ntuples);
!             }
!         }
!     }
!
!     /*
!      * Close down the query and free resources.  Include time for this
!      * in the total runtime (although it should be pretty minimal).
       */
      INSTR_TIME_SET_CURRENT(starttime);

      ExecutorEnd(queryDesc);

      FreeQueryDesc(queryDesc);

*** src/backend/commands/portalcmds.c.orig    Fri Dec 31 17:45:37 2004
--- src/backend/commands/portalcmds.c    Thu Mar 24 23:29:32 2005
***************
*** 281,288 ****
              PG_TRY();
              {
                  CurrentResourceOwner = portal->resowner;
-                 ExecutorEnd(queryDesc);
                  /* we do not need AfterTriggerEndQuery() here */
              }
              PG_CATCH();
              {
--- 281,288 ----
              PG_TRY();
              {
                  CurrentResourceOwner = portal->resowner;
                  /* we do not need AfterTriggerEndQuery() here */
+                 ExecutorEnd(queryDesc);
              }
              PG_CATCH();
              {
***************
*** 382,389 ****
           * Now shut down the inner executor.
           */
          portal->queryDesc = NULL;        /* prevent double shutdown */
-         ExecutorEnd(queryDesc);
          /* we do not need AfterTriggerEndQuery() here */

          /*
           * Reset the position in the result set: ideally, this could be
--- 382,389 ----
           * Now shut down the inner executor.
           */
          portal->queryDesc = NULL;        /* prevent double shutdown */
          /* we do not need AfterTriggerEndQuery() here */
+         ExecutorEnd(queryDesc);

          /*
           * Reset the position in the result set: ideally, this could be
*** src/backend/commands/trigger.c.orig    Thu Mar 24 18:26:50 2005
--- src/backend/commands/trigger.c    Fri Mar 25 01:11:36 2005
***************
*** 28,33 ****
--- 28,34 ----
  #include "commands/defrem.h"
  #include "commands/trigger.h"
  #include "executor/executor.h"
+ #include "executor/instrument.h"
  #include "miscadmin.h"
  #include "nodes/makefuncs.h"
  #include "parser/parse_func.h"
***************
*** 46,52 ****
--- 47,55 ----
                     CommandId cid,
                     TupleTableSlot **newSlot);
  static HeapTuple ExecCallTriggerFunc(TriggerData *trigdata,
+                     int tgindx,
                      FmgrInfo *finfo,
+                     Instrumentation *instr,
                      MemoryContext per_tuple_context);
  static void AfterTriggerSaveEvent(ResultRelInfo *relinfo, int event,
                     bool row_trigger, HeapTuple oldtup, HeapTuple newtup);
***************
*** 1107,1126 ****
   * Call a trigger function.
   *
   *        trigdata: trigger descriptor.
!  *        finfo: possibly-cached call info for the function.
   *        per_tuple_context: memory context to execute the function in.
   *
   * Returns the tuple (or NULL) as returned by the function.
   */
  static HeapTuple
  ExecCallTriggerFunc(TriggerData *trigdata,
                      FmgrInfo *finfo,
                      MemoryContext per_tuple_context)
  {
      FunctionCallInfoData fcinfo;
      Datum        result;
      MemoryContext oldContext;

      /*
       * We cache fmgr lookup info, to avoid making the lookup again on each
       * call.
--- 1110,1135 ----
   * Call a trigger function.
   *
   *        trigdata: trigger descriptor.
!  *        tgindx: trigger's index in finfo and instr arrays.
!  *        finfo: array of cached trigger function call information.
!  *        instr: optional array of EXPLAIN ANALYZE instrumentation state.
   *        per_tuple_context: memory context to execute the function in.
   *
   * Returns the tuple (or NULL) as returned by the function.
   */
  static HeapTuple
  ExecCallTriggerFunc(TriggerData *trigdata,
+                     int tgindx,
                      FmgrInfo *finfo,
+                     Instrumentation *instr,
                      MemoryContext per_tuple_context)
  {
      FunctionCallInfoData fcinfo;
      Datum        result;
      MemoryContext oldContext;

+     finfo += tgindx;
+
      /*
       * We cache fmgr lookup info, to avoid making the lookup again on each
       * call.
***************
*** 1131,1136 ****
--- 1140,1151 ----
      Assert(finfo->fn_oid == trigdata->tg_trigger->tgfoid);

      /*
+      * If doing EXPLAIN ANALYZE, start charging time to this trigger.
+      */
+     if (instr)
+         InstrStartNode(instr + tgindx);
+
+     /*
       * Do the function evaluation in the per-tuple memory context, so that
       * leaked memory will be reclaimed once per tuple. Note in particular
       * that any new tuple created by the trigger function will live till
***************
*** 1160,1165 ****
--- 1175,1187 ----
                   errmsg("trigger function %u returned null value",
                          fcinfo.flinfo->fn_oid)));

+     /*
+      * If doing EXPLAIN ANALYZE, stop charging time to this trigger,
+      * and count one "tuple returned" (really the number of firings).
+      */
+     if (instr)
+         InstrStopNode(instr + tgindx, true);
+
      return (HeapTuple) DatumGetPointer(result);
  }

***************
*** 1183,1193 ****
      if (ntrigs == 0)
          return;

-     /* Allocate cache space for fmgr lookup info, if not done yet */
-     if (relinfo->ri_TrigFunctions == NULL)
-         relinfo->ri_TrigFunctions = (FmgrInfo *)
-             palloc0(trigdesc->numtriggers * sizeof(FmgrInfo));
-
      LocTriggerData.type = T_TriggerData;
      LocTriggerData.tg_event = TRIGGER_EVENT_INSERT |
          TRIGGER_EVENT_BEFORE;
--- 1205,1210 ----
***************
*** 1205,1211 ****
              continue;
          LocTriggerData.tg_trigger = trigger;
          newtuple = ExecCallTriggerFunc(&LocTriggerData,
!                                    relinfo->ri_TrigFunctions + tgindx[i],
                                         GetPerTupleMemoryContext(estate));

          if (newtuple)
--- 1222,1230 ----
              continue;
          LocTriggerData.tg_trigger = trigger;
          newtuple = ExecCallTriggerFunc(&LocTriggerData,
!                                        tgindx[i],
!                                        relinfo->ri_TrigFunctions,
!                                        relinfo->ri_TrigInstrument,
                                         GetPerTupleMemoryContext(estate));

          if (newtuple)
***************
*** 1237,1247 ****
      TriggerData LocTriggerData;
      int            i;

-     /* Allocate cache space for fmgr lookup info, if not done yet */
-     if (relinfo->ri_TrigFunctions == NULL)
-         relinfo->ri_TrigFunctions = (FmgrInfo *)
-             palloc0(trigdesc->numtriggers * sizeof(FmgrInfo));
-
      LocTriggerData.type = T_TriggerData;
      LocTriggerData.tg_event = TRIGGER_EVENT_INSERT |
          TRIGGER_EVENT_ROW |
--- 1256,1261 ----
***************
*** 1259,1265 ****
          LocTriggerData.tg_trigtuplebuf = InvalidBuffer;
          LocTriggerData.tg_trigger = trigger;
          newtuple = ExecCallTriggerFunc(&LocTriggerData,
!                                    relinfo->ri_TrigFunctions + tgindx[i],
                                         GetPerTupleMemoryContext(estate));
          if (oldtuple != newtuple && oldtuple != trigtuple)
              heap_freetuple(oldtuple);
--- 1273,1281 ----
          LocTriggerData.tg_trigtuplebuf = InvalidBuffer;
          LocTriggerData.tg_trigger = trigger;
          newtuple = ExecCallTriggerFunc(&LocTriggerData,
!                                        tgindx[i],
!                                        relinfo->ri_TrigFunctions,
!                                        relinfo->ri_TrigInstrument,
                                         GetPerTupleMemoryContext(estate));
          if (oldtuple != newtuple && oldtuple != trigtuple)
              heap_freetuple(oldtuple);
***************
*** 1300,1310 ****
      if (ntrigs == 0)
          return;

-     /* Allocate cache space for fmgr lookup info, if not done yet */
-     if (relinfo->ri_TrigFunctions == NULL)
-         relinfo->ri_TrigFunctions = (FmgrInfo *)
-             palloc0(trigdesc->numtriggers * sizeof(FmgrInfo));
-
      LocTriggerData.type = T_TriggerData;
      LocTriggerData.tg_event = TRIGGER_EVENT_DELETE |
          TRIGGER_EVENT_BEFORE;
--- 1316,1321 ----
***************
*** 1322,1328 ****
              continue;
          LocTriggerData.tg_trigger = trigger;
          newtuple = ExecCallTriggerFunc(&LocTriggerData,
!                                    relinfo->ri_TrigFunctions + tgindx[i],
                                         GetPerTupleMemoryContext(estate));

          if (newtuple)
--- 1333,1341 ----
              continue;
          LocTriggerData.tg_trigger = trigger;
          newtuple = ExecCallTriggerFunc(&LocTriggerData,
!                                        tgindx[i],
!                                        relinfo->ri_TrigFunctions,
!                                        relinfo->ri_TrigInstrument,
                                         GetPerTupleMemoryContext(estate));

          if (newtuple)
***************
*** 1360,1370 ****
      if (trigtuple == NULL)
          return false;

-     /* Allocate cache space for fmgr lookup info, if not done yet */
-     if (relinfo->ri_TrigFunctions == NULL)
-         relinfo->ri_TrigFunctions = (FmgrInfo *)
-             palloc0(trigdesc->numtriggers * sizeof(FmgrInfo));
-
      LocTriggerData.type = T_TriggerData;
      LocTriggerData.tg_event = TRIGGER_EVENT_DELETE |
          TRIGGER_EVENT_ROW |
--- 1373,1378 ----
***************
*** 1382,1388 ****
          LocTriggerData.tg_trigtuplebuf = InvalidBuffer;
          LocTriggerData.tg_trigger = trigger;
          newtuple = ExecCallTriggerFunc(&LocTriggerData,
!                                    relinfo->ri_TrigFunctions + tgindx[i],
                                         GetPerTupleMemoryContext(estate));
          if (newtuple == NULL)
              break;
--- 1390,1398 ----
          LocTriggerData.tg_trigtuplebuf = InvalidBuffer;
          LocTriggerData.tg_trigger = trigger;
          newtuple = ExecCallTriggerFunc(&LocTriggerData,
!                                        tgindx[i],
!                                        relinfo->ri_TrigFunctions,
!                                        relinfo->ri_TrigInstrument,
                                         GetPerTupleMemoryContext(estate));
          if (newtuple == NULL)
              break;
***************
*** 1433,1443 ****
      if (ntrigs == 0)
          return;

-     /* Allocate cache space for fmgr lookup info, if not done yet */
-     if (relinfo->ri_TrigFunctions == NULL)
-         relinfo->ri_TrigFunctions = (FmgrInfo *)
-             palloc0(trigdesc->numtriggers * sizeof(FmgrInfo));
-
      LocTriggerData.type = T_TriggerData;
      LocTriggerData.tg_event = TRIGGER_EVENT_UPDATE |
          TRIGGER_EVENT_BEFORE;
--- 1443,1448 ----
***************
*** 1455,1461 ****
              continue;
          LocTriggerData.tg_trigger = trigger;
          newtuple = ExecCallTriggerFunc(&LocTriggerData,
!                                    relinfo->ri_TrigFunctions + tgindx[i],
                                         GetPerTupleMemoryContext(estate));

          if (newtuple)
--- 1460,1468 ----
              continue;
          LocTriggerData.tg_trigger = trigger;
          newtuple = ExecCallTriggerFunc(&LocTriggerData,
!                                        tgindx[i],
!                                        relinfo->ri_TrigFunctions,
!                                        relinfo->ri_TrigInstrument,
                                         GetPerTupleMemoryContext(estate));

          if (newtuple)
***************
*** 1501,1511 ****
      if (newSlot != NULL)
          intuple = newtuple = ExecRemoveJunk(estate->es_junkFilter, newSlot);

-     /* Allocate cache space for fmgr lookup info, if not done yet */
-     if (relinfo->ri_TrigFunctions == NULL)
-         relinfo->ri_TrigFunctions = (FmgrInfo *)
-             palloc0(trigdesc->numtriggers * sizeof(FmgrInfo));
-
      LocTriggerData.type = T_TriggerData;
      LocTriggerData.tg_event = TRIGGER_EVENT_UPDATE |
          TRIGGER_EVENT_ROW |
--- 1508,1513 ----
***************
*** 1523,1529 ****
          LocTriggerData.tg_newtuplebuf = InvalidBuffer;
          LocTriggerData.tg_trigger = trigger;
          newtuple = ExecCallTriggerFunc(&LocTriggerData,
!                                    relinfo->ri_TrigFunctions + tgindx[i],
                                         GetPerTupleMemoryContext(estate));
          if (oldtuple != newtuple && oldtuple != intuple)
              heap_freetuple(oldtuple);
--- 1525,1533 ----
          LocTriggerData.tg_newtuplebuf = InvalidBuffer;
          LocTriggerData.tg_trigger = trigger;
          newtuple = ExecCallTriggerFunc(&LocTriggerData,
!                                        tgindx[i],
!                                        relinfo->ri_TrigFunctions,
!                                        relinfo->ri_TrigInstrument,
                                         GetPerTupleMemoryContext(estate));
          if (oldtuple != newtuple && oldtuple != intuple)
              heap_freetuple(oldtuple);
***************
*** 1798,1803 ****
--- 1802,1808 ----
  static void AfterTriggerExecute(AfterTriggerEvent event,
                                  Relation rel, TriggerDesc *trigdesc,
                                  FmgrInfo *finfo,
+                                 Instrumentation *instr,
                                  MemoryContext per_tuple_context);
  static SetConstraintState SetConstraintStateCreate(int numalloc);
  static SetConstraintState SetConstraintStateCopy(SetConstraintState state);
***************
*** 1886,1903 ****
   *
   *    Frequently, this will be fired many times in a row for triggers of
   *    a single relation.    Therefore, we cache the open relation and provide
!  *    fmgr lookup cache space at the caller level.
   *
   *    event: event currently being fired.
   *    rel: open relation for event.
   *    trigdesc: working copy of rel's trigger info.
   *    finfo: array of fmgr lookup cache entries (one per trigger in trigdesc).
   *    per_tuple_context: memory context to call trigger function in.
   * ----------
   */
  static void
  AfterTriggerExecute(AfterTriggerEvent event,
!                     Relation rel, TriggerDesc *trigdesc, FmgrInfo *finfo,
                      MemoryContext per_tuple_context)
  {
      Oid            tgoid = event->ate_tgoid;
--- 1891,1912 ----
   *
   *    Frequently, this will be fired many times in a row for triggers of
   *    a single relation.    Therefore, we cache the open relation and provide
!  *    fmgr lookup cache space at the caller level.  (For triggers fired at
!  *    the end of a query, we can even piggyback on the executor's state.)
   *
   *    event: event currently being fired.
   *    rel: open relation for event.
   *    trigdesc: working copy of rel's trigger info.
   *    finfo: array of fmgr lookup cache entries (one per trigger in trigdesc).
+  *    instr: array of EXPLAIN ANALYZE instrumentation nodes (one per trigger),
+  *        or NULL if no instrumentation is wanted.
   *    per_tuple_context: memory context to call trigger function in.
   * ----------
   */
  static void
  AfterTriggerExecute(AfterTriggerEvent event,
!                     Relation rel, TriggerDesc *trigdesc,
!                     FmgrInfo *finfo, Instrumentation *instr,
                      MemoryContext per_tuple_context)
  {
      Oid            tgoid = event->ate_tgoid;
***************
*** 1910,1915 ****
--- 1919,1946 ----
      int            tgindx;

      /*
+      * Locate trigger in trigdesc.
+      */
+     LocTriggerData.tg_trigger = NULL;
+     for (tgindx = 0; tgindx < trigdesc->numtriggers; tgindx++)
+     {
+         if (trigdesc->triggers[tgindx].tgoid == tgoid)
+         {
+             LocTriggerData.tg_trigger = &(trigdesc->triggers[tgindx]);
+             break;
+         }
+     }
+     if (LocTriggerData.tg_trigger == NULL)
+         elog(ERROR, "could not find trigger %u", tgoid);
+
+     /*
+      * If doing EXPLAIN ANALYZE, start charging time to this trigger.
+      * We want to include time spent re-fetching tuples in the trigger cost.
+      */
+     if (instr)
+         InstrStartNode(instr + tgindx);
+
+     /*
       * Fetch the required OLD and NEW tuples.
       */
      if (ItemPointerIsValid(&(event->ate_oldctid)))
***************
*** 1934,1951 ****
          event->ate_event & (TRIGGER_EVENT_OPMASK | TRIGGER_EVENT_ROW);
      LocTriggerData.tg_relation = rel;

-     LocTriggerData.tg_trigger = NULL;
-     for (tgindx = 0; tgindx < trigdesc->numtriggers; tgindx++)
-     {
-         if (trigdesc->triggers[tgindx].tgoid == tgoid)
-         {
-             LocTriggerData.tg_trigger = &(trigdesc->triggers[tgindx]);
-             break;
-         }
-     }
-     if (LocTriggerData.tg_trigger == NULL)
-         elog(ERROR, "could not find trigger %u", tgoid);
-
      switch (event->ate_event & TRIGGER_EVENT_OPMASK)
      {
          case TRIGGER_EVENT_INSERT:
--- 1965,1970 ----
***************
*** 1973,1983 ****
      MemoryContextReset(per_tuple_context);

      /*
!      * Call the trigger and throw away any eventually returned updated
!      * tuple.
       */
      rettuple = ExecCallTriggerFunc(&LocTriggerData,
!                                    finfo + tgindx,
                                     per_tuple_context);
      if (rettuple != NULL && rettuple != &oldtuple && rettuple != &newtuple)
          heap_freetuple(rettuple);
--- 1992,2004 ----
      MemoryContextReset(per_tuple_context);

      /*
!      * Call the trigger and throw away any possibly returned updated
!      * tuple.  (Don't let ExecCallTriggerFunc measure EXPLAIN time.)
       */
      rettuple = ExecCallTriggerFunc(&LocTriggerData,
!                                    tgindx,
!                                    finfo,
!                                    NULL,
                                     per_tuple_context);
      if (rettuple != NULL && rettuple != &oldtuple && rettuple != &newtuple)
          heap_freetuple(rettuple);
***************
*** 1989,1994 ****
--- 2010,2022 ----
          ReleaseBuffer(oldbuffer);
      if (newbuffer != InvalidBuffer)
          ReleaseBuffer(newbuffer);
+
+     /*
+      * If doing EXPLAIN ANALYZE, stop charging time to this trigger,
+      * and count one "tuple returned" (really the number of firings).
+      */
+     if (instr)
+         InstrStopNode(instr + tgindx, true);
  }


***************
*** 2093,2098 ****
--- 2121,2132 ----
   *    Scan the given event list for events that are marked as to be fired
   *    in the current firing cycle, and fire them.
   *
+  *    If estate isn't NULL, then we expect that all the firable events are
+  *    for triggers of the relations included in the estate's result relation
+  *    array.  This allows us to re-use the estate's open relations and
+  *    trigger cache info.  When estate is NULL, we have to find the relations
+  *    the hard way.
+  *
   *    When delete_ok is TRUE, it's okay to delete fully-processed events.
   *    The events list pointers are updated.
   * ----------
***************
*** 2100,2105 ****
--- 2134,2140 ----
  static void
  afterTriggerInvokeEvents(AfterTriggerEventList *events,
                           CommandId firing_id,
+                          EState *estate,
                           bool delete_ok)
  {
      AfterTriggerEvent event,
***************
*** 2108,2113 ****
--- 2143,2149 ----
      Relation    rel = NULL;
      TriggerDesc *trigdesc = NULL;
      FmgrInfo   *finfo = NULL;
+     Instrumentation *instr = NULL;

      /* Make a per-tuple memory context for trigger function calls */
      per_tuple_context =
***************
*** 2136,2170 ****
               */
              if (rel == NULL || rel->rd_id != event->ate_relid)
              {
!                 if (rel)
!                     heap_close(rel, NoLock);
!                 if (trigdesc)
!                     FreeTriggerDesc(trigdesc);
!                 if (finfo)
!                     pfree(finfo);
!
!                 /*
!                  * We assume that an appropriate lock is still held by
!                  * the executor, so grab no new lock here.
!                  */
!                 rel = heap_open(event->ate_relid, NoLock);
!
!                 /*
!                  * Copy relation's trigger info so that we have a
!                  * stable copy no matter what the called triggers do.
!                  */
!                 trigdesc = CopyTriggerDesc(rel->trigdesc);
!
!                 if (trigdesc == NULL)        /* should not happen */
!                     elog(ERROR, "relation %u has no triggers",
!                          event->ate_relid);

!                 /*
!                  * Allocate space to cache fmgr lookup info for
!                  * triggers.
!                  */
!                 finfo = (FmgrInfo *)
!                     palloc0(trigdesc->numtriggers * sizeof(FmgrInfo));
              }

              /*
--- 2172,2236 ----
               */
              if (rel == NULL || rel->rd_id != event->ate_relid)
              {
!                 if (estate)
!                 {
!                     /* Find target relation among estate's result rels */
!                     ResultRelInfo *rInfo;
!                     int        nr;
!
!                     rInfo = estate->es_result_relations;
!                     nr = estate->es_num_result_relations;
!                     while (nr > 0)
!                     {
!                         if (rInfo->ri_RelationDesc->rd_id == event->ate_relid)
!                             break;
!                         rInfo++;
!                         nr--;
!                     }
!                     if (nr <= 0)                /* should not happen */
!                         elog(ERROR, "could not find relation %u among query result relations",
!                              event->ate_relid);
!                     rel = rInfo->ri_RelationDesc;
!                     trigdesc = rInfo->ri_TrigDesc;
!                     finfo = rInfo->ri_TrigFunctions;
!                     instr = rInfo->ri_TrigInstrument;
!                 }
!                 else
!                 {
!                     /* Hard way: we manage the resources for ourselves */
!                     if (rel)
!                         heap_close(rel, NoLock);
!                     if (trigdesc)
!                         FreeTriggerDesc(trigdesc);
!                     if (finfo)
!                         pfree(finfo);
!                     Assert(instr == NULL);    /* never used in this case */
!
!                     /*
!                      * We assume that an appropriate lock is still held by
!                      * the executor, so grab no new lock here.
!                      */
!                     rel = heap_open(event->ate_relid, NoLock);
!
!                     /*
!                      * Copy relation's trigger info so that we have a
!                      * stable copy no matter what the called triggers do.
!                      */
!                     trigdesc = CopyTriggerDesc(rel->trigdesc);
!
!                     if (trigdesc == NULL)        /* should not happen */
!                         elog(ERROR, "relation %u has no triggers",
!                              event->ate_relid);
!
!                     /*
!                      * Allocate space to cache fmgr lookup info for
!                      * triggers.
!                      */
!                     finfo = (FmgrInfo *)
!                         palloc0(trigdesc->numtriggers * sizeof(FmgrInfo));

!                     /* Never any EXPLAIN info in this case */
!                 }
              }

              /*
***************
*** 2172,2178 ****
               * set, so recursive examinations of the event list won't try
               * to re-fire it.
               */
!             AfterTriggerExecute(event, rel, trigdesc, finfo,
                                  per_tuple_context);

              /*
--- 2238,2244 ----
               * set, so recursive examinations of the event list won't try
               * to re-fire it.
               */
!             AfterTriggerExecute(event, rel, trigdesc, finfo, instr,
                                  per_tuple_context);

              /*
***************
*** 2214,2225 ****
      events->tail = prev_event;

      /* Release working resources */
!     if (rel)
!         heap_close(rel, NoLock);
!     if (trigdesc)
!         FreeTriggerDesc(trigdesc);
!     if (finfo)
!         pfree(finfo);
      MemoryContextDelete(per_tuple_context);
  }

--- 2280,2295 ----
      events->tail = prev_event;

      /* Release working resources */
!     if (!estate)
!     {
!         if (rel)
!             heap_close(rel, NoLock);
!         if (trigdesc)
!             FreeTriggerDesc(trigdesc);
!         if (finfo)
!             pfree(finfo);
!         Assert(instr == NULL);    /* never used in this case */
!     }
      MemoryContextDelete(per_tuple_context);
  }

***************
*** 2308,2317 ****
   *    Called after one query has been completely processed. At this time
   *    we invoke all AFTER IMMEDIATE trigger events queued by the query, and
   *    transfer deferred trigger events to the global deferred-trigger list.
   * ----------
   */
  void
! AfterTriggerEndQuery(void)
  {
      AfterTriggerEventList *events;

--- 2378,2391 ----
   *    Called after one query has been completely processed. At this time
   *    we invoke all AFTER IMMEDIATE trigger events queued by the query, and
   *    transfer deferred trigger events to the global deferred-trigger list.
+  *
+  *    Note that this should be called just BEFORE closing down the executor
+  *    with ExecutorEnd, because we make use of the EState's info about
+  *    target relations.
   * ----------
   */
  void
! AfterTriggerEndQuery(EState *estate)
  {
      AfterTriggerEventList *events;

***************
*** 2339,2345 ****
          CommandId        firing_id = afterTriggers->firing_counter++;

          /* OK to delete the immediate events after processing them */
!         afterTriggerInvokeEvents(events, firing_id, true);
      }

      afterTriggers->query_depth--;
--- 2413,2419 ----
          CommandId        firing_id = afterTriggers->firing_counter++;

          /* OK to delete the immediate events after processing them */
!         afterTriggerInvokeEvents(events, firing_id, estate, true);
      }

      afterTriggers->query_depth--;
***************
*** 2381,2387 ****
      {
          CommandId        firing_id = afterTriggers->firing_counter++;

!         afterTriggerInvokeEvents(events, firing_id, true);
      }

      /*
--- 2455,2461 ----
      {
          CommandId        firing_id = afterTriggers->firing_counter++;

!         afterTriggerInvokeEvents(events, firing_id, NULL, true);
      }

      /*
***************
*** 2838,2844 ****
               * level, but we'd better not if inside a subtransaction, since
               * the subtransaction could later get rolled back.
               */
!             afterTriggerInvokeEvents(events, firing_id,
                                       !IsSubTransaction());
          }
      }
--- 2912,2918 ----
               * level, but we'd better not if inside a subtransaction, since
               * the subtransaction could later get rolled back.
               */
!             afterTriggerInvokeEvents(events, firing_id, NULL,
                                       !IsSubTransaction());
          }
      }
*** src/backend/executor/execMain.c.orig    Mon Mar 21 10:59:31 2005
--- src/backend/executor/execMain.c    Thu Mar 24 23:48:57 2005
***************
*** 39,44 ****
--- 39,45 ----
  #include "commands/trigger.h"
  #include "executor/execdebug.h"
  #include "executor/execdefs.h"
+ #include "executor/instrument.h"
  #include "miscadmin.h"
  #include "optimizer/clauses.h"
  #include "optimizer/var.h"
***************
*** 69,75 ****
  static void initResultRelInfo(ResultRelInfo *resultRelInfo,
                    Index resultRelationIndex,
                    List *rangeTable,
!                   CmdType operation);
  static TupleTableSlot *ExecutePlan(EState *estate, PlanState *planstate,
              CmdType operation,
              long numberTuples,
--- 70,77 ----
  static void initResultRelInfo(ResultRelInfo *resultRelInfo,
                    Index resultRelationIndex,
                    List *rangeTable,
!                   CmdType operation,
!                   bool doInstrument);
  static TupleTableSlot *ExecutePlan(EState *estate, PlanState *planstate,
              CmdType operation,
              long numberTuples,
***************
*** 508,514 ****
                  initResultRelInfo(resultRelInfo,
                                    lfirst_int(l),
                                    rangeTable,
!                                   operation);
                  resultRelInfo++;
              }
          }
--- 510,517 ----
                  initResultRelInfo(resultRelInfo,
                                    lfirst_int(l),
                                    rangeTable,
!                                   operation,
!                                   estate->es_instrument);
                  resultRelInfo++;
              }
          }
***************
*** 523,529 ****
              initResultRelInfo(resultRelInfos,
                                parseTree->resultRelation,
                                rangeTable,
!                               operation);
          }

          estate->es_result_relations = resultRelInfos;
--- 526,533 ----
              initResultRelInfo(resultRelInfos,
                                parseTree->resultRelation,
                                rangeTable,
!                               operation,
!                               estate->es_instrument);
          }

          estate->es_result_relations = resultRelInfos;
***************
*** 798,804 ****
  initResultRelInfo(ResultRelInfo *resultRelInfo,
                    Index resultRelationIndex,
                    List *rangeTable,
!                   CmdType operation)
  {
      Oid            resultRelationOid;
      Relation    resultRelationDesc;
--- 802,809 ----
  initResultRelInfo(ResultRelInfo *resultRelInfo,
                    Index resultRelationIndex,
                    List *rangeTable,
!                   CmdType operation,
!                   bool doInstrument)
  {
      Oid            resultRelationOid;
      Relation    resultRelationDesc;
***************
*** 837,843 ****
      resultRelInfo->ri_IndexRelationInfo = NULL;
      /* make a copy so as not to depend on relcache info not changing... */
      resultRelInfo->ri_TrigDesc = CopyTriggerDesc(resultRelationDesc->trigdesc);
!     resultRelInfo->ri_TrigFunctions = NULL;
      resultRelInfo->ri_ConstraintExprs = NULL;
      resultRelInfo->ri_junkFilter = NULL;

--- 842,863 ----
      resultRelInfo->ri_IndexRelationInfo = NULL;
      /* make a copy so as not to depend on relcache info not changing... */
      resultRelInfo->ri_TrigDesc = CopyTriggerDesc(resultRelationDesc->trigdesc);
!     if (resultRelInfo->ri_TrigDesc)
!     {
!         int        n = resultRelInfo->ri_TrigDesc->numtriggers;
!
!         resultRelInfo->ri_TrigFunctions = (FmgrInfo *)
!             palloc0(n * sizeof(FmgrInfo));
!         if (doInstrument)
!             resultRelInfo->ri_TrigInstrument = InstrAlloc(n);
!         else
!             resultRelInfo->ri_TrigInstrument = NULL;
!     }
!     else
!     {
!         resultRelInfo->ri_TrigFunctions = NULL;
!         resultRelInfo->ri_TrigInstrument = NULL;
!     }
      resultRelInfo->ri_ConstraintExprs = NULL;
      resultRelInfo->ri_junkFilter = NULL;

*** src/backend/executor/execProcnode.c.orig    Fri Dec 31 17:45:40 2004
--- src/backend/executor/execProcnode.c    Thu Mar 24 23:29:24 2005
***************
*** 252,258 ****

      /* Set up instrumentation for this node if requested */
      if (estate->es_instrument)
!         result->instrument = InstrAlloc();

      return result;
  }
--- 252,258 ----

      /* Set up instrumentation for this node if requested */
      if (estate->es_instrument)
!         result->instrument = InstrAlloc(1);

      return result;
  }
*** src/backend/executor/functions.c.orig    Wed Mar 16 16:38:07 2005
--- src/backend/executor/functions.c    Thu Mar 24 23:29:24 2005
***************
*** 399,406 ****
          {
              ActiveSnapshot = es->qd->snapshot;

              ExecutorEnd(es->qd);
-             AfterTriggerEndQuery();
          }
          PG_CATCH();
          {
--- 399,406 ----
          {
              ActiveSnapshot = es->qd->snapshot;

+             AfterTriggerEndQuery(es->qd->estate);
              ExecutorEnd(es->qd);
          }
          PG_CATCH();
          {
*** src/backend/executor/instrument.c.orig    Sun Mar 20 17:27:51 2005
--- src/backend/executor/instrument.c    Thu Mar 24 23:29:25 2005
***************
*** 18,30 ****
  #include "executor/instrument.h"


! /* Allocate new instrumentation structure */
  Instrumentation *
! InstrAlloc(void)
  {
!     Instrumentation *instr = palloc(sizeof(Instrumentation));

!     memset(instr, 0, sizeof(Instrumentation));

      return instr;
  }
--- 18,30 ----
  #include "executor/instrument.h"


! /* Allocate new instrumentation structure(s) */
  Instrumentation *
! InstrAlloc(int n)
  {
!     Instrumentation *instr = palloc0(n * sizeof(Instrumentation));

!     /* we don't need to do any initialization except zero 'em */

      return instr;
  }
*** src/backend/executor/spi.c.orig    Wed Mar 16 16:38:08 2005
--- src/backend/executor/spi.c    Thu Mar 24 23:29:25 2005
***************
*** 1546,1555 ****
              elog(ERROR, "consistency check on SPI tuple count failed");
      }

-     ExecutorEnd(queryDesc);
-
      /* Take care of any queued AFTER triggers */
!     AfterTriggerEndQuery();

      if (queryDesc->dest->mydest == SPI)
      {
--- 1546,1555 ----
              elog(ERROR, "consistency check on SPI tuple count failed");
      }

      /* Take care of any queued AFTER triggers */
!     AfterTriggerEndQuery(queryDesc->estate);
!
!     ExecutorEnd(queryDesc);

      if (queryDesc->dest->mydest == SPI)
      {
*** src/backend/tcop/pquery.c.orig    Wed Mar 16 16:38:08 2005
--- src/backend/tcop/pquery.c    Thu Mar 24 23:29:17 2005
***************
*** 206,218 ****
          }
      }

      /*
       * Now, we close down all the scans and free allocated resources.
       */
      ExecutorEnd(queryDesc);
-
-     /* And take care of any queued AFTER triggers */
-     AfterTriggerEndQuery();

      FreeQueryDesc(queryDesc);

--- 206,218 ----
          }
      }

+     /* Now take care of any queued AFTER triggers */
+     AfterTriggerEndQuery(queryDesc->estate);
+
      /*
       * Now, we close down all the scans and free allocated resources.
       */
      ExecutorEnd(queryDesc);

      FreeQueryDesc(queryDesc);

*** src/include/commands/trigger.h.orig    Fri Dec 31 17:46:48 2004
--- src/include/commands/trigger.h    Thu Mar 24 23:29:08 2005
***************
*** 156,162 ****

  extern void AfterTriggerBeginXact(void);
  extern void AfterTriggerBeginQuery(void);
! extern void AfterTriggerEndQuery(void);
  extern void AfterTriggerEndXact(void);
  extern void AfterTriggerAbortXact(void);
  extern void AfterTriggerBeginSubXact(void);
--- 156,162 ----

  extern void AfterTriggerBeginXact(void);
  extern void AfterTriggerBeginQuery(void);
! extern void AfterTriggerEndQuery(EState *estate);
  extern void AfterTriggerEndXact(void);
  extern void AfterTriggerAbortXact(void);
  extern void AfterTriggerBeginSubXact(void);
*** src/include/executor/instrument.h.orig    Sun Mar 20 17:27:52 2005
--- src/include/executor/instrument.h    Thu Mar 24 23:29:01 2005
***************
*** 70,76 ****
      double        nloops;            /* # of run cycles for this node */
  } Instrumentation;

! extern Instrumentation *InstrAlloc(void);
  extern void InstrStartNode(Instrumentation *instr);
  extern void InstrStopNode(Instrumentation *instr, bool returnedTuple);
  extern void InstrEndLoop(Instrumentation *instr);
--- 70,76 ----
      double        nloops;            /* # of run cycles for this node */
  } Instrumentation;

! extern Instrumentation *InstrAlloc(int n);
  extern void InstrStartNode(Instrumentation *instr);
  extern void InstrStopNode(Instrumentation *instr, bool returnedTuple);
  extern void InstrEndLoop(Instrumentation *instr);
*** src/include/nodes/execnodes.h.orig    Wed Mar 16 16:38:10 2005
--- src/include/nodes/execnodes.h    Thu Mar 24 23:28:54 2005
***************
*** 261,266 ****
--- 261,267 ----
   *        IndexRelationInfo        array of key/attr info for indices
   *        TrigDesc                triggers to be fired, if any
   *        TrigFunctions            cached lookup info for trigger functions
+  *        TrigInstrument            optional runtime measurements for triggers
   *        ConstraintExprs            array of constraint-checking expr states
   *        junkFilter                for removing junk attributes from tuples
   * ----------------
***************
*** 275,280 ****
--- 276,282 ----
      IndexInfo **ri_IndexRelationInfo;
      TriggerDesc *ri_TrigDesc;
      FmgrInfo   *ri_TrigFunctions;
+     struct Instrumentation *ri_TrigInstrument;
      List      **ri_ConstraintExprs;
      JunkFilter *ri_junkFilter;
  } ResultRelInfo;

pgsql-patches by date:

Previous
From: Christopher Kings-Lynne
Date:
Subject: Update psql and pg_dump for new COPY api
Next
From: Christopher Kings-Lynne
Date:
Subject: Re: WIP: make EXPLAIN ANALYZE show time spent in triggers