Monitoring Database Activity monitoring database activity database activity monitoring A database administrator frequently wonders, What is the system doing right now? This chapter discusses how to find that out. Several tools are available for monitoring database activity and analyzing performance. Most of this chapter is devoted to describing PostgreSQL's statistics collector, but one should not neglect regular Unix monitoring programs such as ps, top, iostat, and vmstat. Also, once one has identified a poorly-performing query, further investigation might be needed using PostgreSQL's command. discusses EXPLAIN and other methods for understanding the behavior of an individual query. Standard Unix Tools ps to monitor activity On most Unix platforms, PostgreSQL modifies its command title as reported by ps, so that individual server processes can readily be identified. A sample display is $ ps auxww | grep ^postgres postgres 960 0.0 1.1 6104 1480 pts/1 SN 13:17 0:00 postgres -i postgres 963 0.0 1.1 7084 1472 pts/1 SN 13:17 0:00 postgres: writer process postgres 965 0.0 1.1 6152 1512 pts/1 SN 13:17 0:00 postgres: stats collector process postgres 998 0.0 2.3 6532 2992 pts/1 SN 13:18 0:00 postgres: tgl runbug 127.0.0.1 idle postgres 1003 0.0 2.4 6532 3128 pts/1 SN 13:19 0:00 postgres: tgl regression [local] SELECT waiting postgres 1016 0.1 2.4 6532 3080 pts/1 SN 13:19 0:00 postgres: tgl regression [local] idle in transaction (The appropriate invocation of ps varies across different platforms, as do the details of what is shown. This example is from a recent Linux system.) The first process listed here is the master server process. The command arguments shown for it are the same ones used when it was launched. The next two processes are background worker processes automatically launched by the master process. (The stats collector process will not be present if you have set the system not to start the statistics collector.) Each of the remaining processes is a server process handling one client connection. Each such process sets its command line display in the form postgres: user database host activity The user, database, and (client) host items remain the same for the life of the client connection, but the activity indicator changes. The activity can be idle (i.e., waiting for a client command), idle in transaction (waiting for client inside a BEGIN block), or a command type name such as SELECT. Also, waiting is appended if the server process is presently waiting on a lock held by another session. In the above example we can infer that process 1003 is waiting for process 1016 to complete its transaction and thereby release some lock. If you have turned off then the activity indicator is not updated; the process title is set only once when a new process is launched. On some platforms this saves a measurable amount of per-command overhead; on others it's insignificant. Solaris requires special handling. You must use /usr/ucb/ps, rather than /bin/ps. You also must use two flags, not just one. In addition, your original invocation of the postgres command must have a shorter ps status display than that provided by each server process. If you fail to do all three things, the ps output for each server process will be the original postgres command line. The Statistics Collector statistics PostgreSQL's statistics collector is a subsystem that supports collection and reporting of information about server activity. Presently, the collector can count accesses to tables and indexes in both disk-block and individual-row terms. It also tracks the total number of rows in each table, and the last vacuum and analyze times for each table. It can also count calls to user-defined functions and the total time spent in each one. PostgreSQL also supports reporting of the exact command currently being executed by other server processes. This is an facility independent of the collector process. Statistics Collection Configuration Since collection of statistics adds some overhead to query execution, the system can be configured to collect or not collect information. This is controlled by configuration parameters that are normally set in postgresql.conf. (See for details about setting configuration parameters.) The parameter controls whether statistics are collected about table and index accesses. The parameter enables tracking of usage of user-defined functions. The parameter enables monitoring of the current command being executed by any server process. Normally these parameters are set in postgresql.conf so that they apply to all server processes, but it is possible to turn them on or off in individual sessions using the command. (To prevent ordinary users from hiding their activity from the administrator, only superusers are allowed to change these parameters with SET.) The statistics collector communicates with the backends needing information (including autovacuum) through temporary files. These files are stored in the pg_stat_tmp subdirectory. When the postmaster shuts down, a permanent copy of the statistics data is stored in the global subdirectory. For increased performance, the parameter can be pointed at a RAM-based file system, decreasing physical I/O requirements. Viewing Collected Statistics Several predefined views, listed in , are available to show the results of statistics collection. Alternatively, one can build custom views using the underlying statistics functions. When using the statistics to monitor current activity, it is important to realize that the information does not update instantaneously. Each individual server process transmits new statistical counts to the collector just before going idle; so a query or transaction still in progress does not affect the displayed totals. Also, the collector itself emits a new report at most once per PGSTAT_STAT_INTERVAL milliseconds (500 unless altered while building the server). So the displayed information lags behind actual activity. However, current-query information collected by track_activities is always up-to-date. Another important point is that when a server process is asked to display any of these statistics, it first fetches the most recent report emitted by the collector process and then continues to use this snapshot for all statistical views and functions until the end of its current transaction. So the statistics will show static information as long as you continue the current transaction. Similarly, information about the current queries of all sessions is collected when any such information is first requested within a transaction, and the same information will be displayed throughout the transaction. This is a feature, not a bug, because it allows you to perform several queries on the statistics and correlate the results without worrying that the numbers are changing underneath you. But if you want to see new results with each query, be sure to do the queries outside any transaction block. Alternatively, you can invoke pg_stat_clear_snapshot(), which will discard the current transaction's statistics snapshot (if any). The next use of statistical information will cause a new snapshot to be fetched. Standard Statistics Views View Name Description pg_stat_activity One row per server process, showing database OID, database name, process ID, user OID, user name, application name, current query, query's waiting status, time at which the current transaction and current query began execution, time at which the process was started, and client's address and port number. The columns that report data on the current query are available unless the parameter track_activities has been turned off. Furthermore, these columns are only visible if the user examining the view is a superuser or the same as the user owning the process being reported on. pg_stat_bgwriter One row only, showing cluster-wide statistics from the background writer: number of scheduled checkpoints, requested checkpoints, buffers written by checkpoints and cleaning scans, and the number of times the background writer stopped a cleaning scan because it had written too many buffers. Also includes statistics about the shared buffer pool, including buffers written by backends (that is, not by the background writer) and total buffers allocated. pg_stat_database One row per database, showing database OID, database name, number of active server processes connected to that database, number of transactions committed and rolled back in that database, total disk blocks read, total buffer hits (i.e., block read requests avoided by finding the block already in buffer cache), number of rows returned, fetched, inserted, updated and deleted. pg_stat_all_tables For each table in the current database (including TOAST tables), the table OID, schema and table name, number of sequential scans initiated, number of live rows fetched by sequential scans, number of index scans initiated (over all indexes belonging to the table), number of live rows fetched by index scans, numbers of row insertions, updates, and deletions, number of row updates that were HOT (i.e., no separate index update), numbers of live and dead rows, the last time the table was vacuumed manually, the last time it was vacuumed by the autovacuum daemon, the last time it was analyzed manually, and the last time it was analyzed by the autovacuum daemon. pg_stat_sys_tables Same as pg_stat_all_tables, except that only system tables are shown. pg_stat_user_tables Same as pg_stat_all_tables, except that only user tables are shown. pg_stat_all_indexes For each index in the current database, the table and index OID, schema, table and index name, number of index scans initiated on that index, number of index entries returned by index scans, and number of live table rows fetched by simple index scans using that index. pg_stat_sys_indexes Same as pg_stat_all_indexes, except that only indexes on system tables are shown. pg_stat_user_indexes Same as pg_stat_all_indexes, except that only indexes on user tables are shown. pg_statio_all_tables For each table in the current database (including TOAST tables), the table OID, schema and table name, number of disk blocks read from that table, number of buffer hits, numbers of disk blocks read and buffer hits in all indexes of that table, numbers of disk blocks read and buffer hits from that table's auxiliary TOAST table (if any), and numbers of disk blocks read and buffer hits for the TOAST table's index. pg_statio_sys_tables Same as pg_statio_all_tables, except that only system tables are shown. pg_statio_user_tables Same as pg_statio_all_tables, except that only user tables are shown. pg_statio_all_indexes For each index in the current database, the table and index OID, schema, table and index name, numbers of disk blocks read and buffer hits in that index. pg_statio_sys_indexes Same as pg_statio_all_indexes, except that only indexes on system tables are shown. pg_statio_user_indexes Same as pg_statio_all_indexes, except that only indexes on user tables are shown. pg_statio_all_sequences For each sequence object in the current database, the sequence OID, schema and sequence name, numbers of disk blocks read and buffer hits in that sequence. pg_statio_sys_sequences Same as pg_statio_all_sequences, except that only system sequences are shown. (Presently, no system sequences are defined, so this view is always empty.) pg_statio_user_sequences Same as pg_statio_all_sequences, except that only user sequences are shown. pg_stat_user_functions For all tracked functions, function OID, schema, name, number of calls, total time, and self time. Self time is the amount of time spent in the function itself, total time includes the time spent in functions it called. Time values are in milliseconds.
The per-index statistics are particularly useful to determine which indexes are being used and how effective they are. Beginning in PostgreSQL 8.1, indexes can be used either directly or via bitmap scans. In a bitmap scan the output of several indexes can be combined via AND or OR rules; so it is difficult to associate individual heap row fetches with specific indexes when a bitmap scan is used. Therefore, a bitmap scan increments the pg_stat_all_indexes.idx_tup_read count(s) for the index(es) it uses, and it increments the pg_stat_all_tables.idx_tup_fetch count for the table, but it does not affect pg_stat_all_indexes.idx_tup_fetch. Before PostgreSQL 8.1, the idx_tup_read and idx_tup_fetch counts were essentially always equal. Now they can be different even without considering bitmap scans, because idx_tup_read counts index entries retrieved from the index while idx_tup_fetch counts live rows fetched from the table; the latter will be less if any dead or not-yet-committed rows are fetched using the index. The pg_statio_ views are primarily useful to determine the effectiveness of the buffer cache. When the number of actual disk reads is much smaller than the number of buffer hits, then the cache is satisfying most read requests without invoking a kernel call. However, these statistics do not give the entire story: due to the way in which PostgreSQL handles disk I/O, data that is not in the PostgreSQL buffer cache might still reside in the kernel's I/O cache, and might therefore still be fetched without requiring a physical read. Users interested in obtaining more detailed information on PostgreSQL I/O behavior are advised to use the PostgreSQL statistics collector in combination with operating system utilities that allow insight into the kernel's handling of I/O. Other ways of looking at the statistics can be set up by writing queries that use the same underlying statistics access functions as these standard views do. These functions are listed in . The per-database access functions take a database OID as argument to identify which database to report on. The per-table and per-index functions take a table or index OID. The functions for function-call statistics take a function OID. (Note that only tables, indexes, and functions in the current database can be seen with these functions.) The per-server-process access functions take a server process number, which ranges from one to the number of currently active server processes. Statistics Access Functions Function Return Type Description pg_stat_get_db_numbackends(oid) integer Number of active server processes for database pg_stat_get_db_xact_commit(oid) bigint Transactions committed in database pg_stat_get_db_xact_rollback(oid) bigint Transactions rolled back in database pg_stat_get_db_blocks_fetched(oid) bigint Number of disk block fetch requests for database pg_stat_get_db_blocks_hit(oid) bigint Number of disk block fetch requests found in cache for database pg_stat_get_db_tuples_returned(oid) bigint Number of tuples returned for database pg_stat_get_db_tuples_fetched(oid) bigint Number of tuples fetched for database pg_stat_get_db_tuples_inserted(oid) bigint Number of tuples inserted in database pg_stat_get_db_tuples_updated(oid) bigint Number of tuples updated in database pg_stat_get_db_tuples_deleted(oid) bigint Number of tuples deleted in database pg_stat_get_numscans(oid) bigint Number of sequential scans done when argument is a table, or number of index scans done when argument is an index pg_stat_get_tuples_returned(oid) bigint Number of rows read by sequential scans when argument is a table, or number of index entries returned when argument is an index pg_stat_get_tuples_fetched(oid) bigint Number of table rows fetched by bitmap scans when argument is a table, or table rows fetched by simple index scans using the index when argument is an index pg_stat_get_tuples_inserted(oid) bigint Number of rows inserted into table pg_stat_get_tuples_updated(oid) bigint Number of rows updated in table (includes HOT updates) pg_stat_get_tuples_deleted(oid) bigint Number of rows deleted from table pg_stat_get_tuples_hot_updated(oid) bigint Number of rows HOT-updated in table pg_stat_get_live_tuples(oid) bigint Number of live rows in table pg_stat_get_dead_tuples(oid) bigint Number of dead rows in table pg_stat_get_blocks_fetched(oid) bigint Number of disk block fetch requests for table or index pg_stat_get_blocks_hit(oid) bigint Number of disk block requests found in cache for table or index pg_stat_get_last_vacuum_time(oid) timestamptz Time of the last vacuum initiated by the user on this table pg_stat_get_last_autovacuum_time(oid) timestamptz Time of the last vacuum initiated by the autovacuum daemon on this table pg_stat_get_last_analyze_time(oid) timestamptz Time of the last analyze initiated by the user on this table pg_stat_get_last_autoanalyze_time(oid) timestamptz Time of the last analyze initiated by the autovacuum daemon on this table pg_backend_pid() integer Process ID of the server process attached to the current session pg_stat_get_activity(integer) setof record Returns a record of information about the backend with the specified pid, or one record for each active backend in the system if NULL is specified. The fields returned are the same as in the pg_stat_activity view pg_stat_get_function_calls(oid) bigint Number of times the function has been called. pg_stat_get_function_time(oid) bigint Total wall clock time spent in the function, in microseconds. Includes the time spent in functions called by this one. pg_stat_get_function_self_time(oid) bigint Time spent in only this function. Time spent in called functions is excluded. pg_stat_get_backend_idset() setof integer Set of currently active server process numbers (from 1 to the number of active server processes). See usage example in the text pg_stat_get_backend_pid(integer) integer Process ID of the given server process pg_stat_get_backend_dbid(integer) oid Database ID of the given server process pg_stat_get_backend_userid(integer) oid User ID of the given server process pg_stat_get_backend_activity(integer) text Active command of the given server process, but only if the current user is a superuser or the same user as that of the session being queried (and track_activities is on) pg_stat_get_backend_waiting(integer) boolean True if the given server process is waiting for a lock, but only if the current user is a superuser or the same user as that of the session being queried (and track_activities is on) pg_stat_get_backend_activity_start(integer) timestamp with time zone The time at which the given server process' currently executing query was started, but only if the current user is a superuser or the same user as that of the session being queried (and track_activities is on) pg_stat_get_backend_xact_start(integer) timestamp with time zone The time at which the given server process' currently executing transaction was started, but only if the current user is a superuser or the same user as that of the session being queried (and track_activities is on) pg_stat_get_backend_start(integer) timestamp with time zone The time at which the given server process was started, or null if the current user is not a superuser nor the same user as that of the session being queried pg_stat_get_backend_client_addr(integer) inet The IP address of the client connected to the given server process. Null if the connection is over a Unix domain socket. Also null if the current user is not a superuser nor the same user as that of the session being queried pg_stat_get_backend_client_port(integer) integer The TCP port number of the client connected to the given server process. -1 if the connection is over a Unix domain socket. Null if the current user is not a superuser nor the same user as that of the session being queried pg_stat_get_bgwriter_timed_checkpoints() bigint The number of times the background writer has started timed checkpoints (because the checkpoint_timeout time has expired) pg_stat_get_bgwriter_requested_checkpoints() bigint The number of times the background writer has started checkpoints based on requests from backends because the checkpoint_segments has been exceeded or because the CHECKPOINT command has been issued pg_stat_get_bgwriter_buf_written_checkpoints() bigint The number of buffers written by the background writer during checkpoints pg_stat_get_bgwriter_buf_written_clean() bigint The number of buffers written by the background writer for routine cleaning of dirty pages pg_stat_get_bgwriter_maxwritten_clean() bigint The number of times the background writer has stopped its cleaning scan because it has written more buffers than specified in the bgwriter_lru_maxpages parameter pg_stat_get_buf_written_backend() bigint The number of buffers written by backends because they needed to allocate a new buffer pg_stat_get_buf_alloc() bigint The total number of buffer allocations pg_stat_clear_snapshot() void Discard the current statistics snapshot pg_stat_reset() void Reset all statistics counters for the current database to zero (requires superuser privileges) pg_stat_reset_shared(text) void Reset some of the shared statistics counters for the database cluster to zero (requires superuser privileges). Calling pg_stat_reset_shared('bgwriter') will zero all the values shown by pg_stat_bgwriter. pg_stat_reset_single_table_counters(oid) void Reset statistics for a single table or index in the current database to zero (requires superuser privileges) pg_stat_reset_single_function_counters(oid) void Reset statistics for a single function in the current database to zero (requires superuser privileges)
pg_stat_get_blocks_fetched minus pg_stat_get_blocks_hit gives the number of kernel read() calls issued for the table, index, or database; the number of actual physical reads is usually lower due to kernel-level buffering. The *_blks_read statistics columns use this subtraction, i.e., fetched minus hit. All functions to access information about backends are indexed by backend id number, except pg_stat_get_activity which is indexed by PID. The function pg_stat_get_backend_idset provides a convenient way to generate one row for each active server process. For example, to show the PIDs and current queries of all server processes: SELECT pg_stat_get_backend_pid(s.backendid) AS procpid, pg_stat_get_backend_activity(s.backendid) AS current_query FROM (SELECT pg_stat_get_backend_idset() AS backendid) AS s;
Viewing Locks lock monitoring Another useful tool for monitoring database activity is the pg_locks system table. It allows the database administrator to view information about the outstanding locks in the lock manager. For example, this capability can be used to: View all the locks currently outstanding, all the locks on relations in a particular database, all the locks on a particular relation, or all the locks held by a particular PostgreSQL session. Determine the relation in the current database with the most ungranted locks (which might be a source of contention among database clients). Determine the effect of lock contention on overall database performance, as well as the extent to which contention varies with overall database traffic. Details of the pg_locks view appear in . For more information on locking and managing concurrency with PostgreSQL, refer to . Dynamic Tracing DTrace PostgreSQL provides facilities to support dynamic tracing of the database server. This allows an external utility to be called at specific points in the code and thereby trace execution. A number of probes or trace points are already inserted into the source code. These probes are intended to be used by database developers and administrators. By default the probes are not compiled into PostgreSQL; the user needs to explicitly tell the configure script to make the probes available. Currently, only the DTrace utility is supported, which is available on OpenSolaris, Solaris 10, and Mac OS X Leopard. It is expected that DTrace will be available in the future on FreeBSD and possibly other operating systems. The SystemTap project for Linux also provides a DTrace equivalent. Supporting other dynamic tracing utilities is theoretically possible by changing the definitions for the macros in src/include/utils/probes.h. Compiling for Dynamic Tracing By default, probes are not available, so you will need to explicitly tell the configure script to make the probes available in PostgreSQL. To include DTrace support specify Built-in Probes A number of standard probes are provided in the source code, as shown in . More can certainly be added to enhance PostgreSQL's observability. Built-in DTrace Probes Name Parameters Description transaction-start (LocalTransactionId) Probe that fires at the start of a new transaction. arg0 is the transaction id. transaction-commit (LocalTransactionId) Probe that fires when a transaction completes successfully. arg0 is the transaction id. transaction-abort (LocalTransactionId) Probe that fires when a transaction completes unsuccessfully. arg0 is the transaction id. query-start (const char *) Probe that fires when the processing of a query is started. arg0 is the query string. query-done (const char *) Probe that fires when the processing of a query is complete. arg0 is the query string. query-parse-start (const char *) Probe that fires when the parsing of a query is started. arg0 is the query string. query-parse-done (const char *) Probe that fires when the parsing of a query is complete. arg0 is the query string. query-rewrite-start (const char *) Probe that fires when the rewriting of a query is started. arg0 is the query string. query-rewrite-done (const char *) Probe that fires when the rewriting of a query is complete. arg0 is the query string. query-plan-start () Probe that fires when the planning of a query is started. query-plan-done () Probe that fires when the planning of a query is complete. query-execute-start () Probe that fires when the execution of a query is started. query-execute-done () Probe that fires when the execution of a query is complete. statement-status (const char *) Probe that fires anytime the server process updates its pg_stat_activity.current_query status. arg0 is the new status string. checkpoint-start (int) Probe that fires when a checkpoint is started. arg0 holds the bitwise flags used to distinguish different checkpoint types, such as shutdown, immediate or force. checkpoint-done (int, int, int, int, int) Probe that fires when a checkpoint is complete. (The probes listed next fire in sequence during checkpoint processing.) arg0 is the number of buffers written. arg1 is the total number of buffers. arg2, arg3 and arg4 contain the number of xlog file(s) added, removed and recycled respectively. clog-checkpoint-start (bool) Probe that fires when the CLOG portion of a checkpoint is started. arg0 is true for normal checkpoint, false for shutdown checkpoint. clog-checkpoint-done (bool) Probe that fires when the CLOG portion of a checkpoint is complete. arg0 has the same meaning as for clog-checkpoint-start. subtrans-checkpoint-start (bool) Probe that fires when the SUBTRANS portion of a checkpoint is started. arg0 is true for normal checkpoint, false for shutdown checkpoint. subtrans-checkpoint-done (bool) Probe that fires when the SUBTRANS portion of a checkpoint is complete. arg0 has the same meaning as for subtrans-checkpoint-start. multixact-checkpoint-start (bool) Probe that fires when the MultiXact portion of a checkpoint is started. arg0 is true for normal checkpoint, false for shutdown checkpoint. multixact-checkpoint-done (bool) Probe that fires when the MultiXact portion of a checkpoint is complete. arg0 has the same meaning as for multixact-checkpoint-start. buffer-checkpoint-start (int) Probe that fires when the buffer-writing portion of a checkpoint is started. arg0 holds the bitwise flags used to distinguish different checkpoint types, such as shutdown, immediate or force. buffer-sync-start (int, int) Probe that fires when we begin to write dirty buffers during checkpoint (after identifying which buffers must be written). arg0 is the total number of buffers. arg1 is the number that are currently dirty and need to be written. buffer-sync-written (int) Probe that fires after each buffer is written during checkpoint. arg0 is the ID number of the buffer. buffer-sync-done (int, int, int) Probe that fires when all dirty buffers have been written. arg0 is the total number of buffers. arg1 is the number of buffers actually written by the checkpoint process. arg2 is the number that were expected to be written (arg1 of buffer-sync-start); any difference reflects other processes flushing buffers during the checkpoint. buffer-checkpoint-sync-start () Probe that fires after dirty buffers have been written to the kernel, and before starting to issue fsync requests. buffer-checkpoint-done () Probe that fires when syncing of buffers to disk is complete. twophase-checkpoint-start () Probe that fires when the two-phase portion of a checkpoint is started. twophase-checkpoint-done () Probe that fires when the two-phase portion of a checkpoint is complete. buffer-read-start (ForkNumber, BlockNumber, Oid, Oid, Oid, bool, bool) Probe that fires when a buffer read is started. arg0 and arg1 contain the fork and block numbers of the page (but arg1 will be -1 if this is a relation extension request). arg2, arg3, and arg4 contain the tablespace, database, and relation OIDs identifying the relation. arg5 is true for a local buffer, false for a shared buffer. arg6 is true for a relation extension request, false for normal read. buffer-read-done (ForkNumber, BlockNumber, Oid, Oid, Oid, bool, bool, bool) Probe that fires when a buffer read is complete. arg0 and arg1 contain the fork and block numbers of the page (if this is a relation extension request, arg1 now contains the block number of the newly added block). arg2, arg3, and arg4 contain the tablespace, database, and relation OIDs identifying the relation. arg5 is true for a local buffer, false for a shared buffer. arg6 is true for a relation extension request, false for normal read. arg7 is true if the buffer was found in the pool, false if not. buffer-flush-start (ForkNumber, BlockNumber, Oid, Oid, Oid) Probe that fires before issuing any write request for a shared buffer. arg0 and arg1 contain the fork and block numbers of the page. arg2, arg3, and arg4 contain the tablespace, database, and relation OIDs identifying the relation. buffer-flush-done (ForkNumber, BlockNumber, Oid, Oid, Oid) Probe that fires when a write request is complete. (Note that this just reflects the time to pass the data to the kernel; it's typically not actually been written to disk yet.) The arguments are the same as for buffer-flush-start. buffer-write-dirty-start (ForkNumber, BlockNumber, Oid, Oid, Oid) Probe that fires when a server process begins to write a dirty buffer. (If this happens often, it implies that is too small or the bgwriter control parameters need adjustment.) arg0 and arg1 contain the fork and block numbers of the page. arg2, arg3, and arg4 contain the tablespace, database, and relation OIDs identifying the relation. buffer-write-dirty-done (ForkNumber, BlockNumber, Oid, Oid, Oid) Probe that fires when a dirty-buffer write is complete. The arguments are the same as for buffer-write-dirty-start. wal-buffer-write-dirty-start () Probe that fires when when a server process begins to write a dirty WAL buffer because no more WAL buffer space is available. (If this happens often, it implies that is too small.) wal-buffer-write-dirty-done () Probe that fires when a dirty WAL buffer write is complete. xlog-insert (unsigned char, unsigned char) Probe that fires when a WAL record is inserted. arg0 is the resource manager (rmid) for the record. arg1 contains the info flags. xlog-switch () Probe that fires when a WAL segment switch is requested. smgr-md-read-start (ForkNumber, BlockNumber, Oid, Oid, Oid) Probe that fires when beginning to read a block from a relation. arg0 and arg1 contain the fork and block numbers of the page. arg2, arg3, and arg4 contain the tablespace, database, and relation OIDs identifying the relation. smgr-md-read-done (ForkNumber, BlockNumber, Oid, Oid, Oid, int, int) Probe that fires when a block read is complete. arg0 and arg1 contain the fork and block numbers of the page. arg2, arg3, and arg4 contain the tablespace, database, and relation OIDs identifying the relation. arg5 is the number of bytes actually read, while arg6 is the number requested (if these are different it indicates trouble). smgr-md-write-start (ForkNumber, BlockNumber, Oid, Oid, Oid) Probe that fires when beginning to write a block to a relation. arg0 and arg1 contain the fork and block numbers of the page. arg2, arg3, and arg4 contain the tablespace, database, and relation OIDs identifying the relation. smgr-md-write-done (ForkNumber, BlockNumber, Oid, Oid, Oid, int, int) Probe that fires when a block write is complete. arg0 and arg1 contain the fork and block numbers of the page. arg2, arg3, and arg4 contain the tablespace, database, and relation OIDs identifying the relation. arg5 is the number of bytes actually written, while arg6 is the number requested (if these are different it indicates trouble). sort-start (int, bool, int, int, bool) Probe that fires when a sort operation is started. arg0 indicates heap, index or datum sort. arg1 is true for unique-value enforcement. arg2 is the number of key columns. arg3 is the number of kilobytes of work memory allowed. arg4 is true if random access to the sort result is required. sort-done (bool, long) Probe that fires when a sort is complete. arg0 is true for external sort, false for internal sort. arg1 is the number of disk blocks used for an external sort, or kilobytes of memory used for an internal sort. lwlock-acquire (LWLockId, LWLockMode) Probe that fires when an LWLock has been acquired. arg0 is the LWLock's ID. arg1 is the requested lock mode, either exclusive or shared. lwlock-release (LWLockId) Probe that fires when an LWLock has been released (but note that any released waiters have not yet been awakened). arg0 is the LWLock's ID. lwlock-wait-start (LWLockId, LWLockMode) Probe that fires when an LWLock was not immediately available and a server process has begun to wait for the lock to become available. arg0 is the LWLock's ID. arg1 is the requested lock mode, either exclusive or shared. lwlock-wait-done (LWLockId, LWLockMode) Probe that fires when a server process has been released from its wait for an LWLock (it does not actually have the lock yet). arg0 is the LWLock's ID. arg1 is the requested lock mode, either exclusive or shared. lwlock-condacquire (LWLockId, LWLockMode) Probe that fires when an LWLock was successfully acquired when the caller specified no waiting. arg0 is the LWLock's ID. arg1 is the requested lock mode, either exclusive or shared. lwlock-condacquire-fail (LWLockId, LWLockMode) Probe that fires when an LWLock was not successfully acquired when the caller specified no waiting. arg0 is the LWLock's ID. arg1 is the requested lock mode, either exclusive or shared. lock-wait-start (unsigned int, unsigned int, unsigned int, unsigned int, unsigned int, LOCKMODE) Probe that fires when a request for a heavyweight lock (lmgr lock) has begun to wait because the lock is not available. arg0 through arg3 are the tag fields identifying the object being locked. arg4 indicates the type of object being locked. arg5 indicates the lock type being requested. lock-wait-done (unsigned int, unsigned int, unsigned int, unsigned int, unsigned int, LOCKMODE) Probe that fires when a request for a heavyweight lock (lmgr lock) has finished waiting (i.e., has acquired the lock). The arguments are the same as for lock-wait-start. deadlock-found () Probe that fires when a deadlock is found by the deadlock detector.
Defined Types Used in Probe Parameters Type Definition LocalTransactionId unsigned int LWLockId int LWLockMode int LOCKMODE int BlockNumber unsigned int Oid unsigned int ForkNumber int bool char
Using Probes The example below shows a DTrace script for analyzing transaction counts in the system, as an alternative to snapshotting pg_stat_database before and after a performance test: #!/usr/sbin/dtrace -qs postgresql$1:::transaction-start { @start["Start"] = count(); self->ts = timestamp; } postgresql$1:::transaction-abort { @abort["Abort"] = count(); } postgresql$1:::transaction-commit /self->ts/ { @commit["Commit"] = count(); @time["Total time (ns)"] = sum(timestamp - self->ts); self->ts=0; } When executed, the example D script gives output such as: # ./txn_count.d `pgrep -n postgres` or ./txn_count.d <PID> ^C Start 71 Commit 70 Total time (ns) 2312105013 SystemTap uses a different notation for trace scripts than DTrace does, even though the underlying trace points are compatible. One point worth noting is that at this writing, SystemTap scripts must reference probe names using double underscores in place of hyphens. This is expected to be fixed in future SystemTap releases. You should remember that DTrace scripts need to be carefully written and debugged, otherwise the trace information collected might be meaningless. In most cases where problems are found it is the instrumentation that is at fault, not the underlying system. When discussing information found using dynamic tracing, be sure to enclose the script used to allow that too to be checked and discussed. More example scripts can be found in the PgFoundry dtrace project. Defining New Probes New probes can be defined within the code wherever the developer desires, though this will require a recompilation. Below are the steps for inserting new probes: Decide on probe names and data to be made available through the probes Add the probe definitions to src/backend/utils/probes.d Include pg_trace.h if it is not already present in the module(s) containing the probe points, and insert TRACE_POSTGRESQL probe macros at the desired locations in the source code Recompile and verify that the new probes are available Example: Here is an example of how you would add a probe to trace all new transactions by transaction ID. Decide that the probe will be named transaction-start and requires a parameter of type LocalTransactionId Add the probe definition to src/backend/utils/probes.d: probe transaction__start(LocalTransactionId); Note the use of the double underline in the probe name. In a DTrace script using the probe, the double underline needs to be replaced with a hyphen, so transaction-start is the name to document for users. At compile time, transaction__start is converted to a macro called TRACE_POSTGRESQL_TRANSACTION_START (notice the underscores are single here), which is available by including pg_trace.h. Add the macro call to the appropriate location in the source code. In this case, it looks like the following: TRACE_POSTGRESQL_TRANSACTION_START(vxid.localTransactionId); After recompiling and running the new binary, check that your newly added probe is available by executing the following DTrace command. You should see similar output: # dtrace -ln transaction-start ID PROVIDER MODULE FUNCTION NAME 18705 postgresql49878 postgres StartTransactionCommand transaction-start 18755 postgresql49877 postgres StartTransactionCommand transaction-start 18805 postgresql49876 postgres StartTransactionCommand transaction-start 18855 postgresql49875 postgres StartTransactionCommand transaction-start 18986 postgresql49873 postgres StartTransactionCommand transaction-start There are a few things to be careful about when adding trace macros to the C code: You should take care that the data types specified for a probe's parameters match the data types of the variables used in the macro. Otherwise, you will get compilation errors. On most platforms, if PostgreSQL is built with