diff --git a/src/backend/Makefile b/src/backend/Makefile index 597ec8d8eb..0025a0c2a1 100644 --- a/src/backend/Makefile +++ b/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 diff --git a/src/backend/access/transam/clog.c b/src/backend/access/transam/clog.c index 52224b1d0f..f30ef3a226 100644 --- a/src/backend/access/transam/clog.c +++ b/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); } diff --git a/src/backend/access/transam/multixact.c b/src/backend/access/transam/multixact.c index 8ccd1cf5f9..40182eaeca 100644 --- a/src/backend/access/transam/multixact.c +++ b/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); } /* diff --git a/src/backend/access/transam/subtrans.c b/src/backend/access/transam/subtrans.c index 7d47f5154a..67a9518cce 100644 --- a/src/backend/access/transam/subtrans.c +++ b/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); } diff --git a/src/backend/access/transam/twophase.c b/src/backend/access/transam/twophase.c index 2712066f12..57eb7eeea4 100644 --- a/src/backend/access/transam/twophase.c +++ b/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(); } /* diff --git a/src/backend/postmaster/pgstat.c b/src/backend/postmaster/pgstat.c index e3cb0be5bb..d0e190aa44 100644 --- a/src/backend/postmaster/pgstat.c +++ b/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; diff --git a/src/backend/storage/buffer/bufmgr.c b/src/backend/storage/buffer/bufmgr.c index bd8529d617..e40a815b5d 100644 --- a/src/backend/storage/buffer/bufmgr.c +++ b/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 #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. diff --git a/src/backend/storage/lmgr/deadlock.c b/src/backend/storage/lmgr/deadlock.c index 97be7d9dc7..8a564a1754 100644 --- a/src/backend/storage/lmgr/deadlock.c +++ b/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"); diff --git a/src/backend/storage/lmgr/lock.c b/src/backend/storage/lmgr/lock.c index fbd1be586b..991d94fe35 100644 --- a/src/backend/storage/lmgr/lock.c +++ b/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 diff --git a/src/backend/storage/lmgr/lwlock.c b/src/backend/storage/lmgr/lwlock.c index 5fcad46f2f..488b7bdc5a 100644 --- a/src/backend/storage/lmgr/lwlock.c +++ b/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"); diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c index 242388f2cb..132d33c5a9 100644 --- a/src/backend/tcop/postgres.c +++ b/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; } diff --git a/src/backend/tcop/pquery.c b/src/backend/tcop/pquery.c index a4afab0402..c13f0cda7e 100644 --- a/src/backend/tcop/pquery.c +++ b/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 { diff --git a/src/backend/utils/Gen_dummy_probes.sed b/src/backend/utils/Gen_dummy_probes.sed index db29e4188f..42b2eeb540 100644 --- a/src/backend/utils/Gen_dummy_probes.sed +++ b/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)/ diff --git a/src/backend/utils/Makefile b/src/backend/utils/Makefile index f753016173..b48b267bc0 100644 --- a/src/backend/utils/Makefile +++ b/src/backend/utils/Makefile @@ -1,7 +1,7 @@ # # 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 diff --git a/src/backend/utils/probes.d b/src/backend/utils/probes.d index 40dd3c9e51..b87a234bb3 100644 --- a/src/backend/utils/probes.d +++ b/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(); }; diff --git a/src/backend/utils/sort/tuplesort.c b/src/backend/utils/sort/tuplesort.c index 896ee71ee6..775840da18 100644 --- a/src/backend/utils/sort/tuplesort.c +++ b/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); /*