Re: Review: DTrace probes (merged version) ver_03 - Mailing list pgsql-hackers

Updated patch attached.

This patch addresses all of Alvaro's feedback except the new probes for
v3 protocol which will be submitted later along with the rest of the probes.

It also incorporates Tom's feedback as explained inline below.

I hope this patch is good to go for this commit fest. Will take care of
the rest in the next fest.

Tom Lane wrote:
> Zdenek Kotala <Zdenek.Kotala@Sun.COM> writes:
>
>> I performed review and I prepared own patch which contains only probes
>> without any issue. I suggest commit this patch because the rest of
>> patch is independent and it can be committed next commit fest after
>> rework.
>>
>
> I looked at this patch a little bit.  In addition to the comments Alvaro
> made, I have a couple more issues:
>
> * The probes that pass buffer tag elements are already broken by the
> pending "relation forks" patch: there is soon going to be another field
> in buffer tags.  Perhaps it'd be feasible to pass the buffer tag as a
> single probe argument to make that a bit more future-proof?  I'm not
> sure if that would complicate the use of the probe so much as to be
> counterproductive.
>
>
>
Took out the buffer tag argument for now. Will figure out how to best
solve this after this relation forks patch is committed.
>
> What I suggest might be a reasonable compromise is to copy needed
> typedefs directly into the probes.d file:
>
>     typedef unsigned int LocalTransactionId;
>
>     provider postgresql {
>
>     probe transaction__start(LocalTransactionId);
>
> This at least makes it possible to declare the probes cleanly,
> and it's fairly obvious what to fix if the principal definition of
> LocalTransactionId ever changes.  I don't have Solaris to test on, but
> on OS X this seems to behave the way we'd like: the typedef itself isn't
> copied into the emitted probes.h file, but the emitted extern
> declarations use it.
>
>
Implemented this suggestion. There are some weirdness with the OS X
compiler causing some of the probe declarations not to compile (see
comments in probe.d).  The compiler spits out some warnings because the
types don't show up in the function prototype in probes.h, but the
probes work okay. I think we can safely ignore the warnings.

--
Robert Lor           Sun Microsystems
Austin, USA          http://sun.com/postgresql

Index: src/backend/access/transam/clog.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/access/transam/clog.c,v
retrieving revision 1.46
diff -u -3 -p -r1.46 clog.c
--- src/backend/access/transam/clog.c    1 Jan 2008 19:45:46 -0000    1.46
+++ src/backend/access/transam/clog.c    30 Jul 2008 04:02:32 -0000
@@ -36,6 +36,7 @@
 #include "access/slru.h"
 #include "access/transam.h"
 #include "postmaster/bgwriter.h"
+#include "pg_trace.h"

 /*
  * Defines for CLOG page sizes.  A page is the same BLCKSZ as is used
@@ -313,7 +314,9 @@ void
 ShutdownCLOG(void)
 {
     /* Flush dirty CLOG pages to disk */
+    TRACE_POSTGRESQL_CLOG_CHECKPOINT_START(false);
     SimpleLruFlush(ClogCtl, false);
+    TRACE_POSTGRESQL_CLOG_CHECKPOINT_DONE(false);
 }

 /*
@@ -323,7 +326,9 @@ void
 CheckPointCLOG(void)
 {
     /* Flush dirty CLOG pages to disk */
+    TRACE_POSTGRESQL_CLOG_CHECKPOINT_START(true);
     SimpleLruFlush(ClogCtl, true);
+    TRACE_POSTGRESQL_CLOG_CHECKPOINT_DONE(true);
 }


Index: src/backend/access/transam/multixact.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/access/transam/multixact.c,v
retrieving revision 1.27
diff -u -3 -p -r1.27 multixact.c
--- src/backend/access/transam/multixact.c    1 Jan 2008 19:45:46 -0000    1.27
+++ src/backend/access/transam/multixact.c    30 Jul 2008 04:02:33 -0000
@@ -57,6 +57,7 @@
 #include "storage/lmgr.h"
 #include "utils/memutils.h"
 #include "storage/procarray.h"
+#include "pg_trace.h"


 /*
@@ -1497,8 +1498,10 @@ void
 ShutdownMultiXact(void)
 {
     /* Flush dirty MultiXact pages to disk */
