Add a few more DTrace probes to the backend.

Robert Lor

src/backend/Makefile

@@ -5,7 +5,7 @@
 # Portions Copyright (c) 1996-2008, PostgreSQL Global Development Group
 # Portions Copyright (c) 1994, Regents of the University of California
 #
-# $PostgreSQL: pgsql/src/backend/Makefile,v 1.128 2008/03/17 19:44:40 petere Exp $
+# $PostgreSQL: pgsql/src/backend/Makefile,v 1.129 2008/08/01 13:16:08 alvherre Exp $
 #
 #-------------------------------------------------------------------------
 
@@ -147,7 +147,7 @@ $(top_builddir)/src/include/utils/probes.h: utils/probes.h
 
 ifeq ($(PORTNAME), solaris)
 utils/probes.o: utils/probes.d $(SUBDIROBJS)
-	$(DTRACE) $(DTRACEFLAGS) -G -s $(call expand_subsys,$^) -o $@
+	$(DTRACE) $(DTRACEFLAGS) -C -G -s $(call expand_subsys,$^) -o $@
 endif
 
 

src/backend/access/transam/clog.c

@@ -26,7 +26,7 @@
  * Portions Copyright (c) 1996-2008, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/backend/access/transam/clog.c,v 1.46 2008/01/01 19:45:46 momjian Exp $
+ * $PostgreSQL: pgsql/src/backend/access/transam/clog.c,v 1.47 2008/08/01 13:16:08 alvherre Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -35,6 +35,7 @@
 #include "access/clog.h"
 #include "access/slru.h"
 #include "access/transam.h"
+#include "pg_trace.h"
 #include "postmaster/bgwriter.h"
 
 /*
@@ -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);
 }
 
 

src/backend/access/transam/multixact.c

@@ -42,7 +42,7 @@
  * Portions Copyright (c) 1996-2008, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/backend/access/transam/multixact.c,v 1.27 2008/01/01 19:45:46 momjian Exp $
+ * $PostgreSQL: pgsql/src/backend/access/transam/multixact.c,v 1.28 2008/08/01 13:16:08 alvherre Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -53,10 +53,11 @@
 #include "access/transam.h"
 #include "access/xact.h"
 #include "miscadmin.h"
+#include "pg_trace.h"
 #include "storage/backendid.h"
 #include "storage/lmgr.h"
-#include "utils/memutils.h"
 #include "storage/procarray.h"
+#include "utils/memutils.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_shutdown,
 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);
 }
 
 /*

src/backend/access/transam/subtrans.c

@@ -22,7 +22,7 @@
  * Portions Copyright (c) 1996-2008, PostgreSQL Global Development Group
  * Portions Copyright (c) 1994, Regents of the University of California
  *
- * $PostgreSQL: pgsql/src/backend/access/transam/subtrans.c,v 1.22 2008/03/26 18:48:59 alvherre Exp $
+ * $PostgreSQL: pgsql/src/backend/access/transam/subtrans.c,v 1.23 2008/08/01 13:16:08 alvherre Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -31,6 +31,7 @@
 #include "access/slru.h"
 #include "access/subtrans.h"
 #include "access/transam.h"
+#include "pg_trace.h"
 #include "utils/snapmgr.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);
 }
 
 

src/backend/access/transam/twophase.c

@@ -7,7 +7,7 @@
  * Portions Copyright (c) 1994, Regents of the University of California
  *
  * IDENTIFICATION
- *		$PostgreSQL: pgsql/src/backend/access/transam/twophase.c,v 1.43 2008/05/19 18:16:26 heikki Exp $
+ *		$PostgreSQL: pgsql/src/backend/access/transam/twophase.c,v 1.44 2008/08/01 13:16:08 alvherre Exp $
  *
  * NOTES
  *		Each global transaction is associated with a global transaction
@@ -51,6 +51,7 @@
 #include "catalog/pg_type.h"
 #include "funcapi.h"
 #include "miscadmin.h"
+#include "pg_trace.h"
 #include "pgstat.h"
 #include "storage/fd.h"
 #include "storage/procarray.h"
@@ -1387,6 +1388,9 @@ CheckPointTwoPhase(XLogRecPtr redo_horizon)
 	 */
 	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_horizon)
 	}
 
 	pfree(xids);
