On Monday 19 May 2008 11:32:28 Theo Schlossnagle wrote:
> Howdy,
>
> I just saw Robert Lor's patch w.r.t. dtrace probes. It looks very
> similar in what we've done. We run a nice set of probes in production
> here that allow us to track the details of checkpointing and statement
> execution. I've given a few presentations around these probes and
> have had very positive feedback. They've been available for a while
> now, but I never got around to sending them to the list:
>
> https://labs.omniti.com/trac/project-dtrace/browser/trunk/postgresql/8.3.1.
>patch?format=txt
>
> Documentation is in wiki format, but I'd be happy to convert it to
> something else:
>
> https://labs.omniti.com/trac/project-dtrace/wiki/Applications#PostgreSQL
>
Attached is the patch combining Theo's patch from above into the original
patch from Robert Lor. It is supposed to build on OSX and Solaris. I'll be
updating the July commitfest entry to point to this patch, case anyone wants
to review it.
--
Robert Treat
Build A Brighter LAMP :: Linux Apache {middleware} 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 26 Jun 2008 23:18:30 -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
@@ -323,7 +324,9 @@ void
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 -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 26 Jun 2008 23:18:31 -0000
@@ -57,6 +57,7 @@
#include "storage/lmgr.h"
#include "utils/memutils.h"
#include "storage/procarray.h"
+#include "pg_trace.h"
/*
@@ -1526,6 +1527,8 @@ MultiXactGetCheckptMulti(bool is_shutdow
void
CheckPointMultiXact(void)
{
+ TRACE_POSTGRESQL_MULTIXACT_CHECKPOINT_START();
+
/* Flush dirty MultiXact pages to disk */
SimpleLruFlush(MultiXactOffsetCtl, true);
SimpleLruFlush(MultiXactMemberCtl, true);
@@ -1540,6 +1543,8 @@ CheckPointMultiXact(void)
*/
if (!InRecovery)
TruncateMultiXact();
+
+ TRACE_POSTGRESQL_MULTIXACT_CHECKPOINT_DONE();
}
/*
Index: src/backend/access/transam/slru.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/access/transam/slru.c,v
retrieving revision 1.44
diff -u -3 -p -r1.44 slru.c
--- src/backend/access/transam/slru.c 1 Jan 2008 19:45:48 -0000 1.44
+++ src/backend/access/transam/slru.c 26 Jun 2008 23:18:32 -0000
@@ -57,6 +57,7 @@
#include "storage/fd.h"
#include "storage/shmem.h"
#include "miscadmin.h"
+#include "pg_trace.h"
/*
@@ -372,6 +373,8 @@ SimpleLruReadPage(SlruCtl ctl, int pagen
{
SlruShared shared = ctl->shared;
+ TRACE_POSTGRESQL_SLRU_READPAGE_START((uintptr_t)ctl, pageno, write_ok, xid);
+
/* Outer loop handles restart if we must wait for someone else's I/O */
for (;;)
{
@@ -399,6 +402,7 @@ SimpleLruReadPage(SlruCtl ctl, int pagen
}
/* Otherwise, it's ready to use */
SlruRecentlyUsed(shared, slotno);
+ TRACE_POSTGRESQL_SLRU_READPAGE_DONE(slotno);
return slotno;
}
@@ -446,6 +450,7 @@ SimpleLruReadPage(SlruCtl ctl, int pagen
SlruReportIOError(ctl, pageno, xid);
SlruRecentlyUsed(shared, slotno);
+ TRACE_POSTGRESQL_SLRU_READPAGE_DONE(slotno);
return slotno;
}
}
@@ -470,6 +475,8 @@ SimpleLruReadPage_ReadOnly(SlruCtl ctl,
SlruShared shared = ctl->shared;
int slotno;
+ TRACE_POSTGRESQL_SLRU_READPAGE_READONLY((uintptr_t)ctl, pageno, xid);
+
/* Try to find the page while holding only shared lock */
LWLockAcquire(shared->ControlLock, LW_SHARED);
@@ -511,6 +518,8 @@ SimpleLruWritePage(SlruCtl ctl, int slot
int pageno = shared->page_number[slotno];
bool ok;
+ TRACE_POSTGRESQL_SLRU_WRITEPAGE_START((uintptr_t)ctl, pageno, slotno);
+
/* If a write is in progress, wait for it to finish */
while (shared->page_status[slotno] == SLRU_PAGE_WRITE_IN_PROGRESS &&
shared->page_number[slotno] == pageno)
@@ -525,7 +534,10 @@ SimpleLruWritePage(SlruCtl ctl, int slot
if (!shared->page_dirty[slotno] ||
shared->page_status[slotno] != SLRU_PAGE_VALID ||
shared->page_number[slotno] != pageno)
+ {
+ TRACE_POSTGRESQL_SLRU_WRITEPAGE_DONE();
return;
+ }
/*
* Mark the slot write-busy, and clear the dirtybit. After this point, a
@@ -569,6 +581,8 @@ SimpleLruWritePage(SlruCtl ctl, int slot
/* Now it's okay to ereport if we failed */
if (!ok)
SlruReportIOError(ctl, pageno, InvalidTransactionId);
+
+ TRACE_POSTGRESQL_SLRU_WRITEPAGE_DONE();
}
/*
@@ -593,6 +607,7 @@ SlruPhysicalReadPage(SlruCtl ctl, int pa
SlruFileName(ctl, path, segno);
+ TRACE_POSTGRESQL_SLRU_READPAGE_PHYSICAL_START((uintptr_t)ctl, path, pageno, slotno);
/*
* In a crash-and-restart situation, it's possible for us to receive
* commands to set the commit status of transactions whose bits are in
@@ -607,6 +622,7 @@ SlruPhysicalReadPage(SlruCtl ctl, int pa
{
slru_errcause = SLRU_OPEN_FAILED;
slru_errno = errno;
+ TRACE_POSTGRESQL_SLRU_READPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno);
return false;
}
@@ -614,6 +630,7 @@ SlruPhysicalReadPage(SlruCtl ctl, int pa
(errmsg("file \"%s\" doesn't exist, reading as zeroes",
path)));
MemSet(shared->page_buffer[slotno], 0, BLCKSZ);
+ TRACE_POSTGRESQL_SLRU_READPAGE_PHYSICAL_DONE(true, slru_errcause, slru_errno);
return true;
}
@@ -622,6 +639,7 @@ SlruPhysicalReadPage(SlruCtl ctl, int pa
slru_errcause = SLRU_SEEK_FAILED;
slru_errno = errno;
close(fd);
+ TRACE_POSTGRESQL_SLRU_READPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno);
return false;
}
@@ -631,6 +649,7 @@ SlruPhysicalReadPage(SlruCtl ctl, int pa
slru_errcause = SLRU_READ_FAILED;
slru_errno = errno;
close(fd);
+ TRACE_POSTGRESQL_SLRU_READPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno);
return false;
}
@@ -638,9 +657,11 @@ SlruPhysicalReadPage(SlruCtl ctl, int pa
{
slru_errcause = SLRU_CLOSE_FAILED;
slru_errno = errno;
+ TRACE_POSTGRESQL_SLRU_READPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno);
return false;
}
+ TRACE_POSTGRESQL_SLRU_READPAGE_PHYSICAL_DONE(true, slru_errcause, slru_errno);
return true;
}
@@ -668,6 +689,8 @@ SlruPhysicalWritePage(SlruCtl ctl, int p
char path[MAXPGPATH];
int fd = -1;
+ TRACE_POSTGRESQL_SLRU_WRITEPAGE_PHYSICAL_START((uintptr_t)ctl, pageno, slotno);
+
/*
* Honor the write-WAL-before-data rule, if appropriate, so that we do not
* write out data before associated WAL records. This is the same action
@@ -753,6 +776,7 @@ SlruPhysicalWritePage(SlruCtl ctl, int p
{
slru_errcause = SLRU_OPEN_FAILED;
slru_errno = errno;
+ TRACE_POSTGRESQL_SLRU_WRITEPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno);
return false;
}
@@ -781,6 +805,7 @@ SlruPhysicalWritePage(SlruCtl ctl, int p
slru_errno = errno;
if (!fdata)
close(fd);
+ TRACE_POSTGRESQL_SLRU_WRITEPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno);
return false;
}
@@ -794,6 +819,7 @@ SlruPhysicalWritePage(SlruCtl ctl, int p
slru_errno = errno;
if (!fdata)
close(fd);
+ TRACE_POSTGRESQL_SLRU_WRITEPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno);
return false;
}
@@ -808,6 +834,7 @@ SlruPhysicalWritePage(SlruCtl ctl, int p
slru_errcause = SLRU_FSYNC_FAILED;
slru_errno = errno;
close(fd);
+ TRACE_POSTGRESQL_SLRU_WRITEPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno);
return false;
}
@@ -815,10 +842,12 @@ SlruPhysicalWritePage(SlruCtl ctl, int p
{
slru_errcause = SLRU_CLOSE_FAILED;
slru_errno = errno;
+ TRACE_POSTGRESQL_SLRU_WRITEPAGE_PHYSICAL_DONE(false, slru_errcause, slru_errno);
return false;
}
}
+ TRACE_POSTGRESQL_SLRU_WRITEPAGE_PHYSICAL_DONE(true, slru_errcause, slru_errno);
return 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 26 Jun 2008 23:18:32 -0000
@@ -32,6 +32,7 @@
#include "access/subtrans.h"
#include "access/transam.h"
#include "utils/snapmgr.h"
+#include "pg_trace.h"
/*
@@ -281,7 +282,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();
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 -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 26 Jun 2008 23:18:33 -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/access/transam/xlog.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/access/transam/xlog.c,v
retrieving revision 1.314
diff -u -3 -p -r1.314 xlog.c
--- src/backend/access/transam/xlog.c 12 Jun 2008 09:12:30 -0000 1.314
+++ src/backend/access/transam/xlog.c 26 Jun 2008 23:18:39 -0000
@@ -48,6 +48,7 @@
#include "utils/builtins.h"
#include "utils/pg_locale.h"
#include "utils/ps_status.h"
+#include "pg_trace.h"
/* File path names (all relative to $PGDATA) */
@@ -484,6 +485,8 @@ XLogInsert(RmgrId rmid, uint8 info, XLog
if (info & XLR_INFO_MASK)
elog(PANIC, "invalid xlog info mask %02X", info);
+ TRACE_POSTGRESQL_XLOG_INSERT(rmid, info);
+
/*
* In bootstrap mode, we don't actually log anything but XLOG resources;
* return a phony record pointer.
@@ -912,6 +915,8 @@ begin:;
XLogwrtRqst FlushRqst;
XLogRecPtr OldSegEnd;
+ TRACE_POSTGRESQL_XLOG_SWITCH();
+
LWLockAcquire(WALWriteLock, LW_EXCLUSIVE);
/*
@@ -1270,12 +1275,14 @@ AdvanceXLInsertBuffer(bool new_segment)
* Have to write buffers while holding insert lock. This is
* not good, so only write as much as we absolutely must.
*/
+ TRACE_POSTGRESQL_WAL_BUFFER_WRITE_START();
WriteRqst.Write = OldPageRqstPtr;
WriteRqst.Flush.xlogid = 0;
WriteRqst.Flush.xrecoff = 0;
XLogWrite(WriteRqst, false, false);
LWLockRelease(WALWriteLock);
Insert->LogwrtResult = LogwrtResult;
+ TRACE_POSTGRESQL_WAL_BUFFER_WRITE_DONE();
}
}
}
@@ -5791,6 +5798,7 @@ CreateCheckPoint(int flags)
LWLockRelease(WALInsertLock);
LWLockRelease(CheckpointLock);
END_CRIT_SECTION();
+ TRACE_POSTGRESQL_XLOG_CHECKPOINT_DONE(UINT_MAX,0,0,0,UINT_MAX);
return;
}
}
@@ -5886,6 +5894,8 @@ CreateCheckPoint(int flags)
checkPoint.nextXid = ShmemVariableCache->nextXid;
LWLockRelease(XidGenLock);
+ TRACE_POSTGRESQL_XLOG_CHECKPOINT_START(flags, checkPoint.nextXid);
+
/* Increase XID epoch if we've wrapped around since last checkpoint */
checkPoint.nextXidEpoch = ControlFile->checkPointCopy.nextXidEpoch;
if (checkPoint.nextXid < ControlFile->checkPointCopy.nextXid)
@@ -6010,6 +6020,11 @@ CreateCheckPoint(int flags)
if (log_checkpoints)
LogCheckpointEnd();
+ TRACE_POSTGRESQL_XLOG_CHECKPOINT_DONE(CheckpointStats.ckpt_bufs_written,
+ NBuffers, CheckpointStats.ckpt_segs_added,
+ CheckpointStats.ckpt_segs_removed,
+ CheckpointStats.ckpt_segs_recycled);
+
LWLockRelease(CheckpointLock);
}
Index: src/backend/executor/execScan.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/execScan.c,v
retrieving revision 1.43
diff -u -3 -p -r1.43 execScan.c
--- src/backend/executor/execScan.c 1 Jan 2008 19:45:49 -0000 1.43
+++ src/backend/executor/execScan.c 26 Jun 2008 23:18:39 -0000
@@ -21,6 +21,7 @@
#include "executor/executor.h"
#include "miscadmin.h"
#include "utils/memutils.h"
+#include "pg_trace.h"
static bool tlist_matches_tupdesc(PlanState *ps, List *tlist, Index varno, TupleDesc tupdesc);
@@ -60,6 +61,7 @@ ExecScan(ScanState *node,
qual = node->ps.qual;
projInfo = node->ps.ps_ProjInfo;
+ TRACE_POSTGRESQL_EXECUTOR_SCAN((uintptr_t)node, ((Scan *)node->ps.plan)->scanrelid, (uintptr_t)accessMtd);
/*
* If we have neither a qual to check nor a projection to do, just skip
* all the overhead and return the raw scan tuple.
Index: src/backend/executor/nodeAgg.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeAgg.c,v
retrieving revision 1.158
diff -u -3 -p -r1.158 nodeAgg.c
--- src/backend/executor/nodeAgg.c 12 May 2008 00:00:49 -0000 1.158
+++ src/backend/executor/nodeAgg.c 26 Jun 2008 23:18:40 -0000
@@ -86,6 +86,7 @@
#include "utils/syscache.h"
#include "utils/tuplesort.h"
#include "utils/datum.h"
+#include "pg_trace.h"
/*
@@ -805,6 +806,8 @@ ExecAgg(AggState *node)
if (node->agg_done)
return NULL;
+ TRACE_POSTGRESQL_EXECUTOR_AGG((uintptr_t)node, ((Agg *) node->ss.ps.plan)->aggstrategy);
+
if (((Agg *) node->ss.ps.plan)->aggstrategy == AGG_HASHED)
{
if (!node->table_filled)
Index: src/backend/executor/nodeGroup.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeGroup.c,v
retrieving revision 1.70
diff -u -3 -p -r1.70 nodeGroup.c
--- src/backend/executor/nodeGroup.c 1 Jan 2008 19:45:49 -0000 1.70
+++ src/backend/executor/nodeGroup.c 26 Jun 2008 23:18:40 -0000
@@ -24,6 +24,7 @@
#include "executor/executor.h"
#include "executor/nodeGroup.h"
+#include "pg_trace.h"
/*
@@ -49,6 +50,8 @@ ExecGroup(GroupState *node)
numCols = ((Group *) node->ss.ps.plan)->numCols;
grpColIdx = ((Group *) node->ss.ps.plan)->grpColIdx;
+ TRACE_POSTGRESQL_EXECUTOR_GROUP((uintptr_t)node, numCols);
+
/*
* The ScanTupleSlot holds the (copied) first tuple of each group.
*/
Index: src/backend/executor/nodeHash.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeHash.c,v
retrieving revision 1.116
diff -u -3 -p -r1.116 nodeHash.c
--- src/backend/executor/nodeHash.c 1 Jan 2008 19:45:49 -0000 1.116
+++ src/backend/executor/nodeHash.c 26 Jun 2008 23:18:41 -0000
@@ -35,6 +35,7 @@
#include "utils/dynahash.h"
#include "utils/memutils.h"
#include "utils/lsyscache.h"
+#include "pg_trace.h"
static void ExecHashIncreaseNumBatches(HashJoinTable hashtable);
@@ -70,6 +71,8 @@ MultiExecHash(HashState *node)
ExprContext *econtext;
uint32 hashvalue;
+ TRACE_POSTGRESQL_EXECUTOR_HASH_MULTI((uintptr_t)node);
+
/* must provide our own instrumentation support */
if (node->ps.instrument)
InstrStartNode(node->ps.instrument);
Index: src/backend/executor/nodeHashjoin.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeHashjoin.c,v
retrieving revision 1.93
diff -u -3 -p -r1.93 nodeHashjoin.c
--- src/backend/executor/nodeHashjoin.c 1 Jan 2008 19:45:49 -0000 1.93
+++ src/backend/executor/nodeHashjoin.c 26 Jun 2008 23:18:41 -0000
@@ -20,6 +20,7 @@
#include "executor/nodeHash.h"
#include "executor/nodeHashjoin.h"
#include "utils/memutils.h"
+#include "pg_trace.h"
static TupleTableSlot *ExecHashJoinOuterGetTuple(PlanState *outerNode,
@@ -58,6 +59,8 @@ ExecHashJoin(HashJoinState *node)
uint32 hashvalue;
int batchno;
+ TRACE_POSTGRESQL_EXECUTOR_HASHJOIN((uintptr_t)node);
+
/*
* get information from HashJoin node
*/
Index: src/backend/executor/nodeLimit.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeLimit.c,v
retrieving revision 1.34
diff -u -3 -p -r1.34 nodeLimit.c
--- src/backend/executor/nodeLimit.c 10 Mar 2008 03:37:59 -0000 1.34
+++ src/backend/executor/nodeLimit.c 26 Jun 2008 23:18:42 -0000
@@ -23,6 +23,7 @@
#include "executor/executor.h"
#include "executor/nodeLimit.h"
+#include "pg_trace.h"
static void recompute_limits(LimitState *node);
@@ -41,6 +42,8 @@ ExecLimit(LimitState *node)
TupleTableSlot *slot;
PlanState *outerPlan;
+ TRACE_POSTGRESQL_EXECUTOR_LIMIT((uintptr_t)node);
+
/*
* get information from the node
*/
Index: src/backend/executor/nodeMaterial.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeMaterial.c,v
retrieving revision 1.62
diff -u -3 -p -r1.62 nodeMaterial.c
--- src/backend/executor/nodeMaterial.c 23 Mar 2008 00:54:04 -0000 1.62
+++ src/backend/executor/nodeMaterial.c 26 Jun 2008 23:18:42 -0000
@@ -24,6 +24,7 @@
#include "executor/executor.h"
#include "executor/nodeMaterial.h"
#include "miscadmin.h"
+#include "pg_trace.h"
/* ----------------------------------------------------------------
* ExecMaterial
@@ -45,6 +46,8 @@ ExecMaterial(MaterialState *node)
bool eof_tuplestore;
TupleTableSlot *slot;
+ TRACE_POSTGRESQL_EXECUTOR_MATERIAL((uintptr_t)node);
+
/*
* get state info from node
*/
Index: src/backend/executor/nodeMergejoin.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeMergejoin.c,v
retrieving revision 1.91
diff -u -3 -p -r1.91 nodeMergejoin.c
--- src/backend/executor/nodeMergejoin.c 13 Apr 2008 20:51:20 -0000 1.91
+++ src/backend/executor/nodeMergejoin.c 26 Jun 2008 23:18:43 -0000
@@ -102,6 +102,7 @@
#include "utils/lsyscache.h"
#include "utils/memutils.h"
#include "utils/syscache.h"
+#include "pg_trace.h"
/*
@@ -565,6 +566,8 @@ ExecMergeJoin(MergeJoinState *node)
bool doFillOuter;
bool doFillInner;
+ TRACE_POSTGRESQL_EXECUTOR_MERGEJOIN((uintptr_t)node);
+
/*
* get information from node
*/
Index: src/backend/executor/nodeNestloop.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeNestloop.c,v
retrieving revision 1.46
diff -u -3 -p -r1.46 nodeNestloop.c
--- src/backend/executor/nodeNestloop.c 1 Jan 2008 19:45:49 -0000 1.46
+++ src/backend/executor/nodeNestloop.c 26 Jun 2008 23:18:43 -0000
@@ -24,6 +24,7 @@
#include "executor/execdebug.h"
#include "executor/nodeNestloop.h"
#include "utils/memutils.h"
+#include "pg_trace.h"
/* ----------------------------------------------------------------
@@ -67,6 +68,8 @@ ExecNestLoop(NestLoopState *node)
List *otherqual;
ExprContext *econtext;
+ TRACE_POSTGRESQL_EXECUTOR_NESTLOOP((uintptr_t)node);
+
/*
* get information from the node
*/
Index: src/backend/executor/nodeSetOp.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeSetOp.c,v
retrieving revision 1.25
diff -u -3 -p -r1.25 nodeSetOp.c
--- src/backend/executor/nodeSetOp.c 1 Jan 2008 19:45:49 -0000 1.25
+++ src/backend/executor/nodeSetOp.c 26 Jun 2008 23:18:43 -0000
@@ -37,6 +37,7 @@
#include "executor/executor.h"
#include "executor/nodeSetOp.h"
#include "utils/memutils.h"
+#include "pg_trace.h"
/* ----------------------------------------------------------------
@@ -50,6 +51,8 @@ ExecSetOp(SetOpState *node)
TupleTableSlot *resultTupleSlot;
PlanState *outerPlan;
+ TRACE_POSTGRESQL_EXECUTOR_SETOP((uintptr_t)node);
+
/*
* get information from the node
*/
Index: src/backend/executor/nodeSort.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeSort.c,v
retrieving revision 1.62
diff -u -3 -p -r1.62 nodeSort.c
--- src/backend/executor/nodeSort.c 1 Jan 2008 19:45:49 -0000 1.62
+++ src/backend/executor/nodeSort.c 26 Jun 2008 23:18:43 -0000
@@ -19,6 +19,7 @@
#include "executor/nodeSort.h"
#include "miscadmin.h"
#include "utils/tuplesort.h"
+#include "pg_trace.h"
/* ----------------------------------------------------------------
@@ -53,6 +54,8 @@ ExecSort(SortState *node)
dir = estate->es_direction;
tuplesortstate = (Tuplesortstate *) node->tuplesortstate;
+ TRACE_POSTGRESQL_EXECUTOR_SORT((uintptr_t)node, dir);
+
/*
* If first time through, read all tuples from outer plan and pass them to
* tuplesort.c. Subsequent calls just fetch tuples from tuplesort.
Index: src/backend/executor/nodeSubplan.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeSubplan.c,v
retrieving revision 1.93
diff -u -3 -p -r1.93 nodeSubplan.c
--- src/backend/executor/nodeSubplan.c 12 May 2008 00:00:49 -0000 1.93
+++ src/backend/executor/nodeSubplan.c 26 Jun 2008 23:18:44 -0000
@@ -27,6 +27,7 @@
#include "utils/array.h"
#include "utils/lsyscache.h"
#include "utils/memutils.h"
+#include "pg_trace.h"
static Datum ExecHashSubPlan(SubPlanState *node,
@@ -80,6 +81,8 @@ ExecHashSubPlan(SubPlanState *node,
ExprContext *innerecontext = node->innerecontext;
TupleTableSlot *slot;
+ TRACE_POSTGRESQL_EXECUTOR_SUBPLAN_HASH((uintptr_t)node);
+
/* Shouldn't have any direct correlation Vars */
if (subplan->parParam != NIL || node->args != NIL)
elog(ERROR, "hashed subplan with direct correlation not supported");
@@ -215,6 +218,8 @@ ExecScanSubPlan(SubPlanState *node,
ListCell *l;
ArrayBuildState *astate = NULL;
+ TRACE_POSTGRESQL_EXECUTOR_SUBPLAN_SCAN((uintptr_t)node);
+
/*
* We are probably in a short-lived expression-evaluation context. Switch
* to the per-query context for manipulating the child plan's chgParam,
Index: src/backend/executor/nodeUnique.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeUnique.c,v
retrieving revision 1.56
diff -u -3 -p -r1.56 nodeUnique.c
--- src/backend/executor/nodeUnique.c 1 Jan 2008 19:45:49 -0000 1.56
+++ src/backend/executor/nodeUnique.c 26 Jun 2008 23:18:44 -0000
@@ -28,6 +28,7 @@
#include "executor/executor.h"
#include "executor/nodeUnique.h"
#include "utils/memutils.h"
+#include "pg_trace.h"
/* ----------------------------------------------------------------
@@ -45,6 +46,8 @@ ExecUnique(UniqueState *node)
TupleTableSlot *slot;
PlanState *outerPlan;
+ TRACE_POSTGRESQL_EXECUTOR_UNIQUE((uintptr_t)node);
+
/*
* get information from the node
*/
Index: src/backend/postmaster/autovacuum.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/postmaster/autovacuum.c,v
retrieving revision 1.79
diff -u -3 -p -r1.79 autovacuum.c
--- src/backend/postmaster/autovacuum.c 5 Jun 2008 15:47:32 -0000 1.79
+++ src/backend/postmaster/autovacuum.c 26 Jun 2008 23:18:46 -0000
@@ -99,6 +99,7 @@
#include "utils/ps_status.h"
#include "utils/syscache.h"
#include "utils/tqual.h"
+#include "pg_trace.h"
/*
@@ -1603,6 +1604,7 @@ AutoVacWorkerMain(int argc, char *argv[]
InitPostgres(NULL, dbid, NULL, &dbname);
SetProcessingMode(NormalProcessing);
set_ps_display(dbname, false);
+ TRACE_POSTGRESQL_AUTOVACUUM_START(dbid, dbname);
ereport(DEBUG1,
(errmsg("autovacuum: processing database \"%s\"", dbname)));
@@ -2113,6 +2115,7 @@ do_autovacuum(void)
{
/* have at it */
MemoryContextSwitchTo(TopTransactionContext);
+ TRACE_POSTGRESQL_AUTOVACUUM_RELATION(tab->at_relid, datname, nspname, relname);
autovacuum_do_vac_analyze(tab->at_relid,
tab->at_dovacuum,
tab->at_doanalyze,
Index: src/backend/postmaster/pgstat.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/postmaster/pgstat.c,v
retrieving revision 1.175
diff -u -3 -p -r1.175 pgstat.c
--- src/backend/postmaster/pgstat.c 19 Jun 2008 00:46:05 -0000 1.175
+++ src/backend/postmaster/pgstat.c 26 Jun 2008 23:18:48 -0000
@@ -61,6 +61,7 @@
#include "utils/ps_status.h"
#include "utils/rel.h"
#include "utils/tqual.h"
+#include "pg_trace.h"
/* ----------
@@ -2178,6 +2179,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.233
diff -u -3 -p -r1.233 bufmgr.c
--- src/backend/storage/buffer/bufmgr.c 19 Jun 2008 00:46:05 -0000 1.233
+++ src/backend/storage/buffer/bufmgr.c 26 Jun 2008 23:18:51 -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,6 +214,9 @@ 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++;
@@ -240,12 +244,19 @@ ReadBuffer_common(SMgrRelation smgr, boo
{
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,6 +308,7 @@ ReadBuffer_common(SMgrRelation smgr, boo
} while (!StartBufferIO(bufHdr, true));
}
}
+ TRACE_POSTGRESQL_BUFFER_MISS();
/*
* if we have gotten to this point, we have allocated a buffer for the
@@ -368,6 +380,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);
}
@@ -510,6 +526,11 @@ BufferAlloc(SMgrRelation smgr,
* happens to be trying to split the page the first one got from
* StrategyGetBuffer.)
*/
+
+ TRACE_POSTGRESQL_BUFFER_WRITE_DIRTY_START(blockNum,
+ smgr->smgr_rnode.spcNode, smgr->smgr_rnode.dbNode,
+ smgr->smgr_rnode.relNode);
+
if (LWLockConditionalAcquire(buf->content_lock, LW_SHARED))
{
/*
@@ -532,6 +553,11 @@ BufferAlloc(SMgrRelation smgr,
/* OK, do the I/O */
FlushBuffer(buf, NULL);
LWLockRelease(buf->content_lock);
+
+ TRACE_POSTGRESQL_BUFFER_WRITE_DIRTY_DONE(
+ blockNum, smgr->smgr_rnode.spcNode,
+ smgr->smgr_rnode.dbNode, smgr->smgr_rnode.relNode,
+ (oldFlags & BM_HINT_BITS_TEST));
}
else
{
@@ -850,7 +876,9 @@ MarkBufferDirty(Buffer buffer)
if (!(bufHdr->flags & BM_DIRTY) && VacuumCostActive)
VacuumCostBalance += VacuumCostPageDirty;
- bufHdr->flags |= (BM_DIRTY | BM_JUST_DIRTIED);
+ bufHdr->flags |= (BM_DIRTY | BM_JUST_DIRTIED | BM_HINT_BITS_TEST);
+
+ TRACE_POSTGRESQL_BUFFER_MARK_DIRTY(buffer);
UnlockBufHdr(bufHdr);
}
@@ -1086,6 +1114,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 +1147,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 +1178,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 +1686,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 +1794,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, 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,6 +1824,10 @@ FlushBuffer(volatile BufferDesc *buf, SM
BufferFlushCount++;
+ TRACE_POSTGRESQL_BUFFER_FLUSH_DONE(reln->smgr_rnode.spcNode,
+ reln->smgr_rnode.dbNode, reln->smgr_rnode.relNode,
+ buf->tag.blockNum, (buf->flags & BM_HINT_BITS_TEST));
+
/*
* Mark the buffer as clean (unless BM_JUST_DIRTIED has become set) and
* end the io_in_progress state.
@@ -2536,7 +2579,7 @@ TerminateBufferIO(volatile BufferDesc *b
Assert(buf->flags & BM_IO_IN_PROGRESS);
buf->flags &= ~(BM_IO_IN_PROGRESS | BM_IO_ERROR);
if (clear_dirty && !(buf->flags & BM_JUST_DIRTIED))
- buf->flags &= ~(BM_DIRTY | BM_CHECKPOINT_NEEDED);
+ buf->flags &= ~(BM_DIRTY | BM_CHECKPOINT_NEEDED | BM_HINT_BITS_TEST);
buf->flags |= set_flag_bits;
UnlockBufHdr(buf);
Index: src/backend/storage/buffer/localbuf.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/storage/buffer/localbuf.c,v
retrieving revision 1.80
diff -u -3 -p -r1.80 localbuf.c
--- src/backend/storage/buffer/localbuf.c 12 Jun 2008 09:12:31 -0000 1.80
+++ src/backend/storage/buffer/localbuf.c 26 Jun 2008 23:18:51 -0000
@@ -21,6 +21,7 @@
#include "utils/guc.h"
#include "utils/memutils.h"
#include "utils/resowner.h"
+#include "pg_trace.h"
/*#define LBDEBUG*/
@@ -236,6 +237,7 @@ MarkLocalBufferDirty(Buffer buffer)
bufHdr = &LocalBufferDescriptors[bufid];
bufHdr->flags |= BM_DIRTY;
+ TRACE_POSTGRESQL_BUFFER_MARK_DIRTY_LOCAL(buffer);
}
/*
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 26 Jun 2008 23:18:51 -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");
@@ -259,6 +262,8 @@ DeadLockCheck(PGPROC *proc)
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/storage/smgr/md.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/storage/smgr/md.c,v
retrieving revision 1.138
diff -u -3 -p -r1.138 md.c
--- src/backend/storage/smgr/md.c 2 May 2008 01:08:27 -0000 1.138
+++ src/backend/storage/smgr/md.c 26 Jun 2008 23:18:53 -0000
@@ -26,6 +26,7 @@
#include "storage/smgr.h"
#include "utils/hsearch.h"
#include "utils/memutils.h"
+#include "pg_trace.h"
/* interval for calling AbsorbFsyncRequests in mdsync */
@@ -555,6 +556,8 @@ mdread(SMgrRelation reln, BlockNumber bl
int nbytes;
MdfdVec *v;
+ TRACE_POSTGRESQL_SMGR_READ_START(blocknum, reln->smgr_rnode.spcNode, reln->smgr_rnode.dbNode, reln->smgr_rnode.relNode);
+
v = _mdfd_getseg(reln, blocknum, false, EXTENSION_FAIL);
seekpos = (off_t) BLCKSZ * (blocknum % ((BlockNumber) RELSEG_SIZE));
@@ -569,7 +572,11 @@ mdread(SMgrRelation reln, BlockNumber bl
reln->smgr_rnode.dbNode,
reln->smgr_rnode.relNode)));
- if ((nbytes = FileRead(v->mdfd_vfd, buffer, BLCKSZ)) != BLCKSZ)
+ nbytes = FileRead(v->mdfd_vfd, buffer, BLCKSZ);
+
+ TRACE_POSTGRESQL_SMGR_READ_DONE(blocknum, reln->smgr_rnode.spcNode, reln->smgr_rnode.dbNode, reln->smgr_rnode.relNode, nbytes, BLCKSZ);
+
+ if (nbytes != BLCKSZ)
{
if (nbytes < 0)
ereport(ERROR,
@@ -621,6 +628,8 @@ mdwrite(SMgrRelation reln, BlockNumber b
Assert(blocknum < mdnblocks(reln));
#endif
+ TRACE_POSTGRESQL_SMGR_WRITE_START(blocknum, reln->smgr_rnode.spcNode, reln->smgr_rnode.dbNode, reln->smgr_rnode.relNode);
+
v = _mdfd_getseg(reln, blocknum, isTemp, EXTENSION_FAIL);
seekpos = (off_t) BLCKSZ * (blocknum % ((BlockNumber) RELSEG_SIZE));
@@ -657,6 +666,8 @@ mdwrite(SMgrRelation reln, BlockNumber b
errhint("Check free disk space.")));
}
+ TRACE_POSTGRESQL_SMGR_WRITE_DONE(blocknum, reln->smgr_rnode.spcNode, reln->smgr_rnode.dbNode, reln->smgr_rnode.relNode, nbytes, BLCKSZ);
+
if (!isTemp)
register_dirty_segment(reln, v);
}
Index: src/backend/tcop/postgres.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/tcop/postgres.c,v
retrieving revision 1.553
diff -u -3 -p -r1.553 postgres.c
--- src/backend/tcop/postgres.c 15 May 2008 00:17:40 -0000 1.553
+++ src/backend/tcop/postgres.c 26 Jun 2008 23:18:57 -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();
@@ -660,6 +663,8 @@ pg_rewrite_query(Query *query)
elog_node_display(DEBUG1, "rewritten parse tree", querytree_list,
Debug_pretty_print);
+ TRACE_POSTGRESQL_QUERY_PARSE_DONE();
+
return querytree_list;
}
@@ -673,6 +678,8 @@ pg_plan_query(Query *querytree, int curs
{
PlannedStmt *plan;
+ TRACE_POSTGRESQL_QUERY_PLAN_START();
+
/* Utility commands have no plans. */
if (querytree->commandType == CMD_UTILITY)
return NULL;
@@ -710,6 +717,7 @@ 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 +793,7 @@ exec_simple_query(const char *query_stri
bool isTopLevel;
char msec_str[32];
+
/*
* Report query to various monitoring facilities.
*/
@@ -792,6 +801,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 +1069,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;
}
@@ -3497,6 +3510,7 @@ PostgresMain(int argc, char *argv[], con
{
if (IsTransactionOrTransactionBlock())
{
+ TRACE_POSTGRESQL_TRANSACTION_IDLE_START(GetCurrentTransactionId(), GetCurrentCommandId(false));
set_ps_display("idle in transaction", false);
pgstat_report_activity("<IDLE> in transaction");
}
@@ -3526,6 +3540,8 @@ PostgresMain(int argc, char *argv[], con
*/
firstchar = ReadCommand(&input_message);
+ TRACE_POSTGRESQL_TRANSACTION_IDLE_DONE();
+
/*
* (4) disable async signal conditions again.
*/
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 26 Jun 2008 23:18:58 -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 26 Jun 2008 23:18:59 -0000
@@ -7,18 +7,123 @@
* ----------
*/
+
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 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 transaction__idle__start(unsigned int currentTxnId, unsigned int currentCmdId);
+ probe transaction__idle__done();
+
+ 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, int isHintBitsWrite);
+ probe buffer__hit();
+ probe buffer__miss();
+ probe buffer__mark__dirty(int bufferId);
+ probe buffer__mark__dirty__local(int bufferId);
+ 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 wal__buffer__write__start();
+ probe wal__buffer__write__done();
+
+ probe deadlock__found();
+ probe deadlock__notfound(int);
+
+ probe smgr__read__start(int blockNum, int tablespaceOid,
+ int databaseOid, int relationOid);
+ probe smgr__read__done(int blockNum, int tablespaceOid,
+ int databaseOid, int relationOid, int bytesRead,
+ int blockSize);
+ probe smgr__write__start(int blockNum, int tablespaceOid,
+ int databaseOid, int relationOid);
+ probe smgr__write__done(int blockNum, int tablespaceOid,
+ int databaseOid, int relationOid, int bytesRead,
+ int blockSize);
+
+ probe xlog__insert(unsigned char, unsigned char);
+ probe xlog__switch();
+
+ probe xlog__checkpoint__start(int checkpointFlags, unsigned int transactionId);
+ probe xlog__checkpoint__done(int bufsWritten, int NBuffers, int segsAdded,
+ int segsRemoved, int segsRecycled);
+ 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();
+
+ probe autovacuum__start(unsigned int databaseOid, char *databaseName);
+ probe autovacuum__relation(unsigned int, char *, char *, char *);
+
+ probe slru__readpage__start(unsigned int, int pageNum, int writeOk, int xid);
+ probe slru__readpage__done(int slotNum);
+ probe slru__readpage__readonly(unsigned int, int, int);
+ probe slru__writepage__start(unsigned int, int pageNum, int slotNum);
+ probe slru__writepage__done();
+ probe slru__readpage__physical__start(unsigned int, char *path, int pageNum, int slotNum);
+ probe slru__readpage__physical__done(int retVal, int errCause, int errNo);
+ probe slru__writepage__physical__start(unsigned int, int pageNum, int slotNum);
+ probe slru__writepage__physical__done(int retVal, int errCause, int errNo);
+ probe executor__scan(unsigned int, unsigned int, unsigned int);
+ probe executor__agg(unsigned int, int);
+ probe executor__group(unsigned int, int);
+ probe executor__hash__multi(unsigned int);
+ probe executor__hashjoin(unsigned int);
+ probe executor__limit(unsigned int);
+ probe executor__material(unsigned int);
+ probe executor__mergejoin(unsigned int);
+ probe executor__nestloop(unsigned int);
+ probe executor__setop(unsigned int);
+ probe executor__sort(unsigned int, int);
+ probe executor__subplan__hash(unsigned int);
+ probe executor__subplan__scan(unsigned int);
+ probe executor__unique(unsigned int);
};
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 26 Jun 2008 23:19:04 -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(true) :
+ (state->allowedMem - state->availMem + 1023) / 1024));
+
+
MemoryContextSwitchTo(oldcontext);
/*
Index: src/include/storage/buf_internals.h
===================================================================
RCS file: /projects/cvsroot/pgsql/src/include/storage/buf_internals.h,v
retrieving revision 1.97
diff -u -3 -p -r1.97 buf_internals.h
--- src/include/storage/buf_internals.h 19 Jun 2008 00:46:06 -0000 1.97
+++ src/include/storage/buf_internals.h 26 Jun 2008 23:19:06 -0000
@@ -37,6 +37,7 @@
#define BM_JUST_DIRTIED (1 << 5) /* dirtied since write started */
#define BM_PIN_COUNT_WAITER (1 << 6) /* have waiter for sole pin */
#define BM_CHECKPOINT_NEEDED (1 << 7) /* must write for checkpoint */
+#define BM_HINT_BITS_TEST (1 << 8) /* test effect of writes due to hint bits */
typedef bits16 BufFlags;
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
