*** a/contrib/pg_stat_statements/pg_stat_statements--1.0--1.1.sql
--- b/contrib/pg_stat_statements/pg_stat_statements--1.0--1.1.sql
***************
*** 17,22 **** CREATE FUNCTION pg_stat_statements(
--- 17,23 ----
OUT dbid oid,
OUT query text,
OUT calls int8,
+ OUT plan_time float8,
OUT total_time float8,
OUT rows int8,
OUT shared_blks_hit int8,
*** a/contrib/pg_stat_statements/pg_stat_statements--1.1.sql
--- b/contrib/pg_stat_statements/pg_stat_statements--1.1.sql
***************
*** 14,19 **** CREATE FUNCTION pg_stat_statements(
--- 14,20 ----
OUT dbid oid,
OUT query text,
OUT calls int8,
+ OUT plan_time float8,
OUT total_time float8,
OUT rows int8,
OUT shared_blks_hit int8,
*** a/contrib/pg_stat_statements/pg_stat_statements.c
--- b/contrib/pg_stat_statements/pg_stat_statements.c
***************
*** 1,7 ****
/*-------------------------------------------------------------------------
*
* pg_stat_statements.c
! * Track statement execution times across a whole database cluster.
*
* Note about locking issues: to create or delete an entry in the shared
* hashtable, one must hold pgss->lock exclusively. Modifying any field
--- 1,7 ----
/*-------------------------------------------------------------------------
*
* pg_stat_statements.c
! * Track statement planning and execution times across a whole database cluster.
*
* Note about locking issues: to create or delete an entry in the shared
* hashtable, one must hold pgss->lock exclusively. Modifying any field
***************
*** 27,32 ****
--- 27,33 ----
#include "funcapi.h"
#include "mb/pg_wchar.h"
#include "miscadmin.h"
+ #include "optimizer/planner.h"
#include "pgstat.h"
#include "storage/fd.h"
#include "storage/ipc.h"
***************
*** 73,78 **** typedef struct pgssHashKey
--- 74,80 ----
typedef struct Counters
{
int64 calls; /* # of times executed */
+ double plan_time; /* total planning time in seconds */
double total_time; /* total execution time in seconds */
int64 rows; /* total # of retrieved or affected rows */
int64 shared_blks_hit; /* # of shared buffer hits */
***************
*** 118,123 **** static int nested_level = 0;
--- 120,126 ----
/* Saved hook values in case of unload */
static shmem_startup_hook_type prev_shmem_startup_hook = NULL;
+ static planner_hook_type prev_planner_hook = NULL;
static ExecutorStart_hook_type prev_ExecutorStart = NULL;
static ExecutorRun_hook_type prev_ExecutorRun = NULL;
static ExecutorFinish_hook_type prev_ExecutorFinish = NULL;
***************
*** 168,173 **** PG_FUNCTION_INFO_V1(pg_stat_statements);
--- 171,178 ----
static void pgss_shmem_startup(void);
static void pgss_shmem_shutdown(int code, Datum arg);
+ static PlannedStmt *pgss_planner(Query *parse, int cursorOptions,
+ ParamListInfo boundParams);
static void pgss_ExecutorStart(QueryDesc *queryDesc, int eflags);
static void pgss_ExecutorRun(QueryDesc *queryDesc,
ScanDirection direction,
***************
*** 179,186 **** 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,
! const BufferUsage *bufusage);
static Size pgss_memsize(void);
static pgssEntry *entry_alloc(pgssHashKey *key);
static void entry_dealloc(void);
--- 184,191 ----
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 plan_time, double total_time,
! uint64 rows, const BufferUsage *bufusage);
static Size pgss_memsize(void);
static pgssEntry *entry_alloc(pgssHashKey *key);
static void entry_dealloc(void);
***************
*** 269,274 **** _PG_init(void)
--- 274,281 ----
*/
prev_shmem_startup_hook = shmem_startup_hook;
shmem_startup_hook = pgss_shmem_startup;
+ prev_planner_hook = planner_hook;
+ planner_hook = pgss_planner;
prev_ExecutorStart = ExecutorStart_hook;
ExecutorStart_hook = pgss_ExecutorStart;
prev_ExecutorRun = ExecutorRun_hook;
***************
*** 289,294 **** _PG_fini(void)
--- 296,302 ----
{
/* Uninstall hooks. */
shmem_startup_hook = prev_shmem_startup_hook;
+ planner_hook = prev_planner_hook;
ExecutorStart_hook = prev_ExecutorStart;
ExecutorRun_hook = prev_ExecutorRun;
ExecutorFinish_hook = prev_ExecutorFinish;
***************
*** 505,510 **** error:
--- 513,565 ----
}
/*
+ * planner hook
+ */
+ static PlannedStmt *
+ pgss_planner(Query *parse, int cursorOptions, ParamListInfo boundParams)
+ {
+ PlannedStmt *result;
+
+ if (pgss_enabled())
+ {
+ instr_time start;
+ instr_time duration;
+
+ INSTR_TIME_SET_CURRENT(start);
+
+ nested_level++;
+ PG_TRY();
+ {
+ if (prev_planner_hook)
+ result = prev_planner_hook(parse, cursorOptions, boundParams);
+ else
+ result = standard_planner(parse, cursorOptions, boundParams);
+ nested_level--;
+ }
+ PG_CATCH();
+ {
+ nested_level--;
+ PG_RE_THROW();
+ }
+ PG_END_TRY();
+
+ INSTR_TIME_SET_CURRENT(duration);
+ INSTR_TIME_SUBTRACT(duration, start);
+
+ result->plan_time = INSTR_TIME_GET_DOUBLE(duration);
+ }
+ else
+ {
+ if (prev_planner_hook)
+ result = prev_planner_hook(parse, cursorOptions, boundParams);
+ else
+ result = standard_planner(parse, cursorOptions, boundParams);
+ }
+
+ return result;
+ }
+
+ /*
* ExecutorStart hook: start up tracking if needed
*/
static void
***************
*** 594,599 **** pgss_ExecutorEnd(QueryDesc *queryDesc)
--- 649,655 ----
InstrEndLoop(queryDesc->totaltime);
pgss_store(queryDesc->sourceText,
+ queryDesc->plannedstmt->plan_time,
queryDesc->totaltime->total,
queryDesc->estate->es_processed,
&queryDesc->totaltime->bufusage);
***************
*** 671,677 **** pgss_ProcessUtility(Node *parsetree, const char *queryString,
bufusage.temp_blks_written =
pgBufferUsage.temp_blks_written - bufusage.temp_blks_written;
! pgss_store(queryString, INSTR_TIME_GET_DOUBLE(duration), rows,
&bufusage);
}
else
--- 727,734 ----
bufusage.temp_blks_written =
pgBufferUsage.temp_blks_written - bufusage.temp_blks_written;
! /* planning time is always 0 because utility commands have no plans */
! pgss_store(queryString, 0, INSTR_TIME_GET_DOUBLE(duration), rows,
&bufusage);
}
else
***************
*** 723,730 **** 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,
! const BufferUsage *bufusage)
{
pgssHashKey key;
double usage;
--- 780,787 ----
* Store some statistics for a statement.
*/
static void
! pgss_store(const char *query, double plan_time, double total_time,
! uint64 rows, const BufferUsage *bufusage)
{
pgssHashKey key;
double usage;
***************
*** 768,773 **** pgss_store(const char *query, double total_time, uint64 rows,
--- 825,831 ----
SpinLockAcquire(&e->mutex);
e->counters.calls += 1;
+ e->counters.plan_time += plan_time;
e->counters.total_time += total_time;
e->counters.rows += rows;
e->counters.shared_blks_hit += bufusage->shared_blks_hit;
***************
*** 802,808 **** pg_stat_statements_reset(PG_FUNCTION_ARGS)
}
#define PG_STAT_STATEMENTS_COLS_V1_0 14
! #define PG_STAT_STATEMENTS_COLS 16
/*
* Retrieve statement statistics.
--- 860,866 ----
}
#define PG_STAT_STATEMENTS_COLS_V1_0 14
! #define PG_STAT_STATEMENTS_COLS 17
/*
* Retrieve statement statistics.
***************
*** 895,900 **** pg_stat_statements(PG_FUNCTION_ARGS)
--- 953,959 ----
}
values[i++] = Int64GetDatumFast(tmp.calls);
+ values[i++] = Float8GetDatumFast(tmp.plan_time);
values[i++] = Float8GetDatumFast(tmp.total_time);
values[i++] = Int64GetDatumFast(tmp.rows);
values[i++] = Int64GetDatumFast(tmp.shared_blks_hit);
*** a/doc/src/sgml/pgstatstatements.sgml
--- b/doc/src/sgml/pgstatstatements.sgml
***************
*** 9,15 ****
The pg_stat_statements module provides a means for
! tracking execution statistics of all SQL statements executed by a server.
--- 9,15 ----
The pg_stat_statements module provides a means for
! tracking planning and execution statistics of all SQL statements executed by a server.
***************
*** 72,81 ****
total_time
double precision
! Total time spent in the statement, in seconds
--- 72,88 ----
+ plan_time
+ double precision
+
+ Total planning time spent in the statement, in seconds
+
+
+
total_time
double precision
! Total execution time spent in the statement, in seconds
*** a/src/backend/nodes/copyfuncs.c
--- b/src/backend/nodes/copyfuncs.c
***************
*** 93,98 **** _copyPlannedStmt(const PlannedStmt *from)
--- 93,99 ----
COPY_NODE_FIELD(relationOids);
COPY_NODE_FIELD(invalItems);
COPY_SCALAR_FIELD(nParamExec);
+ COPY_SCALAR_FIELD(plan_time);
return newnode;
}
*** a/src/backend/nodes/outfuncs.c
--- b/src/backend/nodes/outfuncs.c
***************
*** 257,262 **** _outPlannedStmt(StringInfo str, const PlannedStmt *node)
--- 257,263 ----
WRITE_NODE_FIELD(relationOids);
WRITE_NODE_FIELD(invalItems);
WRITE_INT_FIELD(nParamExec);
+ WRITE_FLOAT_FIELD(plan_time, "%.0f");
}
/*
*** a/src/backend/optimizer/plan/planner.c
--- b/src/backend/optimizer/plan/planner.c
***************
*** 240,245 **** standard_planner(Query *parse, int cursorOptions, ParamListInfo boundParams)
--- 240,246 ----
result->relationOids = glob->relationOids;
result->invalItems = glob->invalItems;
result->nParamExec = list_length(glob->paramlist);
+ result->plan_time = 0;
return result;
}
*** a/src/include/nodes/plannodes.h
--- b/src/include/nodes/plannodes.h
***************
*** 67,72 **** typedef struct PlannedStmt
--- 67,75 ----
List *invalItems; /* other dependencies, as PlanInvalItems */
int nParamExec; /* number of PARAM_EXEC Params used */
+
+ /* This is always set 0 by the core system, but plugins can change it */
+ double plan_time; /* total time spent in planner */
} PlannedStmt;
/* macro for fetching the Plan associated with a SubPlan node */