+
+	TRACE_POSTGRESQL_TWOPHASE_CHECKPOINT_DONE();
 }
 
 /*

src/backend/postmaster/pgstat.c

@@ -13,7 +13,7 @@
  *
  *	Copyright (c) 2001-2008, PostgreSQL Global Development Group
  *
- *	$PostgreSQL: pgsql/src/backend/postmaster/pgstat.c,v 1.176 2008/06/30 10:58:47 heikki Exp $
+ *	$PostgreSQL: pgsql/src/backend/postmaster/pgstat.c,v 1.177 2008/08/01 13:16:08 alvherre Exp $
  * ----------
  */
 #include "postgres.h"
@@ -48,6 +48,7 @@
 #include "libpq/pqsignal.h"
 #include "mb/pg_wchar.h"
 #include "miscadmin.h"
+#include "pg_trace.h"
 #include "postmaster/autovacuum.h"
 #include "postmaster/fork_process.h"
 #include "postmaster/postmaster.h"
@@ -2202,6 +2203,8 @@ pgstat_report_activity(const char *cmd_str)
 	TimestampTz start_timestamp;
 	int			len;
 
+	TRACE_POSTGRESQL_STATEMENT_STATUS(cmd_str);
+
 	if (!pgstat_track_activities || !beentry)
 		return;
 

src/backend/storage/buffer/bufmgr.c

@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *	  $PostgreSQL: pgsql/src/backend/storage/buffer/bufmgr.c,v 1.234 2008/07/13 20:45:47 tgl Exp $
+ *	  $PostgreSQL: pgsql/src/backend/storage/buffer/bufmgr.c,v 1.235 2008/08/01 13:16:08 alvherre Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -34,6 +34,8 @@
 #include <unistd.h>
 
 #include "miscadmin.h"
+#include "pg_trace.h"
+#include "pgstat.h"
 #include "postmaster/bgwriter.h"
 #include "storage/buf_internals.h"
 #include "storage/bufmgr.h"
@@ -42,7 +44,6 @@
 #include "storage/smgr.h"
 #include "utils/rel.h"
 #include "utils/resowner.h"
-#include "pgstat.h"
 
 
 /* Note: these two macros only work on shared buffers, not local ones! */
@@ -213,12 +214,22 @@ ReadBuffer_common(SMgrRelation smgr, bool isLocalBuf, BlockNumber blockNum,
 	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, bool isLocalBuf, BlockNumber blockNum,
 		 */
 		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, bool isLocalBuf, BlockNumber blockNum,
 			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, bool isLocalBuf, BlockNumber blockNum,
 	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, SMgrRelation reln)
 	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, SMgrRelation reln)
 
 	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.

src/backend/storage/lmgr/deadlock.c

@@ -12,7 +12,7 @@
  *
  *
  * IDENTIFICATION
- *	  $PostgreSQL: pgsql/src/backend/storage/lmgr/deadlock.c,v 1.53 2008/03/24 18:22:36 tgl Exp $
+ *	  $PostgreSQL: pgsql/src/backend/storage/lmgr/deadlock.c,v 1.54 2008/08/01 13:16:09 alvherre Exp $
  *
  *	Interface:
  *
@@ -26,6 +26,7 @@
 #include "postgres.h"
 
 #include "miscadmin.h"
+#include "pg_trace.h"
 #include "pgstat.h"
 #include "storage/lmgr.h"
 #include "storage/proc.h"
@@ -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");

src/backend/storage/lmgr/lock.c

@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *	  $PostgreSQL: pgsql/src/backend/storage/lmgr/lock.c,v 1.183 2008/03/17 19:44:41 petere Exp $
+ *	  $PostgreSQL: pgsql/src/backend/storage/lmgr/lock.c,v 1.184 2008/08/01 13:16:09 alvherre Exp $
  *
  * NOTES
  *	  A lock table is a shared memory hash table.  When
@@ -36,11 +36,11 @@
 #include "access/twophase.h"
 #include "access/twophase_rmgr.h"
 #include "miscadmin.h"
