diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index 1ac972e46feb901c18e71703d199f45468c89330..2368337c14ec0ca32dfe2a383ed4e77875c1dc74 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -7,7 +7,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/xlog.c,v 1.323 2008/12/03 08:20:11 heikki Exp $ + * $PostgreSQL: pgsql/src/backend/access/transam/xlog.c,v 1.324 2008/12/17 01:39:03 momjian Exp $ * *------------------------------------------------------------------------- */ @@ -48,6 +48,7 @@ #include "utils/builtins.h" #include "utils/guc.h" #include "utils/ps_status.h" +#include "pg_trace.h" /* File path names (all relative to $PGDATA) */ @@ -486,6 +487,8 @@ XLogInsert(RmgrId rmid, uint8 info, XLogRecData *rdata) 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. @@ -914,6 +917,8 @@ begin:; XLogwrtRqst FlushRqst; XLogRecPtr OldSegEnd; + TRACE_POSTGRESQL_XLOG_SWITCH(); + LWLockAcquire(WALWriteLock, LW_EXCLUSIVE); /* @@ -1313,12 +1318,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(); } } } @@ -5904,6 +5911,8 @@ CreateCheckPoint(int flags) if (log_checkpoints) LogCheckpointStart(flags); + TRACE_POSTGRESQL_CHECKPOINT_START(flags); + /* * Before flushing data, we must wait for any transactions that are * currently in their commit critical sections. If an xact inserted its @@ -6069,6 +6078,11 @@ CreateCheckPoint(int flags) if (log_checkpoints) LogCheckpointEnd(); + TRACE_POSTGRESQL_CHECKPOINT_DONE(CheckpointStats.ckpt_bufs_written, + NBuffers, CheckpointStats.ckpt_segs_added, + CheckpointStats.ckpt_segs_removed, + CheckpointStats.ckpt_segs_recycled); + LWLockRelease(CheckpointLock); } diff --git a/src/backend/storage/buffer/bufmgr.c b/src/backend/storage/buffer/bufmgr.c index b7e0861e2b5b5aa89489e86e46f46e0a72cfd070..157e9aaafcf5f0e0dafc30978c5eb3671cc99a35 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.242 2008/11/19 10:34:52 heikki Exp $ + * $PostgreSQL: pgsql/src/backend/storage/buffer/bufmgr.c,v 1.243 2008/12/17 01:39:03 momjian Exp $ * *------------------------------------------------------------------------- */ @@ -203,8 +203,7 @@ ReadBuffer_common(SMgrRelation smgr, bool isLocalBuf, ForkNumber forkNum, if (isExtend) blockNum = smgrnblocks(smgr, forkNum); - TRACE_POSTGRESQL_BUFFER_READ_START(blockNum, smgr->smgr_rnode.spcNode, - smgr->smgr_rnode.dbNode, smgr->smgr_rnode.relNode, isLocalBuf); + TRACE_POSTGRESQL_BUFFER_READ_START(forkNum, blockNum, smgr->smgr_rnode.spcNode, smgr->smgr_rnode.dbNode, smgr->smgr_rnode.relNode, isLocalBuf); if (isLocalBuf) { @@ -253,7 +252,7 @@ ReadBuffer_common(SMgrRelation smgr, bool isLocalBuf, ForkNumber forkNum, if (VacuumCostActive) VacuumCostBalance += VacuumCostPageHit; - TRACE_POSTGRESQL_BUFFER_READ_DONE(blockNum, + TRACE_POSTGRESQL_BUFFER_READ_DONE(forkNum, blockNum, smgr->smgr_rnode.spcNode, smgr->smgr_rnode.dbNode, smgr->smgr_rnode.relNode, isLocalBuf, found); @@ -380,9 +379,9 @@ ReadBuffer_common(SMgrRelation smgr, bool isLocalBuf, ForkNumber forkNum, if (VacuumCostActive) VacuumCostBalance += VacuumCostPageMiss; - TRACE_POSTGRESQL_BUFFER_READ_DONE(blockNum, smgr->smgr_rnode.spcNode, - smgr->smgr_rnode.dbNode, smgr->smgr_rnode.relNode, - isLocalBuf, found); + TRACE_POSTGRESQL_BUFFER_READ_DONE(forkNum, blockNum, + smgr->smgr_rnode.spcNode, smgr->smgr_rnode.dbNode, + smgr->smgr_rnode.relNode, isLocalBuf, found); return BufferDescriptorGetBuffer(bufHdr); } @@ -526,6 +525,11 @@ BufferAlloc(SMgrRelation smgr, ForkNumber forkNum, * happens to be trying to split the page the first one got from * StrategyGetBuffer.) */ + + TRACE_POSTGRESQL_BUFFER_WRITE_DIRTY_START(forkNum, + blockNum, smgr->smgr_rnode.spcNode, + smgr->smgr_rnode.dbNode, smgr->smgr_rnode.relNode); + if (LWLockConditionalAcquire(buf->content_lock, LW_SHARED)) { /* @@ -548,6 +552,11 @@ BufferAlloc(SMgrRelation smgr, ForkNumber forkNum, /* OK, do the I/O */ FlushBuffer(buf, NULL); LWLockRelease(buf->content_lock); + + TRACE_POSTGRESQL_BUFFER_WRITE_DIRTY_DONE( + forkNum, blockNum, smgr->smgr_rnode.spcNode, + smgr->smgr_rnode.dbNode, + smgr->smgr_rnode.relNode); } else { @@ -1682,6 +1691,7 @@ CheckPointBuffers(int flags) CheckpointStats.ckpt_write_t = GetCurrentTimestamp(); BufferSync(flags); CheckpointStats.ckpt_sync_t = GetCurrentTimestamp(); + TRACE_POSTGRESQL_BUFFER_CHECKPOINT_SYNC_START(); smgrsync(); CheckpointStats.ckpt_sync_end_t = GetCurrentTimestamp(); TRACE_POSTGRESQL_BUFFER_CHECKPOINT_DONE(); diff --git a/src/backend/storage/smgr/md.c b/src/backend/storage/smgr/md.c index 1a762eb5bc7610e524d29daaf26141cd6b592055..d4214a8bd4272a2442274bd4f2de9b8ca5135a3a 100644 --- a/src/backend/storage/smgr/md.c +++ b/src/backend/storage/smgr/md.c @@ -8,7 +8,7 @@ * * * IDENTIFICATION - * $PostgreSQL: pgsql/src/backend/storage/smgr/md.c,v 1.141 2008/11/14 11:09:50 heikki Exp $ + * $PostgreSQL: pgsql/src/backend/storage/smgr/md.c,v 1.142 2008/12/17 01:39:04 momjian Exp $ * *------------------------------------------------------------------------- */ @@ -27,6 +27,7 @@ #include "storage/smgr.h" #include "utils/hsearch.h" #include "utils/memutils.h" +#include "pg_trace.h" /* interval for calling AbsorbFsyncRequests in mdsync */ @@ -560,6 +561,8 @@ mdread(SMgrRelation reln, ForkNumber forknum, BlockNumber blocknum, int nbytes; MdfdVec *v; + TRACE_POSTGRESQL_SMGR_MD_READ_START(forknum, blocknum, reln->smgr_rnode.spcNode, reln->smgr_rnode.dbNode, reln->smgr_rnode.relNode); + v = _mdfd_getseg(reln, forknum, blocknum, false, EXTENSION_FAIL); seekpos = (off_t) BLCKSZ * (blocknum % ((BlockNumber) RELSEG_SIZE)); @@ -571,7 +574,11 @@ mdread(SMgrRelation reln, ForkNumber forknum, BlockNumber blocknum, errmsg("could not seek to block %u of relation %s: %m", blocknum, relpath(reln->smgr_rnode, forknum)))); - if ((nbytes = FileRead(v->mdfd_vfd, buffer, BLCKSZ)) != BLCKSZ) + nbytes = FileRead(v->mdfd_vfd, buffer, BLCKSZ); + + TRACE_POSTGRESQL_SMGR_MD_READ_DONE(forknum, blocknum, reln->smgr_rnode.spcNode, reln->smgr_rnode.dbNode, reln->smgr_rnode.relNode, relpath(reln->smgr_rnode, forknum), nbytes, BLCKSZ); + + if (nbytes != BLCKSZ) { if (nbytes < 0) ereport(ERROR, @@ -618,6 +625,8 @@ mdwrite(SMgrRelation reln, ForkNumber forknum, BlockNumber blocknum, Assert(blocknum < mdnblocks(reln, forknum)); #endif + TRACE_POSTGRESQL_SMGR_MD_WRITE_START(forknum, blocknum, reln->smgr_rnode.spcNode, reln->smgr_rnode.dbNode, reln->smgr_rnode.relNode); + v = _mdfd_getseg(reln, forknum, blocknum, isTemp, EXTENSION_FAIL); seekpos = (off_t) BLCKSZ * (blocknum % ((BlockNumber) RELSEG_SIZE)); @@ -629,7 +638,11 @@ mdwrite(SMgrRelation reln, ForkNumber forknum, BlockNumber blocknum, errmsg("could not seek to block %u of relation %s: %m", blocknum, relpath(reln->smgr_rnode, forknum)))); - if ((nbytes = FileWrite(v->mdfd_vfd, buffer, BLCKSZ)) != BLCKSZ) + nbytes = FileWrite(v->mdfd_vfd, buffer, BLCKSZ); + + TRACE_POSTGRESQL_SMGR_MD_WRITE_DONE(forknum, blocknum, reln->smgr_rnode.spcNode, reln->smgr_rnode.dbNode, reln->smgr_rnode.relNode, relpath(reln->smgr_rnode, forknum), nbytes, BLCKSZ); + + if (nbytes != BLCKSZ) { if (nbytes < 0) ereport(ERROR, diff --git a/src/backend/utils/Gen_dummy_probes.sed b/src/backend/utils/Gen_dummy_probes.sed index 42b2eeb54073deb04b2fcee158b2076879927462..3844c5dcdb7358faf1b594f264de30f985337bce 100644 --- a/src/backend/utils/Gen_dummy_probes.sed +++ b/src/backend/utils/Gen_dummy_probes.sed @@ -3,7 +3,7 @@ # # Copyright (c) 2008, PostgreSQL Global Development Group # -# $PostgreSQL: pgsql/src/backend/utils/Gen_dummy_probes.sed,v 1.2 2008/08/01 13:16:09 alvherre Exp $ +# $PostgreSQL: pgsql/src/backend/utils/Gen_dummy_probes.sed,v 1.3 2008/12/17 01:39:04 momjian Exp $ #------------------------------------------------------------------------- /^[ ]*probe /!d @@ -17,5 +17,7 @@ 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)/ +s/([^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\})/(INT1, INT2, INT3, INT4, INT5, INT6, INT7)/ +s/([^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\}, [^,)]\{1,\})/(INT1, INT2, INT3, INT4, INT5, INT6, INT7, INT8)/ P s/(.*$/_ENABLED() (0)/ diff --git a/src/backend/utils/probes.d b/src/backend/utils/probes.d index b87a234bb351fa249d23df2b4c6aa9313d66a41f..e03154c514497845328a07d16a83b42fa1348ee6 100644 --- a/src/backend/utils/probes.d +++ b/src/backend/utils/probes.d @@ -3,26 +3,25 @@ * * Copyright (c) 2006-2008, PostgreSQL Global Development Group * - * $PostgreSQL: pgsql/src/backend/utils/probes.d,v 1.3 2008/08/01 13:16:09 alvherre Exp $ + * $PostgreSQL: pgsql/src/backend/utils/probes.d,v 1.4 2008/12/17 01:39:04 momjian 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 LocalTransactionId unsigned int +#define LWLockId int +#define LWLockMode int +#define LOCKMODE int +#define BlockNumber unsigned int +#define Oid unsigned int +#define ForkNumber int #define bool char provider postgresql { /* - * Due to a bug in Mac OS X 10.5, using built-in typedefs (e.g. uintptr_t, - * uint32_t, etc.) cause compilation errors. + * Note: Do not use built-in typedefs (e.g. uintptr_t, uint32_t, etc) * as they cause compilation errors in Mac OS X 10.5. */ probe transaction__start(LocalTransactionId); @@ -36,13 +35,8 @@ provider postgresql { 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 lock__wait__start(unsigned int, LOCKMODE); + probe lock__wait__done(unsigned int, LOCKMODE); probe query__parse__start(const char *); probe query__parse__done(const char *); @@ -59,27 +53,26 @@ provider postgresql { 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__read__start(ForkNumber, BlockNumber, Oid, Oid, Oid, bool); + probe buffer__read__done(ForkNumber, BlockNumber, Oid, Oid, Oid, 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__sync__start(); probe buffer__checkpoint__done(); probe buffer__sync__start(int, int); probe buffer__sync__written(int); probe buffer__sync__done(int, int, int); + probe buffer__write__dirty__start(ForkNumber, BlockNumber, Oid, Oid, Oid); + probe buffer__write__dirty__done(ForkNumber, BlockNumber, Oid, Oid, Oid); probe deadlock__found(); + probe checkpoint__start(int); + probe checkpoint__done(int, int, int, int, int); probe clog__checkpoint__start(bool); probe clog__checkpoint__done(bool); probe subtrans__checkpoint__start(bool); @@ -88,4 +81,14 @@ provider postgresql { probe multixact__checkpoint__done(bool); probe twophase__checkpoint__start(); probe twophase__checkpoint__done(); + + probe smgr__md__read__start(ForkNumber, BlockNumber, Oid, Oid, Oid); + probe smgr__md__read__done(ForkNumber, BlockNumber, Oid, Oid, Oid, const char *, int, int); + probe smgr__md__write__start(ForkNumber, BlockNumber, Oid, Oid, Oid); + probe smgr__md__write__done(ForkNumber, BlockNumber, Oid, Oid, Oid, const char *, int, int); + + probe xlog__insert(unsigned char, unsigned char); + probe xlog__switch(); + probe wal__buffer__write__start(); + probe wal__buffer__write__done(); };