+    TRACE_POSTGRESQL_MULTIXACT_CHECKPOINT_START(false);
     SimpleLruFlush(MultiXactOffsetCtl, false);
     SimpleLruFlush(MultiXactMemberCtl, false);
+    TRACE_POSTGRESQL_MULTIXACT_CHECKPOINT_DONE(false);
 }

 /*
@@ -1526,6 +1529,8 @@ MultiXactGetCheckptMulti(bool is_shutdow
 void
 CheckPointMultiXact(void)
 {
+    TRACE_POSTGRESQL_MULTIXACT_CHECKPOINT_START(true);
+
     /* Flush dirty MultiXact pages to disk */
     SimpleLruFlush(MultiXactOffsetCtl, true);
     SimpleLruFlush(MultiXactMemberCtl, true);
@@ -1540,6 +1545,8 @@ CheckPointMultiXact(void)
      */
     if (!InRecovery)
         TruncateMultiXact();
+
+    TRACE_POSTGRESQL_MULTIXACT_CHECKPOINT_DONE(true);
 }

 /*
Index: src/backend/access/transam/subtrans.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/access/transam/subtrans.c,v
retrieving revision 1.22
diff -u -3 -p -r1.22 subtrans.c
--- src/backend/access/transam/subtrans.c    26 Mar 2008 18:48:59 -0000    1.22
+++ src/backend/access/transam/subtrans.c    30 Jul 2008 04:02:34 -0000
@@ -32,6 +32,7 @@
 #include "access/subtrans.h"
 #include "access/transam.h"
 #include "utils/snapmgr.h"
+#include "pg_trace.h"


 /*
@@ -265,7 +266,9 @@ ShutdownSUBTRANS(void)
      * This is not actually necessary from a correctness point of view. We do
      * it merely as a debugging aid.
      */
+    TRACE_POSTGRESQL_SUBTRANS_CHECKPOINT_START(false);
     SimpleLruFlush(SubTransCtl, false);
+    TRACE_POSTGRESQL_SUBTRANS_CHECKPOINT_DONE(false);
 }

 /*
@@ -281,7 +284,9 @@ CheckPointSUBTRANS(void)
      * it merely to improve the odds that writing of dirty pages is done by
      * the checkpoint process and not by backends.
      */
+    TRACE_POSTGRESQL_SUBTRANS_CHECKPOINT_START(true);
     SimpleLruFlush(SubTransCtl, true);
+    TRACE_POSTGRESQL_SUBTRANS_CHECKPOINT_DONE(true);
 }


Index: src/backend/access/transam/twophase.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/access/transam/twophase.c,v
retrieving revision 1.43
diff -u -3 -p -r1.43 twophase.c
--- src/backend/access/transam/twophase.c    19 May 2008 18:16:26 -0000    1.43
+++ src/backend/access/transam/twophase.c    30 Jul 2008 04:02:35 -0000
@@ -57,6 +57,7 @@
 #include "storage/smgr.h"
 #include "utils/builtins.h"
 #include "utils/memutils.h"
+#include "pg_trace.h"


 /*
@@ -1387,6 +1388,9 @@ CheckPointTwoPhase(XLogRecPtr redo_horiz
      */
     if (max_prepared_xacts <= 0)
         return;                    /* nothing to do */
+
+    TRACE_POSTGRESQL_TWOPHASE_CHECKPOINT_START();
+
     xids = (TransactionId *) palloc(max_prepared_xacts * sizeof(TransactionId));
     nxids = 0;

@@ -1444,6 +1448,8 @@ CheckPointTwoPhase(XLogRecPtr redo_horiz
     }

     pfree(xids);
