Index: src/backend/access/transam/clog.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/access/transam/clog.c,v
retrieving revision 1.46
diff -c -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	24 Jul 2008 14:19:23 -0000
***************
*** 36,41 ****
--- 36,42 ----
  #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
***************
*** 323,329 ****
--- 324,332 ----
  CheckPointCLOG(void)
  {
  	/* Flush dirty CLOG pages to disk */
+ 	TRACE_POSTGRESQL_CLOG_CHECKPOINT_START();
  	SimpleLruFlush(ClogCtl, true);
+ 	TRACE_POSTGRESQL_CLOG_CHECKPOINT_DONE();
  }
  
  
Index: src/backend/access/transam/multixact.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/access/transam/multixact.c,v
retrieving revision 1.27
diff -c -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	24 Jul 2008 14:19:24 -0000
***************
*** 57,62 ****
--- 57,63 ----
  #include "storage/lmgr.h"
  #include "utils/memutils.h"
  #include "storage/procarray.h"
+ #include "pg_trace.h"
  
  
  /*
***************
*** 1526,1531 ****
--- 1527,1534 ----
  void
  CheckPointMultiXact(void)
  {
+ 	TRACE_POSTGRESQL_MULTIXACT_CHECKPOINT_START();
+ 
  	/* Flush dirty MultiXact pages to disk */
  	SimpleLruFlush(MultiXactOffsetCtl, true);
  	SimpleLruFlush(MultiXactMemberCtl, true);
***************
*** 1540,1545 ****
--- 1543,1550 ----
  	 */
  	if (!InRecovery)
  		TruncateMultiXact();
+ 
+ 	TRACE_POSTGRESQL_MULTIXACT_CHECKPOINT_DONE();
  }
  
  /*
Index: src/backend/access/transam/subtrans.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/access/transam/subtrans.c,v
retrieving revision 1.22
diff -c -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	24 Jul 2008 14:19:24 -0000
***************
*** 32,37 ****
--- 32,38 ----
  #include "access/subtrans.h"
  #include "access/transam.h"
  #include "utils/snapmgr.h"
+ #include "pg_trace.h"
  
  
  /*
***************
*** 281,287 ****
--- 282,290 ----
  	 * 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();
  	SimpleLruFlush(SubTransCtl, true);
+ 	TRACE_POSTGRESQL_SUBTRANS_CHECKPOINT_DONE();
  }
  
  
Index: src/backend/access/transam/twophase.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/access/transam/twophase.c,v
retrieving revision 1.43
diff -c -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	24 Jul 2008 14:19:24 -0000
***************
*** 57,62 ****
--- 57,63 ----
  #include "storage/smgr.h"
  #include "utils/builtins.h"
  #include "utils/memutils.h"
+ #include "pg_trace.h"
  
  
  /*
***************
*** 1387,1392 ****
--- 1388,1396 ----
  	 */
  	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,1449 ****
--- 1448,1455 ----
  	}
  
  	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 -c -r1.176 pgstat.c
*** src/backend/postmaster/pgstat.c	30 Jun 2008 10:58:47 -0000	1.176
--- src/backend/postmaster/pgstat.c	24 Jul 2008 14:19:30 -0000
***************
*** 61,66 ****
--- 61,67 ----
  #include "utils/ps_status.h"
  #include "utils/rel.h"
  #include "utils/tqual.h"
+ #include "pg_trace.h"
  
  
  /* ----------
***************
*** 2202,2207 ****
--- 2203,2210 ----
  	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 -c -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	24 Jul 2008 14:19:31 -0000
***************
*** 43,48 ****
--- 43,49 ----
  #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,218 ****
--- 214,222 ----
  	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++;
***************
*** 240,251 ****
--- 244,262 ----
  	{
  		if (!isExtend)
  		{
+ 			TRACE_POSTGRESQL_BUFFER_HIT();
+ 
  			/* Just need to update stats before we exit */
  			*hit = true;
  
  			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);
  		}
  
***************
*** 297,302 ****
--- 308,314 ----
  			} while (!StartBufferIO(bufHdr, true));
  		}
  	}
