From 8964dbd51e4e3e7ea179f85b46ce52715383d869 Mon Sep 17 00:00:00 2001 From: Itagaki Takahiro Date: Fri, 8 Jan 2010 00:38:20 +0000 Subject: [PATCH] Add buffer access counters to pg_stat_statements. This uses the same infrastructure with EXPLAIN BUFFERS to support {shared|local}_blks_{hit|read|written} andtemp_blks_{read|written} columns in the pg_stat_statements view. The dumped file format also updated. Thanks to Robert Haas for the review. --- .../pg_stat_statements/pg_stat_statements.c | 92 ++++++++++---- .../pg_stat_statements.sql.in | 12 +- doc/src/sgml/pgstatstatements.sgml | 120 ++++++++++++++---- 3 files changed, 169 insertions(+), 55 deletions(-) diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c index 75fda12452..11dfb6280a 100644 --- a/contrib/pg_stat_statements/pg_stat_statements.c +++ b/contrib/pg_stat_statements/pg_stat_statements.c @@ -14,7 +14,7 @@ * Copyright (c) 2008-2010, PostgreSQL Global Development Group * * IDENTIFICATION - * $PostgreSQL: pgsql/contrib/pg_stat_statements/pg_stat_statements.c,v 1.11 2010/01/02 16:57:32 momjian Exp $ + * $PostgreSQL: pgsql/contrib/pg_stat_statements/pg_stat_statements.c,v 1.12 2010/01/08 00:38:19 itagaki Exp $ * *------------------------------------------------------------------------- */ @@ -26,6 +26,7 @@ #include "catalog/pg_type.h" #include "executor/executor.h" #include "executor/instrument.h" +#include "funcapi.h" #include "mb/pg_wchar.h" #include "miscadmin.h" #include "pgstat.h" @@ -44,7 +45,7 @@ PG_MODULE_MAGIC; #define PGSS_DUMP_FILE "global/pg_stat_statements.stat" /* This constant defines the magic number in the stats file header */ -static const uint32 PGSS_FILE_HEADER = 0x20081202; +static const uint32 PGSS_FILE_HEADER = 0x20100108; /* XXX: Should USAGE_EXEC reflect execution time and/or buffer usage? */ #define USAGE_EXEC(duration) (1.0) @@ -75,10 +76,18 @@ typedef struct pgssHashKey */ typedef struct Counters { - int64 calls; /* # of times executed */ - double total_time; /* total execution time in seconds */ - int64 rows; /* total # of retrieved or affected rows */ - double usage; /* usage factor */ + int64 calls; /* # of times executed */ + double total_time; /* total execution time in seconds */ + int64 rows; /* total # of retrieved or affected rows */ + int64 shared_blks_hit; /* # of shared buffer hits */ + int64 shared_blks_read; /* # of shared disk blocks read */ + int64 shared_blks_written;/* # of shared disk blocks written */ + int64 local_blks_hit; /* # of local buffer hits */ + int64 local_blks_read; /* # of local disk blocks read */ + int64 local_blks_written; /* # of local disk blocks written */ + int64 temp_blks_read; /* # of temp blocks read */ + int64 temp_blks_written; /* # of temp blocks written */ + double usage; /* usage factor */ } Counters; /* @@ -129,7 +138,8 @@ typedef enum PGSS_TRACK_ALL /* all statements, including nested ones */ } PGSSTrackLevel; -static const struct config_enum_entry track_options[] = { +static const struct config_enum_entry track_options[] = +{ {"none", PGSS_TRACK_NONE, false}, {"top", PGSS_TRACK_TOP, false}, {"all", PGSS_TRACK_ALL, false}, @@ -169,7 +179,8 @@ static void pgss_ProcessUtility(Node *parsetree, DestReceiver *dest, char *completionTag); static uint32 pgss_hash_fn(const void *key, Size keysize); static int pgss_match_fn(const void *key1, const void *key2, Size keysize); -static void pgss_store(const char *query, double total_time, uint64 rows); +static void pgss_store(const char *query, double total_time, uint64 rows, + const BufferUsage *bufusage); static Size pgss_memsize(void); static pgssEntry *entry_alloc(pgssHashKey *key); static void entry_dealloc(void); @@ -558,7 +569,8 @@ pgss_ExecutorEnd(QueryDesc *queryDesc) pgss_store(queryDesc->sourceText, queryDesc->totaltime->total, - queryDesc->estate->es_processed); + queryDesc->estate->es_processed, + &queryDesc->totaltime->bufusage); } if (prev_ExecutorEnd) @@ -580,7 +592,9 @@ pgss_ProcessUtility(Node *parsetree, const char *queryString, instr_time start; instr_time duration; uint64 rows = 0; + BufferUsage bufusage; + bufusage = pgBufferUsage; INSTR_TIME_SET_CURRENT(start); nested_level++; @@ -609,7 +623,26 @@ pgss_ProcessUtility(Node *parsetree, const char *queryString, sscanf(completionTag, "COPY " UINT64_FORMAT, &rows) != 1) rows = 0; - pgss_store(queryString, INSTR_TIME_GET_DOUBLE(duration), rows); + /* calc differences of buffer counters. */ + bufusage.shared_blks_hit = + pgBufferUsage.shared_blks_hit - bufusage.shared_blks_hit; + bufusage.shared_blks_read = + pgBufferUsage.shared_blks_read - bufusage.shared_blks_read; + bufusage.shared_blks_written = + pgBufferUsage.shared_blks_written - bufusage.shared_blks_written; + bufusage.local_blks_hit = + pgBufferUsage.local_blks_hit - bufusage.local_blks_hit; + bufusage.local_blks_read = + pgBufferUsage.local_blks_read - bufusage.local_blks_read; + bufusage.local_blks_written = + pgBufferUsage.local_blks_written - bufusage.local_blks_written; + bufusage.temp_blks_read = + pgBufferUsage.temp_blks_read - bufusage.temp_blks_read; + bufusage.temp_blks_written = + pgBufferUsage.temp_blks_written - bufusage.temp_blks_written; + + pgss_store(queryString, INSTR_TIME_GET_DOUBLE(duration), rows, + &bufusage); } else { @@ -660,7 +693,8 @@ pgss_match_fn(const void *key1, const void *key2, Size keysize) * Store some statistics for a statement. */ static void -pgss_store(const char *query, double total_time, uint64 rows) +pgss_store(const char *query, double total_time, uint64 rows, + const BufferUsage *bufusage) { pgssHashKey key; double usage; @@ -706,6 +740,14 @@ pgss_store(const char *query, double total_time, uint64 rows) e->counters.calls += 1; e->counters.total_time += total_time; e->counters.rows += rows; + e->counters.shared_blks_hit += bufusage->shared_blks_hit; + e->counters.shared_blks_read += bufusage->shared_blks_read; + e->counters.shared_blks_written += bufusage->shared_blks_written; + e->counters.local_blks_hit += bufusage->local_blks_hit; + e->counters.local_blks_read += bufusage->local_blks_read; + e->counters.local_blks_written += bufusage->local_blks_written; + e->counters.temp_blks_read += bufusage->temp_blks_read; + e->counters.temp_blks_written += bufusage->temp_blks_written; e->counters.usage += usage; SpinLockRelease(&e->mutex); } @@ -727,7 +769,7 @@ pg_stat_statements_reset(PG_FUNCTION_ARGS) PG_RETURN_VOID(); } -#define PG_STAT_STATEMENTS_COLS 6 +#define PG_STAT_STATEMENTS_COLS 14 /* * Retrieve statement statistics. @@ -761,23 +803,13 @@ pg_stat_statements(PG_FUNCTION_ARGS) errmsg("materialize mode required, but it is not " \ "allowed in this context"))); + /* Build a tuple descriptor for our result type */ + if (get_call_result_type(fcinfo, NULL, &tupdesc) != TYPEFUNC_COMPOSITE) + elog(ERROR, "return type must be a row type"); + per_query_ctx = rsinfo->econtext->ecxt_per_query_memory; oldcontext = MemoryContextSwitchTo(per_query_ctx); - tupdesc = CreateTemplateTupleDesc(PG_STAT_STATEMENTS_COLS, false); - TupleDescInitEntry(tupdesc, (AttrNumber) 1, "userid", - OIDOID, -1, 0); - TupleDescInitEntry(tupdesc, (AttrNumber) 2, "dbid", - OIDOID, -1, 0); - TupleDescInitEntry(tupdesc, (AttrNumber) 3, "query", - TEXTOID, -1, 0); - TupleDescInitEntry(tupdesc, (AttrNumber) 4, "calls", - INT8OID, -1, 0); - TupleDescInitEntry(tupdesc, (AttrNumber) 5, "total_time", - FLOAT8OID, -1, 0); - TupleDescInitEntry(tupdesc, (AttrNumber) 6, "rows", - INT8OID, -1, 0); - tupstore = tuplestore_begin_heap(true, false, work_mem); rsinfo->returnMode = SFRM_Materialize; rsinfo->setResult = tupstore; @@ -829,6 +861,14 @@ pg_stat_statements(PG_FUNCTION_ARGS) values[i++] = Int64GetDatumFast(tmp.calls); values[i++] = Float8GetDatumFast(tmp.total_time); values[i++] = Int64GetDatumFast(tmp.rows); + values[i++] = Int64GetDatumFast(tmp.shared_blks_hit); + values[i++] = Int64GetDatumFast(tmp.shared_blks_read); + values[i++] = Int64GetDatumFast(tmp.shared_blks_written); + values[i++] = Int64GetDatumFast(tmp.local_blks_hit); + values[i++] = Int64GetDatumFast(tmp.local_blks_read); + values[i++] = Int64GetDatumFast(tmp.local_blks_written); + values[i++] = Int64GetDatumFast(tmp.temp_blks_read); + values[i++] = Int64GetDatumFast(tmp.temp_blks_written); Assert(i == PG_STAT_STATEMENTS_COLS); diff --git a/contrib/pg_stat_statements/pg_stat_statements.sql.in b/contrib/pg_stat_statements/pg_stat_statements.sql.in index 7655136ed9..cf82a0e3dc 100644 --- a/contrib/pg_stat_statements/pg_stat_statements.sql.in +++ b/contrib/pg_stat_statements/pg_stat_statements.sql.in @@ -1,4 +1,4 @@ -/* $PostgreSQL: pgsql/contrib/pg_stat_statements/pg_stat_statements.sql.in,v 1.1 2009/01/04 22:19:59 tgl Exp $ */ +/* $PostgreSQL: pgsql/contrib/pg_stat_statements/pg_stat_statements.sql.in,v 1.2 2010/01/08 00:38:19 itagaki Exp $ */ -- Adjust this setting to control where the objects get created. SET search_path = public; @@ -15,7 +15,15 @@ CREATE FUNCTION pg_stat_statements( OUT query text, OUT calls int8, OUT total_time float8, - OUT rows int8 + OUT rows int8, + OUT shared_blks_hit int8, + OUT shared_blks_read int8, + OUT shared_blks_written int8, + OUT local_blks_hit int8, + OUT local_blks_read int8, + OUT local_blks_written int8, + OUT temp_blks_read int8, + OUT temp_blks_written int8 ) RETURNS SETOF record AS 'MODULE_PATHNAME' diff --git a/doc/src/sgml/pgstatstatements.sgml b/doc/src/sgml/pgstatstatements.sgml index 470902152f..3bd3d60d76 100644 --- a/doc/src/sgml/pgstatstatements.sgml +++ b/doc/src/sgml/pgstatstatements.sgml @@ -1,4 +1,4 @@ - + pg_stat_statements @@ -85,6 +85,62 @@ Total number of rows retrieved or affected by the statement + + shared_blks_hit + bigint + + Total number of shared blocks hits by the statement + + + + shared_blks_read + bigint + + Total number of shared blocks reads by the statement + + + + shared_blks_written + bigint + + Total number of shared blocks writes by the statement + + + + local_blks_hit + bigint + + Total number of local blocks hits by the statement + + + + local_blks_read + bigint + + Total number of local blocks reads by the statement + + + + local_blks_written + bigint + + Total number of local blocks writes by the statement + + + + temp_blks_read + bigint + + Total number of temp blocks reads by the statement + + + + temp_blks_written + bigint + + Total number of temp blocks writes by the statement + + @@ -239,35 +295,45 @@ pg_stat_statements.track = all Sample output -$ pgbench -i bench - -postgres=# SELECT pg_stat_statements_reset(); +bench=# SELECT pg_stat_statements_reset(); +$ pgbench -i bench $ pgbench -c10 -t300 -M prepared bench -postgres=# \x -postgres=# SELECT * FROM pg_stat_statements ORDER BY total_time DESC LIMIT 3; --[ RECORD 1 ]------------------------------------------------------------ -userid | 10 -dbid | 63781 -query | UPDATE branches SET bbalance = bbalance + $1 WHERE bid = $2; -calls | 3000 -total_time | 20.716706 -rows | 3000 --[ RECORD 2 ]------------------------------------------------------------ -userid | 10 -dbid | 63781 -query | UPDATE tellers SET tbalance = tbalance + $1 WHERE tid = $2; -calls | 3000 -total_time | 17.1107649999999 -rows | 3000 --[ RECORD 3 ]------------------------------------------------------------ -userid | 10 -dbid | 63781 -query | UPDATE accounts SET abalance = abalance + $1 WHERE aid = $2; -calls | 3000 -total_time | 0.645601 -rows | 3000 +bench=# \x +bench=# SELECT query, calls, total_time, rows, 100.0 * shared_blks_hit / + nullif(shared_blks_hit + shared_blks_read, 0) AS hit_percent + FROM pg_stat_statements ORDER BY total_time DESC LIMIT 5; +-[ RECORD 1 ]--------------------------------------------------------------------- +query | UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2; +calls | 3000 +total_time | 9.60900100000002 +rows | 2836 +hit_percent | 99.9778970000200936 +-[ RECORD 2 ]--------------------------------------------------------------------- +query | UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2; +calls | 3000 +total_time | 8.015156 +rows | 2990 +hit_percent | 99.9731126579631345 +-[ RECORD 3 ]--------------------------------------------------------------------- +query | copy pgbench_accounts from stdin +calls | 1 +total_time | 0.310624 +rows | 100000 +hit_percent | 0.30395136778115501520 +-[ RECORD 4 ]--------------------------------------------------------------------- +query | UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2; +calls | 3000 +total_time | 0.271741999999997 +rows | 3000 +hit_percent | 93.7968855088209426 +-[ RECORD 5 ]--------------------------------------------------------------------- +query | alter table pgbench_accounts add primary key (aid) +calls | 1 +total_time | 0.08142 +rows | 0 +hit_percent | 34.4947735191637631 -- 2.40.0