+
+    TRACE_POSTGRESQL_TWOPHASE_CHECKPOINT_DONE();
 }

 /*
Index: src/backend/postmaster/pgstat.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/postmaster/pgstat.c,v
retrieving revision 1.176
diff -u -3 -p -r1.176 pgstat.c
--- src/backend/postmaster/pgstat.c    30 Jun 2008 10:58:47 -0000    1.176
+++ src/backend/postmaster/pgstat.c    30 Jul 2008 04:02:37 -0000
@@ -61,6 +61,7 @@
 #include "utils/ps_status.h"
 #include "utils/rel.h"
 #include "utils/tqual.h"
+#include "pg_trace.h"


 /* ----------
@@ -2202,6 +2203,8 @@ pgstat_report_activity(const char *cmd_s
     TimestampTz start_timestamp;
     int            len;

+    TRACE_POSTGRESQL_STATEMENT_STATUS(cmd_str);
+
     if (!pgstat_track_activities || !beentry)
         return;

Index: src/backend/storage/buffer/bufmgr.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/storage/buffer/bufmgr.c,v
retrieving revision 1.234
diff -u -3 -p -r1.234 bufmgr.c
--- src/backend/storage/buffer/bufmgr.c    13 Jul 2008 20:45:47 -0000    1.234
+++ src/backend/storage/buffer/bufmgr.c    30 Jul 2008 04:02:38 -0000
@@ -43,6 +43,7 @@
 #include "utils/rel.h"
 #include "utils/resowner.h"
 #include "pgstat.h"
+#include "pg_trace.h"


 /* Note: these two macros only work on shared buffers, not local ones! */
