I performed review and I prepared own patch which contains only probes without
any issue. I suggest commit this patch because the rest of patch is independent
and it can be committed next commit fest after rework.
I found following issues:
1) SLRU probes.
I think it is good to have probes there but they needs polish. See my comments
http://reviewdemo.postgresql.org/r/25/
2) XLOG probes
I think there is confuse placement of probes after merge. It needs cleanup.
3) Executor probes
I would like to see any use case for them/
4) smgr probes
I prefer to have this probes in smgr instead of md. The reason why Robert put
them into md is that it returns number of written/read bytes, but it is "always"
BLCKSZ which could be returned from smgr directly. Only difference is
when error occurs during write/read and not all data are written/read.
It needs discuss.
5) autovacuum start probes
I would like to see also stat/stop for any other process types. It was discussed
but no comment from author(s).
6) idle transaction
See my comments
http://reviewdemo.postgresql.org/r/25/
7) query-reewrite is missing
8) mark dirty and BM_HINT... flag
I remove these because I don't see any use case for it. It would be nice provide
some dtrace script or describe basic ideas.
Thats all Zdenek
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);
/*
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