+ 	TRACE_POSTGRESQL_BUFFER_MISS();
  
  	/*
  	 * if we have gotten to this point, we have allocated a buffer for the
***************
*** 368,373 ****
--- 380,389 ----
  	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,1091 ****
--- 1102,1109 ----
  	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,1122 ****
--- 1135,1141 ----
  		{
  			if (SyncOneBuffer(buf_id, false) & BUF_WRITTEN)
  			{
+ 				TRACE_POSTGRESQL_BUFFER_SYNC_WRITTEN(buf_id);
  				BgWriterStats.m_buf_written_checkpoints++;
  				num_written++;
  
***************
*** 1147,1152 ****
--- 1166,1173 ----
  			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,1663 ****
--- 1674,1686 ----
  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,1764 ****
--- 1782,1791 ----
  	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, buf->tag.blockNum);
+ 
  	/*
  	 * 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,1790 ****
--- 1812,1821 ----
  
  	BufferFlushCount++;
  
+ 	TRACE_POSTGRESQL_BUFFER_FLUSH_DONE(reln->smgr_rnode.spcNode,
+ 		 reln->smgr_rnode.dbNode, reln->smgr_rnode.relNode,
+ 		 buf->tag.blockNum);
+ 
  	/*
  	 * 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 -c -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	24 Jul 2008 14:19:31 -0000
***************
*** 30,35 ****
--- 30,36 ----
  #include "storage/lmgr.h"
  #include "storage/proc.h"
  #include "utils/memutils.h"
+ #include "pg_trace.h"
  
  
  /* One edge in the waits-for graph */
***************
*** 222,227 ****
--- 223,230 ----
  		 */
  		int			nSoftEdges;
  
+ 		TRACE_POSTGRESQL_DEADLOCK_FOUND();
+ 
  		nWaitOrders = 0;
  		if (!FindLockCycle(proc, possibleConstraints, &nSoftEdges))
  			elog(FATAL, "deadlock seems to have disappeared");
***************
*** 259,264 ****
--- 262,269 ----
  		ProcLockWakeup(GetLocksMethodTable(lock), lock);
  	}
  
+ 	TRACE_POSTGRESQL_DEADLOCK_NOTFOUND(nWaitOrders);
+ 
  	/* Return code tells caller if we had to escape a deadlock or not */
  	if (nWaitOrders > 0)
  		return DS_SOFT_DEADLOCK;
Index: src/backend/tcop/postgres.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/tcop/postgres.c,v
retrieving revision 1.554
diff -c -r1.554 postgres.c
*** src/backend/tcop/postgres.c	18 Jul 2008 20:26:06 -0000	1.554
--- src/backend/tcop/postgres.c	24 Jul 2008 14:19:31 -0000
***************
*** 71,76 ****
--- 71,77 ----
  #include "mb/pg_wchar.h"
  
  #include "pgstat.h"
+ #include "pg_trace.h"
  
  extern int	optind;
  extern char *optarg;
***************
*** 551,556 ****
--- 552,559 ----
  {
  	List	   *raw_parsetree_list;
  
+ 	TRACE_POSTGRESQL_QUERY_PARSE_START(query_string);
+ 
  	if (log_parser_stats)
  		ResetUsage();
  
***************
*** 660,665 ****
--- 663,670 ----
  		elog_node_display(DEBUG1, "rewritten parse tree", querytree_list,
  						  Debug_pretty_print);
  
+ 	TRACE_POSTGRESQL_QUERY_PARSE_DONE();
+ 
  	return querytree_list;
  }
  
***************
*** 673,678 ****
--- 678,685 ----
  {
  	PlannedStmt *plan;
  
+ 	TRACE_POSTGRESQL_QUERY_PLAN_START();
+ 
  	/* Utility commands have no plans. */
  	if (querytree->commandType == CMD_UTILITY)
  		return NULL;
***************
*** 710,715 ****
--- 717,723 ----
  	 */
  	if (Debug_print_plan)
  		elog_node_display(DEBUG1, "plan", plan, Debug_pretty_print);
+ 	TRACE_POSTGRESQL_QUERY_PLAN_DONE();
  
  	return plan;
  }
***************
*** 785,790 ****
--- 793,799 ----
  	bool		isTopLevel;
  	char		msec_str[32];
  
+ 
  	/*
  	 * Report query to various monitoring facilities.
  	 */
***************
*** 792,797 ****
--- 801,808 ----
  
  	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,1063 ****
--- 1069,1076 ----
  	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 -c -r1.123 pquery.c
*** src/backend/tcop/pquery.c	12 May 2008 20:02:02 -0000	1.123
--- src/backend/tcop/pquery.c	24 Jul 2008 14:19:31 -0000
***************
*** 24,29 ****
--- 24,30 ----
  #include "tcop/utility.h"
  #include "utils/memutils.h"
  #include "utils/snapmgr.h"
+ #include "pg_trace.h"
  
  
  /*
***************
*** 711,716 ****
--- 712,719 ----
  
  	AssertArg(PortalIsValid(portal));
  
+ 	TRACE_POSTGRESQL_QUERY_EXECUTE_START();
+ 
  	/* Initialize completion tag to empty string */
  	if (completionTag)
  		completionTag[0] = '\0';
***************
*** 857,862 ****
--- 860,867 ----
  
  	if (log_executor_stats && portal->strategy != PORTAL_MULTI_QUERY)
  		ShowUsage("EXECUTOR STATISTICS");
