pg_stat_statements_plantime_v1.patch

*** 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 ****
  
   <para>
    The <filename>pg_stat_statements</filename> module provides a means for
!   tracking execution statistics of all SQL statements executed by a server.
   </para>
  
   <para>
--- 9,15 ----
  
   <para>
    The <filename>pg_stat_statements</filename> module provides a means for
!   tracking planning and execution statistics of all SQL statements executed by a server.
   </para>
  
   <para>
***************
*** 72,81 ****
       </row>
  
       <row>
        <entry><structfield>total_time</structfield></entry>
        <entry><type>double precision</type></entry>
        <entry></entry>
!       <entry>Total time spent in the statement, in seconds</entry>
       </row>
  
       <row>
--- 72,88 ----
       </row>
  
       <row>
+       <entry><structfield>plan_time</structfield></entry>
+       <entry><type>double precision</type></entry>
+       <entry></entry>
+       <entry>Total planning time spent in the statement, in seconds</entry>
+      </row>
+ 
+      <row>
        <entry><structfield>total_time</structfield></entry>
        <entry><type>double precision</type></entry>
        <entry></entry>
!       <entry>Total execution time spent in the statement, in seconds</entry>
       </row>
  
       <row>
*** 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 */