+#include "pg_trace.h"
 #include "pgstat.h"
 #include "utils/memutils.h"
 #include "utils/ps_status.h"
 #include "utils/resowner.h"
-#include "pg_trace.h"
 
 
 /* This configuration variable is used to set the lock table size */
@@ -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

src/backend/storage/lmgr/lwlock.c

@@ -15,7 +15,7 @@
  * Portions Copyright (c) 1994, Regents of the University of California
  *
  * IDENTIFICATION
- *	  $PostgreSQL: pgsql/src/backend/storage/lmgr/lwlock.c,v 1.51 2008/03/17 19:44:41 petere Exp $
+ *	  $PostgreSQL: pgsql/src/backend/storage/lmgr/lwlock.c,v 1.52 2008/08/01 13:16:09 alvherre Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -25,10 +25,10 @@
 #include "access/multixact.h"
 #include "access/subtrans.h"
 #include "miscadmin.h"
+#include "pg_trace.h"
 #include "storage/ipc.h"
 #include "storage/proc.h"
 #include "storage/spin.h"
-#include "pg_trace.h"
 
 
 /* We use the ShmemLock spinlock to protect LWLockAssign */
@@ -448,7 +448,7 @@ LWLockAcquire(LWLockId lockid, LWLockMode mode)
 		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, LWLockMode mode)
 			extraWaits++;
 		}
 
-		TRACE_POSTGRESQL_LWLOCK_ENDWAIT(lockid, mode);
+		TRACE_POSTGRESQL_LWLOCK_WAIT_DONE(lockid, mode);
 
 		LOG_LWDEBUG("LWLockAcquire", lockid, "awakened");
 

src/backend/tcop/postgres.c

@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *	  $PostgreSQL: pgsql/src/backend/tcop/postgres.c,v 1.554 2008/07/18 20:26:06 tgl Exp $
+ *	  $PostgreSQL: pgsql/src/backend/tcop/postgres.c,v 1.555 2008/08/01 13:16:09 alvherre Exp $
  *
  * NOTES
  *	  this is the "main" module of the postgres backend and
@@ -50,6 +50,8 @@
 #include "miscadmin.h"
 #include "nodes/print.h"
 #include "optimizer/planner.h"
+#include "pgstat.h"
+#include "pg_trace.h"
 #include "parser/analyze.h"
 #include "parser/parser.h"
 #include "postmaster/autovacuum.h"
@@ -70,7 +72,6 @@
 #include "utils/snapmgr.h"
 #include "mb/pg_wchar.h"
 
-#include "pgstat.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, const char *query_string,
 	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, const char *query_string,
 	 */
 	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 cursorOptions, ParamListInfo boundParams)
 	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 cursorOptions, ParamListInfo boundParams)
 	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_string)
 	bool		isTopLevel;
 	char		msec_str[32];
 
+
 	/*
 	 * Report query to various monitoring facilities.
 	 */
@@ -792,6 +806,8 @@ exec_simple_query(const char *query_string)
 
 	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_string)
 	if (save_log_statement_stats)
 		ShowUsage("QUERY STATISTICS");
 
+	TRACE_POSTGRESQL_QUERY_DONE(query_string);
+
 	debug_query_string = NULL;
 }
 

src/backend/tcop/pquery.c

@@ -8,7 +8,7 @@
  *
  *
  * IDENTIFICATION
- *	  $PostgreSQL: pgsql/src/backend/tcop/pquery.c,v 1.123 2008/05/12 20:02:02 alvherre Exp $
+ *	  $PostgreSQL: pgsql/src/backend/tcop/pquery.c,v 1.124 2008/08/01 13:16:09 alvherre Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -19,6 +19,7 @@
 #include "commands/prepare.h"
 #include "commands/trigger.h"
 #include "miscadmin.h"
+#include "pg_trace.h"
 #include "tcop/pquery.h"
 #include "tcop/tcopprot.h"
 #include "tcop/utility.h"