+ 	
+ 	TRACE_POSTGRESQL_QUERY_EXECUTE_DONE();
  
  	return result;
  }
***************
*** 1237,1242 ****
--- 1242,1249 ----
  			 */
  			PlannedStmt *pstmt = (PlannedStmt *) stmt;
  
+ 			TRACE_POSTGRESQL_QUERY_EXECUTE_START();
+ 
  			if (log_executor_stats)
  				ResetUsage();
  
***************
*** 1257,1262 ****
--- 1264,1271 ----
  
  			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 -c -r1.2 probes.d
*** src/backend/utils/probes.d	2 Jan 2008 02:42:06 -0000	1.2
--- src/backend/utils/probes.d	24 Jul 2008 14:19:31 -0000
***************
*** 7,24 ****
   * ----------
   */
  
  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);
  
  };
--- 7,76 ----
   * ----------
   */
  
  provider postgresql {
  
! 	/* 
! 	 * Due to a bug in Mac OS X 10.5, using defined types (e.g. uintptr_t,
! 	 * uint32_t, etc.) cause compilation error.  
! 	 */
! 	  
! 	probe transaction__start(unsigned int transactionId);
! 	probe transaction__commit(unsigned int transactionId);
! 	probe transaction__abort(unsigned int transactionId);
! 
! 	probe lwlock__acquire(unsigned int lockId, unsigned int mode);
! 	probe lwlock__release(unsigned int lockId);
! 	probe lwlock__startwait(unsigned int lockId, unsigned int mode);
! 	probe lwlock__endwait(unsigned int lockId, unsigned int mode);
! 	probe lwlock__condacquire(unsigned int lockId, unsigned int mode);
! 	probe lwlock__condacquire__fail(unsigned int lockId, unsigned int mode);
! 	probe lock__startwait(unsigned int lockTagField2, int lockMode);
! 	probe lock__endwait(unsigned int lockTagField2, int lockMode);
! 
! 	probe query__parse__start(char *queryString);
! 	probe query__parse__done();
! 	probe query__plan__start();
! 	probe query__plan__done();
! 	probe query__execute__start();
! 	probe query__execute__done();
! 	probe query__start(char *queryString);
! 	probe query__done(char *queryString);
! 	probe statement__status(char *cmdString);
! 
! 	probe sort__start(int, int, int, int, int);
! 	probe sort__end(int, long);
! 
! 	probe buffer__read__start(int blockNum, int tablespaceOid,
! 			int databaseOid, int relationOid, int isLocalBuf);
! 	probe buffer__read__done(int blockNum, int tablespaceOid,
! 		 	int databaseOid, int relationOid, int isLocalBuf,
! 			int isInBuffPool);
! 	probe buffer__write__dirty__start(int blockNum, int tablespaceOid,
! 			int databaseOid, int relationOid);
! 	probe buffer__write__dirty__done(int blockNum, int tablespaceOid,
! 			int databaseOid, int relationOid, int isHintBitsWrite);
! 
! 	probe buffer__flush__start(int tablespaceOid,
! 			int databaseOid, int relationOid, int blockNum);
! 	probe buffer__flush__done(int tablespaceOid, int databaseOid,
! 			int relationOid, int blockNum);
! 	probe buffer__hit();
! 	probe buffer__miss();
! 	probe buffer__checkpoint__start(int);
! 	probe buffer__checkpoint__done();
! 	probe buffer__sync__start(int numBuffers, int numToWrite);
! 	probe buffer__sync__written(int bufId);
! 	probe buffer__sync__done(int numBuffers, int numWritten, int numToWrite);
! 
! 	probe deadlock__found();
! 	probe deadlock__notfound(int);
  
+ 	probe clog__checkpoint__start();
+ 	probe clog__checkpoint__done();
+ 	probe subtrans__checkpoint__start();
+ 	probe subtrans__checkpoint__done();
+ 	probe multixact__checkpoint__start();
+ 	probe multixact__checkpoint__done();
+ 	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 -c -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	24 Jul 2008 14:19:32 -0000
***************
*** 115,126 ****
--- 115,132 ----
  #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,574 ****
--- 575,581 ----
  			 "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,641 ****
--- 643,650 ----
  
  	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,718 ****
--- 722,728 ----
  			 "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,830 ****
--- 835,845 ----
  	}
  #endif
  
+ 	TRACE_POSTGRESQL_SORT_END(state->tapeset,
+ 			(state->tapeset ? LogicalTapeSetBlocks(state->tapeset) :
+ 			(state->allowedMem - state->availMem + 1023) / 1024));
+ 
+ 
  	MemoryContextSwitchTo(oldcontext);
  
  	/*