@@ -213,12 +214,22 @@ ReadBuffer_common(SMgrRelation smgr, boo
     if (isExtend)
         blockNum = smgrnblocks(smgr);

+    TRACE_POSTGRESQL_BUFFER_READ_START(blockNum, smgr->smgr_rnode.spcNode,
+        smgr->smgr_rnode.dbNode, smgr->smgr_rnode.relNode, isLocalBuf);
+
     if (isLocalBuf)
     {
         ReadLocalBufferCount++;
         bufHdr = LocalBufferAlloc(smgr, blockNum, &found);
         if (found)
+        {
             LocalBufferHitCount++;
+            TRACE_POSTGRESQL_BUFFER_HIT(true); /* true == local buffer */
+        }
+        else
+        {
+            TRACE_POSTGRESQL_BUFFER_MISS(true); /* ditto */
+        }
     }
     else
     {
@@ -230,7 +241,14 @@ ReadBuffer_common(SMgrRelation smgr, boo
          */
         bufHdr = BufferAlloc(smgr, blockNum, strategy, &found);
         if (found)
+        {
             BufferHitCount++;
+            TRACE_POSTGRESQL_BUFFER_HIT(false); /* false != local buffer */
+        }
+        else
+        {
+            TRACE_POSTGRESQL_BUFFER_MISS(false); /* ditto */
+        }
     }

     /* At this point we do NOT hold any locks. */
@@ -246,6 +264,11 @@ ReadBuffer_common(SMgrRelation smgr, boo
             if (VacuumCostActive)
                 VacuumCostBalance += VacuumCostPageHit;

+            TRACE_POSTGRESQL_BUFFER_READ_DONE(blockNum,
+                smgr->smgr_rnode.spcNode,
+                smgr->smgr_rnode.dbNode,
+                smgr->smgr_rnode.relNode, isLocalBuf, found);
+
             return BufferDescriptorGetBuffer(bufHdr);
         }

@@ -368,6 +391,10 @@ ReadBuffer_common(SMgrRelation smgr, boo
     if (VacuumCostActive)
         VacuumCostBalance += VacuumCostPageMiss;

+    TRACE_POSTGRESQL_BUFFER_READ_DONE(blockNum, smgr->smgr_rnode.spcNode,
+            smgr->smgr_rnode.dbNode, smgr->smgr_rnode.relNode,
+            isLocalBuf, found);
+
     return BufferDescriptorGetBuffer(bufHdr);
 }

@@ -1086,6 +1113,8 @@ BufferSync(int flags)
     if (num_to_write == 0)
         return;                    /* nothing to do */

+    TRACE_POSTGRESQL_BUFFER_SYNC_START(NBuffers, num_to_write);
+
     /*
      * Loop over all buffers again, and write the ones (still) marked with
      * BM_CHECKPOINT_NEEDED.  In this loop, we start at the clock sweep point
@@ -1117,6 +1146,7 @@ BufferSync(int flags)
         {
             if (SyncOneBuffer(buf_id, false) & BUF_WRITTEN)
             {
+                TRACE_POSTGRESQL_BUFFER_SYNC_WRITTEN(buf_id);
                 BgWriterStats.m_buf_written_checkpoints++;
                 num_written++;

@@ -1147,6 +1177,8 @@ BufferSync(int flags)
             buf_id = 0;
     }

+    TRACE_POSTGRESQL_BUFFER_SYNC_DONE(NBuffers, num_written, num_to_write);
+
     /*
      * Update checkpoint statistics. As noted above, this doesn't include
      * buffers written by other backends or bgwriter scan.
@@ -1653,11 +1685,13 @@ PrintBufferLeakWarning(Buffer buffer)
 void
 CheckPointBuffers(int flags)
 {
+    TRACE_POSTGRESQL_BUFFER_CHECKPOINT_START(flags);
     CheckpointStats.ckpt_write_t = GetCurrentTimestamp();
     BufferSync(flags);
     CheckpointStats.ckpt_sync_t = GetCurrentTimestamp();
     smgrsync();
     CheckpointStats.ckpt_sync_end_t = GetCurrentTimestamp();
+    TRACE_POSTGRESQL_BUFFER_CHECKPOINT_DONE();
 }


@@ -1759,6 +1793,10 @@ FlushBuffer(volatile BufferDesc *buf, SM
     if (reln == NULL)
         reln = smgropen(buf->tag.rnode);

+    TRACE_POSTGRESQL_BUFFER_FLUSH_START(reln->smgr_rnode.spcNode,
+         reln->smgr_rnode.dbNode,
+         reln->smgr_rnode.relNode);
+
     /*
      * Force XLOG flush up to buffer's LSN.  This implements the basic WAL
      * rule that log updates must hit disk before any of the data-file changes
@@ -1785,6 +1823,9 @@ FlushBuffer(volatile BufferDesc *buf, SM

     BufferFlushCount++;

+    TRACE_POSTGRESQL_BUFFER_FLUSH_DONE(reln->smgr_rnode.spcNode,
+         reln->smgr_rnode.dbNode, reln->smgr_rnode.relNode);
+
     /*
      * Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
      * end the io_in_progress state.
Index: src/backend/storage/lmgr/deadlock.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/storage/lmgr/deadlock.c,v
retrieving revision 1.53
diff -u -3 -p -r1.53 deadlock.c
--- src/backend/storage/lmgr/deadlock.c    24 Mar 2008 18:22:36 -0000    1.53
+++ src/backend/storage/lmgr/deadlock.c    30 Jul 2008 04:02:39 -0000
@@ -30,6 +30,7 @@
 #include "storage/lmgr.h"
 #include "storage/proc.h"
 #include "utils/memutils.h"
+#include "pg_trace.h"


 /* One edge in the waits-for graph */
@@ -222,6 +223,8 @@ DeadLockCheck(PGPROC *proc)
          */
         int            nSoftEdges;

+        TRACE_POSTGRESQL_DEADLOCK_FOUND();
+
         nWaitOrders = 0;
         if (!FindLockCycle(proc, possibleConstraints, &nSoftEdges))
             elog(FATAL, "deadlock seems to have disappeared");
Index: src/backend/storage/lmgr/lock.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/storage/lmgr/lock.c,v
retrieving revision 1.183
diff -u -3 -p -r1.183 lock.c
--- src/backend/storage/lmgr/lock.c    17 Mar 2008 19:44:41 -0000    1.183
+++ src/backend/storage/lmgr/lock.c    30 Jul 2008 04:02:40 -0000
@@ -787,11 +787,11 @@ LockAcquire(const LOCKTAG *locktag,
          * Sleep till someone wakes me up.
          */

-        TRACE_POSTGRESQL_LOCK_STARTWAIT(locktag->locktag_field2, lockmode);
+        TRACE_POSTGRESQL_LOCK_WAIT_START(locktag->locktag_field2, lockmode);

         WaitOnLock(locallock, owner);

-        TRACE_POSTGRESQL_LOCK_ENDWAIT(locktag->locktag_field2, lockmode);
+        TRACE_POSTGRESQL_LOCK_WAIT_DONE(locktag->locktag_field2, lockmode);

         /*
          * NOTE: do not do any material change of state between here and
Index: src/backend/storage/lmgr/lwlock.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/storage/lmgr/lwlock.c,v
retrieving revision 1.51
diff -u -3 -p -r1.51 lwlock.c
--- src/backend/storage/lmgr/lwlock.c    17 Mar 2008 19:44:41 -0000    1.51
+++ src/backend/storage/lmgr/lwlock.c    30 Jul 2008 04:02:40 -0000
@@ -448,7 +448,7 @@ LWLockAcquire(LWLockId lockid, LWLockMod
         block_counts[lockid]++;
 #endif

-        TRACE_POSTGRESQL_LWLOCK_STARTWAIT(lockid, mode);
+        TRACE_POSTGRESQL_LWLOCK_WAIT_START(lockid, mode);

         for (;;)
         {
@@ -459,7 +459,7 @@ LWLockAcquire(LWLockId lockid, LWLockMod
             extraWaits++;
         }

-        TRACE_POSTGRESQL_LWLOCK_ENDWAIT(lockid, mode);
+        TRACE_POSTGRESQL_LWLOCK_WAIT_DONE(lockid, mode);

         LOG_LWDEBUG("LWLockAcquire", lockid, "awakened");

Index: src/backend/tcop/postgres.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/tcop/postgres.c,v
retrieving revision 1.554
diff -u -3 -p -r1.554 postgres.c
--- src/backend/tcop/postgres.c    18 Jul 2008 20:26:06 -0000    1.554
+++ src/backend/tcop/postgres.c    30 Jul 2008 04:02:42 -0000
@@ -71,6 +71,7 @@
 #include "mb/pg_wchar.h"

 #include "pgstat.h"
+#include "pg_trace.h"

 extern int    optind;
 extern char *optarg;
@@ -551,6 +552,8 @@ pg_parse_query(const char *query_string)
 {
     List       *raw_parsetree_list;

+    TRACE_POSTGRESQL_QUERY_PARSE_START(query_string);
+
     if (log_parser_stats)
         ResetUsage();

@@ -572,6 +575,8 @@ pg_parse_query(const char *query_string)
     }
 #endif

+    TRACE_POSTGRESQL_QUERY_PARSE_DONE(query_string);
+
     return raw_parsetree_list;
 }

@@ -591,6 +596,8 @@ pg_analyze_and_rewrite(Node *parsetree,
     Query       *query;
     List       *querytree_list;

+    TRACE_POSTGRESQL_QUERY_REWRITE_START(query_string);
+
     /*
      * (1) Perform parse analysis.
      */
@@ -607,6 +614,8 @@ pg_analyze_and_rewrite(Node *parsetree,
      */
     querytree_list = pg_rewrite_query(query);

+    TRACE_POSTGRESQL_QUERY_REWRITE_DONE(query_string);
+
     return querytree_list;
 }

@@ -677,6 +686,8 @@ pg_plan_query(Query *querytree, int curs
     if (querytree->commandType == CMD_UTILITY)
         return NULL;

+    TRACE_POSTGRESQL_QUERY_PLAN_START();
+
     if (log_planner_stats)
         ResetUsage();

@@ -711,6 +722,8 @@ pg_plan_query(Query *querytree, int curs
     if (Debug_print_plan)
         elog_node_display(DEBUG1, "plan", plan, Debug_pretty_print);

+    TRACE_POSTGRESQL_QUERY_PLAN_DONE();
+
     return plan;
 }

@@ -785,6 +798,7 @@ exec_simple_query(const char *query_stri
     bool        isTopLevel;
     char        msec_str[32];

+
     /*
      * Report query to various monitoring facilities.
      */
@@ -792,6 +806,8 @@ exec_simple_query(const char *query_stri

     pgstat_report_activity(query_string);

+    TRACE_POSTGRESQL_QUERY_START(query_string);
+
     /*
      * We use save_log_statement_stats so ShowUsage doesn't report incorrect
      * results because ResetUsage wasn't called.
@@ -1058,6 +1074,8 @@ exec_simple_query(const char *query_stri
     if (save_log_statement_stats)
         ShowUsage("QUERY STATISTICS");

+    TRACE_POSTGRESQL_QUERY_DONE(query_string);
+
     debug_query_string = NULL;
 }

Index: src/backend/tcop/pquery.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/tcop/pquery.c,v
retrieving revision 1.123
diff -u -3 -p -r1.123 pquery.c
--- src/backend/tcop/pquery.c    12 May 2008 20:02:02 -0000    1.123
+++ src/backend/tcop/pquery.c    30 Jul 2008 04:02:43 -0000
@@ -24,6 +24,7 @@
 #include "tcop/utility.h"
 #include "utils/memutils.h"
 #include "utils/snapmgr.h"
+#include "pg_trace.h"


 /*
@@ -711,6 +712,8 @@ PortalRun(Portal portal, long count, boo

     AssertArg(PortalIsValid(portal));

+    TRACE_POSTGRESQL_QUERY_EXECUTE_START();
+
     /* Initialize completion tag to empty string */
     if (completionTag)
         completionTag[0] = '\0';
@@ -857,6 +860,8 @@ PortalRun(Portal portal, long count, boo

     if (log_executor_stats && portal->strategy != PORTAL_MULTI_QUERY)
         ShowUsage("EXECUTOR STATISTICS");
+
+    TRACE_POSTGRESQL_QUERY_EXECUTE_DONE();

     return result;
 }
@@ -1237,6 +1242,8 @@ PortalRunMulti(Portal portal, bool isTop
              */
             PlannedStmt *pstmt = (PlannedStmt *) stmt;

+            TRACE_POSTGRESQL_QUERY_EXECUTE_START();
+
             if (log_executor_stats)
                 ResetUsage();

@@ -1257,6 +1264,8 @@ PortalRunMulti(Portal portal, bool isTop

             if (log_executor_stats)
                 ShowUsage("EXECUTOR STATISTICS");
+
+            TRACE_POSTGRESQL_QUERY_EXECUTE_DONE();
         }
         else
         {
Index: src/backend/utils/probes.d
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/utils/probes.d,v
retrieving revision 1.2
diff -u -3 -p -r1.2 probes.d
--- src/backend/utils/probes.d    2 Jan 2008 02:42:06 -0000    1.2
+++ src/backend/utils/probes.d    30 Jul 2008 04:02:43 -0000
@@ -7,18 +7,99 @@
  * ----------
  */

+
+typedef unsigned int LocalTransactionId;
+typedef int LWLockId;
+typedef int LWLockMode;
+typedef unsigned int locktag_field2;
+typedef int LOCKMODE;
+typedef const char * query_string;
+typedef int sortType;
+typedef int trueFalse;
+typedef int nkeys;
+typedef int workMem;
+typedef int randomAccess;
+typedef unsigned long LogicalTapeSetPtr;
+typedef long spaceUsed;
+typedef unsigned int BlockNumber;
+typedef unsigned int Oid;
+typedef int isLocalBuf;
+typedef int found;
+typedef int flags;
+typedef int num_to_write;
+typedef int num_written;
+typedef int NBuffers;
+typedef int buf_id;
+
+
 provider postgresql {

-probe transaction__start(int);
-probe transaction__commit(int);
-probe transaction__abort(int);
-probe lwlock__acquire(int, int);
-probe lwlock__release(int);
-probe lwlock__startwait(int, int);
-probe lwlock__endwait(int, int);
-probe lwlock__condacquire(int, int);
-probe lwlock__condacquire__fail(int, int);
-probe lock__startwait(int, int);
-probe lock__endwait(int, int);
+    /*
+     * Due to a bug in Mac OS X 10.5, using built-in typedefs (e.g. uintptr_t,
+     * uint32_t, etc.) cause compilation errors.
+     */
+
+    probe transaction__start(LocalTransactionId);
+    probe transaction__commit(LocalTransactionId);
+    probe transaction__abort(LocalTransactionId);
+
+    probe lwlock__acquire(LWLockId, LWLockMode);
+    probe lwlock__release(LWLockId);
+    probe lwlock__wait__start(LWLockId, LWLockMode);
+    probe lwlock__wait__done(LWLockId, LWLockMode);
+    probe lwlock__condacquire(LWLockId, LWLockMode);
+    probe lwlock__condacquire__fail(LWLockId, LWLockMode);
+
+    /* The following probe declarations cause compilation errors
+         * on Mac OS X but not on Solaris. Need further investigation.
+     * probe lock__wait__start(locktag_field2, LOCKMODE);
+     * probe lock__wait__done(locktag_field2, LOCKMODE);
+     */
+    probe lock__wait__start(unsigned int, int);
+    probe lock__wait__done(unsigned int, int);
+
+    probe query__parse__start(query_string);
+    probe query__parse__done(query_string);
+    probe query__rewrite__start(query_string);
+    probe query__rewrite__done(query_string);
+    probe query__plan__start();
+    probe query__plan__done();
+    probe query__execute__start();
+    probe query__execute__done();
+    probe query__start(query_string);
+    probe query__done(query_string);
+    probe statement__status(query_string);
+
+    probe sort__start(sortType, trueFalse, nkeys, workMem, randomAccess);
+    probe sort__end(LogicalTapeSetPtr, spaceUsed);
+
+    /* The following probe declarations cause compilation errors
+         * on Mac OS X but not on Solaris. Need further investigation.
+     * probe buffer__read__start(BlockNumber, Oid, Oid, Oid, isLocalBuf);
+     * probe buffer__read__done(BlockNumber, Oid, Oid, Oid, isLocalBuf, found);
+     */
+    probe buffer__read__start(unsigned int, unsigned int, unsigned int, unsigned int, int);
+    probe buffer__read__done(unsigned int, unsigned int, unsigned int, unsigned int, int, int);
+
+    probe buffer__flush__start(Oid, Oid, Oid);
+    probe buffer__flush__done(Oid, Oid, Oid);
+
+    probe buffer__hit(trueFalse);
+    probe buffer__miss(trueFalse);
+    probe buffer__checkpoint__start(flags);
+    probe buffer__checkpoint__done();
+    probe buffer__sync__start(NBuffers, num_to_write);
+    probe buffer__sync__written(buf_id);
+    probe buffer__sync__done(NBuffers, num_written, num_to_write);
+
+    probe deadlock__found();

+    probe clog__checkpoint__start(trueFalse);
+    probe clog__checkpoint__done(trueFalse);
+    probe subtrans__checkpoint__start(trueFalse);
+    probe subtrans__checkpoint__done(trueFalse);
+    probe multixact__checkpoint__start(trueFalse);
+    probe multixact__checkpoint__done(trueFalse);
+    probe twophase__checkpoint__start();
+    probe twophase__checkpoint__done();
 };
Index: src/backend/utils/sort/tuplesort.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/utils/sort/tuplesort.c,v
retrieving revision 1.85
diff -u -3 -p -r1.85 tuplesort.c
--- src/backend/utils/sort/tuplesort.c    19 Jun 2008 00:46:05 -0000    1.85
+++ src/backend/utils/sort/tuplesort.c    30 Jul 2008 04:02:45 -0000
@@ -115,12 +115,18 @@
 #include "utils/rel.h"
 #include "utils/syscache.h"
 #include "utils/tuplesort.h"
+#include "pg_trace.h"


 /* GUC variables */
 #ifdef TRACE_SORT
 bool        trace_sort = false;
 #endif
+
+#define HEAP_SORT    0
+#define INDEX_SORT    1
+#define DATUM_SORT    2
+
 #ifdef DEBUG_BOUNDED_SORT
 bool        optimize_bounded_sort = true;
 #endif
@@ -569,6 +575,7 @@ tuplesort_begin_heap(TupleDesc tupDesc,
              "begin tuple sort: nkeys = %d, workMem = %d, randomAccess = %c",
              nkeys, workMem, randomAccess ? 't' : 'f');
 #endif
+    TRACE_POSTGRESQL_SORT_START(HEAP_SORT, false, nkeys, workMem, randomAccess);

     state->nKeys = nkeys;

@@ -636,6 +643,8 @@ tuplesort_begin_index_btree(Relation ind

     state->nKeys = RelationGetNumberOfAttributes(indexRel);

+    TRACE_POSTGRESQL_SORT_START(INDEX_SORT, enforceUnique, state->nKeys, workMem, randomAccess);
+
     state->comparetup = comparetup_index_btree;
     state->copytup = copytup_index;
     state->writetup = writetup_index;
@@ -713,6 +722,7 @@ tuplesort_begin_datum(Oid datumType,
              "begin datum sort: workMem = %d, randomAccess = %c",
              workMem, randomAccess ? 't' : 'f');
 #endif
+    TRACE_POSTGRESQL_SORT_START(DATUM_SORT, false, 1, workMem, randomAccess);

     state->nKeys = 1;            /* always a one-column sort */

@@ -825,6 +835,11 @@ tuplesort_end(Tuplesortstate *state)
     }
 #endif

+    TRACE_POSTGRESQL_SORT_END(state->tapeset,
+            (state->tapeset ? LogicalTapeSetBlocks(state->tapeset) :
+            (state->allowedMem - state->availMem + 1023) / 1024));
+
+
     MemoryContextSwitchTo(oldcontext);

     /*