@@ -711,6 +712,8 @@ PortalRun(Portal portal, long count, bool isTopLevel,
 
 	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, bool isTopLevel,
 
 	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 isTopLevel,
 			 */
 			PlannedStmt *pstmt = (PlannedStmt *) stmt;
 
+			TRACE_POSTGRESQL_QUERY_EXECUTE_START();
+
 			if (log_executor_stats)
 				ResetUsage();
 
@@ -1257,6 +1264,8 @@ PortalRunMulti(Portal portal, bool isTopLevel,
 
 			if (log_executor_stats)
 				ShowUsage("EXECUTOR STATISTICS");
+
+			TRACE_POSTGRESQL_QUERY_EXECUTE_DONE();
 		}
 		else
 		{

src/backend/utils/Gen_dummy_probes.sed

@@ -3,14 +3,19 @@
 #
 # Copyright (c) 2008, PostgreSQL Global Development Group
 #
-# $PostgreSQL: pgsql/src/backend/utils/Gen_dummy_probes.sed,v 1.1 2008/03/17 19:44:41 petere Exp $
+# $PostgreSQL: pgsql/src/backend/utils/Gen_dummy_probes.sed,v 1.2 2008/08/01 13:16:09 alvherre Exp $
 #-------------------------------------------------------------------------
 
-/^probe /!d
-s/^probe \([^(]*\)\(.*\);/\1\2/
+/^[ 	]*probe /!d
+s/^[ 	]*probe \([^(]*\)\(.*\);/\1\2/
 s/__/_/g
 y/abcdefghijklmnopqrstuvwxyz/ABCDEFGHIJKLMNOPQRSTUVWXYZ/
 s/^/#define TRACE_POSTGRESQL_/
-s/(INT, INT)/(INT1, INT2)/
+s/([^,)]\{1,\})/(INT1)/
+s/([^,)]\{1,\}, [^,)]\{1,\})/(INT1, INT2)/
+s/([^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\})/(INT1, INT2, INT3)/
+s/([^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\})/(INT1, INT2, INT3, INT4)/
+s/([^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\})/(INT1, INT2, INT3, INT4, INT5)/
+s/([^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\})/(INT1, INT2, INT3, INT4, INT5, INT6)/
 P
 s/(.*$/_ENABLED() (0)/

src/backend/utils/Makefile

 #
 # Makefile for utils
 #
-# $PostgreSQL: pgsql/src/backend/utils/Makefile,v 1.27 2008/03/17 19:44:41 petere Exp $
+# $PostgreSQL: pgsql/src/backend/utils/Makefile,v 1.28 2008/08/01 13:16:09 alvherre Exp $
 #
 
 subdir = src/backend/utils
@@ -20,9 +20,13 @@ $(SUBDIRS:%=%-recursive): fmgroids.h
 fmgroids.h fmgrtab.c: Gen_fmgrtab.sh $(top_srcdir)/src/include/catalog/pg_proc.h
 	AWK='$(AWK)' $(SHELL) $< $(top_srcdir)/src/include/catalog/pg_proc.h
 
+ifneq ($(enable_dtrace), yes)
+probes.h: Gen_dummy_probes.sed
+endif
+
 probes.h: probes.d
 ifeq ($(enable_dtrace), yes)
-	$(DTRACE) -h -s $< -o $@.tmp
+	$(DTRACE) -C -h -s $< -o $@.tmp
 	sed -e 's/POSTGRESQL_/TRACE_POSTGRESQL_/g' $@.tmp >$@
 	rm $@.tmp
 else

src/backend/utils/probes.d

@@ -3,22 +3,89 @@
  *
  *	Copyright (c) 2006-2008, PostgreSQL Global Development Group
  *
- *	$PostgreSQL: pgsql/src/backend/utils/probes.d,v 1.2 2008/01/02 02:42:06 momjian Exp $
+ *	$PostgreSQL: pgsql/src/backend/utils/probes.d,v 1.3 2008/08/01 13:16:09 alvherre Exp $
  * ----------
  */
 
+
+/* typedefs used in PostgreSQL */
+typedef unsigned int LocalTransactionId;
+typedef int LWLockId;
+typedef int LWLockMode;
+typedef int LOCKMODE;
+typedef unsigned int BlockNumber;
+typedef unsigned int Oid;
+
+#define bool char
+
 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(unsigned int, LOCKMODE);
+	 * probe lock__wait__done(unsigned int, LOCKMODE);
+	 */
+	probe lock__wait__start(unsigned int, int);
+	probe lock__wait__done(unsigned int, int);
+
+	probe query__parse__start(const char *);
+	probe query__parse__done(const char *);
+	probe query__rewrite__start(const char *);
+	probe query__rewrite__done(const char *);
+	probe query__plan__start();
+	probe query__plan__done();
+	probe query__execute__start();
+	probe query__execute__done();
+	probe query__start(const char *);
+	probe query__done(const char *);
+	probe statement__status(const char *);
+
+	probe sort__start(int, bool, int, int, bool);
+	probe sort__done(unsigned long, long);
+
+	/* 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, bool);
+	 * probe buffer__read__done(BlockNumber, Oid, Oid, Oid, bool, bool);
+	 */
+	probe buffer__read__start(unsigned int, unsigned int, unsigned int, unsigned int, bool);
+	probe buffer__read__done(unsigned int, unsigned int, unsigned int, unsigned int, bool, bool);
+
+	probe buffer__flush__start(Oid, Oid, Oid);
+	probe buffer__flush__done(Oid, Oid, Oid);
+
+	probe buffer__hit(bool);
+	probe buffer__miss(bool);
+	probe buffer__checkpoint__start(int);
+	probe buffer__checkpoint__done();
+	probe buffer__sync__start(int, int);
+	probe buffer__sync__written(int);
+	probe buffer__sync__done(int, int, int);
+
+	probe deadlock__found();
 
+	probe clog__checkpoint__start(bool);
+	probe clog__checkpoint__done(bool);
+	probe subtrans__checkpoint__start(bool);
+	probe subtrans__checkpoint__done(bool);
+	probe multixact__checkpoint__start(bool);
+	probe multixact__checkpoint__done(bool);
+	probe twophase__checkpoint__start();
+	probe twophase__checkpoint__done();
 };

src/backend/utils/sort/tuplesort.c

@@ -91,7 +91,7 @@
  * Portions Copyright (c) 1994, Regents of the University of California
  *
  * IDENTIFICATION
- *	  $PostgreSQL: pgsql/src/backend/utils/sort/tuplesort.c,v 1.85 2008/06/19 00:46:05 alvherre Exp $
+ *	  $PostgreSQL: pgsql/src/backend/utils/sort/tuplesort.c,v 1.86 2008/08/01 13:16:09 alvherre Exp $
  *
  *-------------------------------------------------------------------------
  */
@@ -107,6 +107,7 @@
 #include "catalog/pg_operator.h"
 #include "commands/tablespace.h"
 #include "miscadmin.h"
+#include "pg_trace.h"
 #include "utils/datum.h"
 #include "utils/logtape.h"
 #include "utils/lsyscache.h"
@@ -121,6 +122,11 @@
 #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
@@ -570,6 +576,8 @@ tuplesort_begin_heap(TupleDesc tupDesc,
 			 nkeys, workMem, randomAccess ? 't' : 'f');
 #endif
 
+	TRACE_POSTGRESQL_SORT_START(HEAP_SORT, false, nkeys, workMem, randomAccess);
+
 	state->nKeys = nkeys;
 
 	state->comparetup = comparetup_heap;
@@ -636,6 +644,8 @@ tuplesort_begin_index_btree(Relation indexRel,
 
 	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;
@@ -714,6 +724,8 @@ tuplesort_begin_datum(Oid datumType,
 			 workMem, randomAccess ? 't' : 'f');
 #endif
 
+	TRACE_POSTGRESQL_SORT_START(DATUM_SORT, false, 1, workMem, randomAccess);
+
 	state->nKeys = 1;			/* always a one-column sort */
 
 	state->comparetup = comparetup_datum;
@@ -825,6 +837,11 @@ tuplesort_end(Tuplesortstate *state)
 	}
 #endif
 
+	TRACE_POSTGRESQL_SORT_DONE(state->tapeset,
+			(state->tapeset ? LogicalTapeSetBlocks(state->tapeset) :
+			(state->allowedMem - state->availMem + 1023) / 1024));
+
+
 	MemoryContextSwitchTo(oldcontext);
 
 	/*