Hello hackers,I'd like to follow up to my previous proposition of tracking (some) best and worst plans for different queries in the pg_stat_statements extension.
Based on the comments and suggestions made towards my last endeavour, I've taken the path of computing the interquartile distance (by means of an adapted z-test, under the assumption of normal distribution, based on the mean_time and stddev_time already used by the extension).
A bad plan is recorded, if there is no previously recorded plan, or if the current execution time is greater than the maximum of the previously recorded plan's time and the query's mean+1.5*interquartile_distance. A good plan is recorded on a similar condition; The execution time needs to be shorter than the minimum of the previously recorded good plan's time and the query's mean-1.5*interquartile_distance.
The boundaries are chosen to resemble the boundaries for whiskers in boxplots. Using these boundaries, plans will be updated very seldomly, as long as they are more or less normally distributed. Changes in the plans (for example the use of indices) used for each kind of query will most likely result in execution times exceeding these boundaries, so such changes are (very probably) recorded.
The ideal solution would be to compare the current plan with the last plan and only update when there is a difference between them, however I think this is unreasonably complex and a rather expensive task to compute on the completion of every query.
The intent of this patch is to provide a quick insight into the plans currently used by the database for the execution of certain queries. The tracked plans only represent instances of queries with very good or very poor performance.
I've (re)submitted this patch for the next commitfest as well. Kind regards Julian On 03/04/2017 02:56 PM, Julian Markwort wrote:
Alright, for the next version of this patch I'll look into standard deviation (an implementation of Welfords' algorithm already exists in pg_stat_statements).On 3/4/17 14:18, Peter Eisentraut wrote:I've already thought of tracking specific parts of the explanation, like the cost numbers, instead of the whole string, I'll think of something, but if anybody has any bright ideas in the meantime, I'd gladly listen to them.The other problem is that this measures execution time, which can vary for reasons other than plan. I would have expected that the cost numbers are tracked somehow.Would you be so kind and elaborate a little bit on this? I'm not sure if I understand this correctly. This patch only tracks specific plans, yes. The inital idea was that there might be some edge-cases that are not apparent when looking at generalized plans or queries.There is also the issue of generic vs specific plans, which this approach might be papering over.kind regards Julian
diff --git a/contrib/pg_stat_statements/Makefile b/contrib/pg_stat_statements/Makefile
index 39b368b70e..4d658d0ec7 100644
--- a/contrib/pg_stat_statements/Makefile
+++ b/contrib/pg_stat_statements/Makefile
@@ -4,7 +4,7 @@ MODULE_big = pg_stat_statements
OBJS = pg_stat_statements.o $(WIN32RES)
EXTENSION = pg_stat_statements
-DATA = pg_stat_statements--1.4.sql pg_stat_statements--1.4--1.5.sql \
+DATA = pg_stat_statements--1.5.sql pg_stat_statements--1.4--1.5.sql \
pg_stat_statements--1.3--1.4.sql pg_stat_statements--1.2--1.3.sql \
pg_stat_statements--1.1--1.2.sql pg_stat_statements--1.0--1.1.sql \
pg_stat_statements--unpackaged--1.0.sql
diff --git a/contrib/pg_stat_statements/expected/pg_stat_statements.out b/contrib/pg_stat_statements/expected/pg_stat_statements.out
index 5318c3550c..3e79890d50 100644
--- a/contrib/pg_stat_statements/expected/pg_stat_statements.out
+++ b/contrib/pg_stat_statements/expected/pg_stat_statements.out
@@ -395,4 +395,40 @@ SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C";
SELECT pg_stat_statements_reset() | 1 | 1
(8 rows)
+-- test to see if any plans have been recorded.
+SELECT
+ CASE WHEN good_plan_time > 0 THEN 1 ELSE 0 END,
+ CASE WHEN bad_plan_time > 0 THEN 1 ELSE 0 END,
+ CASE WHEN good_plan_timestamp >= timestamp '1970-01-01 00:00:00' THEN 1 ELSE 0 END,
+ CASE WHEN good_plan_timestamp >= timestamp '1970-01-01 00:00:00' THEN 1 ELSE 0 END
+FROM pg_stat_statements ORDER BY query COLLATE "C";
+ case | case | case | case
+------+------+------+------
+ 0 | 0 | 0 | 0
+ 0 | 0 | 0 | 0
+ 0 | 0 | 0 | 0
+ 0 | 0 | 0 | 0
+ 0 | 0 | 0 | 0
+ 0 | 0 | 0 | 0
+ 1 | 1 | 1 | 1
+ 1 | 1 | 1 | 1
+ 1 | 1 | 1 | 1
+(9 rows)
+
+-- test if there is some text in the recorded plans.
+select substr(good_plan, 0, 11), substr(bad_plan, 0, 11) from pg_stat_statements ORDER BY query COLLATE "C";
+ substr | substr
+------------+------------
+ |
+ |
+ |
+ |
+ |
+ |
+ Query Text | Query Text
+ Query Text | Query Text
+ Query Text | Query Text
+ Query Text | Query Text
+(10 rows)
+
DROP EXTENSION pg_stat_statements;
diff --git a/contrib/pg_stat_statements/pg_stat_statements--1.4--1.5.sql b/contrib/pg_stat_statements/pg_stat_statements--1.4--1.5.sql
index 9c76122a2b..27a26c1c26 100644
--- a/contrib/pg_stat_statements/pg_stat_statements--1.4--1.5.sql
+++ b/contrib/pg_stat_statements/pg_stat_statements--1.4--1.5.sql
@@ -3,4 +3,69 @@
-- complain if script is sourced in psql, rather than via ALTER EXTENSION
\echo Use "ALTER EXTENSION pg_stat_statements UPDATE TO '1.5'" to load this file. \quit
+-- Register new functions.
+CREATE FUNCTION pg_stat_statements_good_plan_reset(IN queryid bigint)
+RETURNS void
+AS 'MODULE_PATHNAME'
+LANGUAGE C PARALLEL SAFE;
+
+CREATE FUNCTION pg_stat_statements_bad_plan_reset(IN queryid bigint)
+RETURNS void
+AS 'MODULE_PATHNAME'
+LANGUAGE C PARALLEL SAFE;
+
+/* First we have to remove them from the extension */
+ALTER EXTENSION pg_stat_statements DROP VIEW pg_stat_statements;
+ALTER EXTENSION pg_stat_statements DROP FUNCTION pg_stat_statements(boolean);
+
+/* Then we can drop them */
+DROP VIEW pg_stat_statements;
+DROP FUNCTION pg_stat_statements(boolean);
+
+/* Now redefine */
+CREATE FUNCTION pg_stat_statements(IN showtext boolean,
+ OUT userid oid,
+ OUT dbid oid,
+ OUT queryid bigint,
+ OUT query text,
+ OUT good_plan text,
+ OUT bad_plan text,
+ OUT calls int8,
+ OUT total_time float8,
+ OUT min_time float8,
+ OUT max_time float8,
+ OUT mean_time float8,
+ OUT stddev_time float8,
+ OUT good_plan_time float8,
+ OUT good_plan_timestamp timestamp,
+ OUT bad_plan_time float8,
+ OUT bad_plan_timestamp timestamp,
+ OUT rows int8,
+ OUT shared_blks_hit int8,
+ OUT shared_blks_read int8,
+ OUT shared_blks_dirtied int8,
+ OUT shared_blks_written int8,
+ OUT local_blks_hit int8,
+ OUT local_blks_read int8,
+ OUT local_blks_dirtied int8,
+ OUT local_blks_written int8,
+ OUT temp_blks_read int8,
+ OUT temp_blks_written int8,
+ OUT blk_read_time float8,
+ OUT blk_write_time float8
+)
+RETURNS SETOF record
+AS 'MODULE_PATHNAME', 'pg_stat_statements_1_5'
+LANGUAGE C STRICT VOLATILE PARALLEL SAFE;
+
+CREATE VIEW pg_stat_statements AS
+ SELECT * FROM pg_stat_statements(true);
+
+GRANT SELECT ON pg_stat_statements TO PUBLIC;
+
+-- Don't want this to be available to non-superusers.
+REVOKE ALL ON FUNCTION pg_stat_statements_reset() FROM PUBLIC;
+REVOKE ALL ON FUNCTION pg_stat_statements_good_plan_reset FROM PUBLIC;
+REVOKE ALL ON FUNCTION pg_stat_statements_bad_plan_reset FROM PUBLIC;
+
GRANT EXECUTE ON FUNCTION pg_stat_statements_reset() TO pg_read_all_stats;
diff --git a/contrib/pg_stat_statements/pg_stat_statements--1.5.sql b/contrib/pg_stat_statements/pg_stat_statements--1.5.sql
new file mode 100644
index 0000000000..49aa65e6e3
--- /dev/null
+++ b/contrib/pg_stat_statements/pg_stat_statements--1.5.sql
@@ -0,0 +1,68 @@
+/* contrib/pg_stat_statements/pg_stat_statements--1.5.sql */
+
+-- complain if script is sourced in psql, rather than via CREATE EXTENSION
+\echo Use "CREATE EXTENSION pg_stat_statements" to load this file. \quit
+
+-- Register functions.
+CREATE FUNCTION pg_stat_statements_reset()
+RETURNS void
+AS 'MODULE_PATHNAME'
+LANGUAGE C PARALLEL SAFE;
+
+CREATE FUNCTION pg_stat_statements_good_plan_reset(IN queryid bigint)
+RETURNS void
+AS 'MODULE_PATHNAME'
+LANGUAGE C PARALLEL SAFE;
+
+CREATE FUNCTION pg_stat_statements_bad_plan_reset(IN queryid bigint)
+RETURNS void
+AS 'MODULE_PATHNAME'
+LANGUAGE C PARALLEL SAFE;
+
+CREATE FUNCTION pg_stat_statements(IN showtext boolean,
+ OUT userid oid,
+ OUT dbid oid,
+ OUT queryid bigint,
+ OUT query text,
+ OUT good_plan text,
+ OUT bad_plan text,
+ OUT calls int8,
+ OUT total_time float8,
+ OUT min_time float8,
+ OUT max_time float8,
+ OUT mean_time float8,
+ OUT stddev_time float8,
+ OUT good_plan_time float8,
+ OUT good_plan_timestamp timestamp,
+ OUT bad_plan_time float8,
+ OUT bad_plan_timestamp timestamp,
+ OUT rows int8,
+ OUT shared_blks_hit int8,
+ OUT shared_blks_read int8,
+ OUT shared_blks_dirtied int8,
+ OUT shared_blks_written int8,
+ OUT local_blks_hit int8,
+ OUT local_blks_read int8,
+ OUT local_blks_dirtied int8,
+ OUT local_blks_written int8,
+ OUT temp_blks_read int8,
+ OUT temp_blks_written int8,
+ OUT blk_read_time float8,
+ OUT blk_write_time float8
+)
+RETURNS SETOF record
+AS 'MODULE_PATHNAME', 'pg_stat_statements_1_5'
+LANGUAGE C STRICT VOLATILE PARALLEL SAFE;
+
+-- Register a view on the function for ease of use.
+CREATE VIEW pg_stat_statements AS
+ SELECT * FROM pg_stat_statements(true);
+
+GRANT SELECT ON pg_stat_statements TO PUBLIC;
+
+-- Don't want this to be available to non-superusers.
+REVOKE ALL ON FUNCTION pg_stat_statements_reset() FROM PUBLIC;
+REVOKE ALL ON FUNCTION pg_stat_statements_good_plan_reset(bigint) FROM PUBLIC;
+REVOKE ALL ON FUNCTION pg_stat_statements_bad_plan_reset(bigint) FROM PUBLIC;
+
+GRANT EXECUTE ON FUNCTION pg_stat_statements_reset() TO pg_read_all_stats;
diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c
index 928673498a..be68d68329 100644
--- a/contrib/pg_stat_statements/pg_stat_statements.c
+++ b/contrib/pg_stat_statements/pg_stat_statements.c
@@ -63,6 +63,7 @@
#include "access/hash.h"
#include "catalog/pg_authid.h"
+#include "commands/explain.h"
#include "executor/instrument.h"
#include "funcapi.h"
#include "mb/pg_wchar.h"
@@ -78,6 +79,7 @@
#include "tcop/utility.h"
#include "utils/builtins.h"
#include "utils/memutils.h"
+#include "utils/timestamp.h"
PG_MODULE_MAGIC;
@@ -119,7 +121,8 @@ typedef enum pgssVersion
PGSS_V1_0 = 0,
PGSS_V1_1,
PGSS_V1_2,
- PGSS_V1_3
+ PGSS_V1_3,
+ PGSS_V1_5
} pgssVersion;
/*
@@ -165,6 +168,14 @@ typedef struct Counters
double usage; /* usage factor */
} Counters;
+typedef struct pgssPlan
+{
+ Size offset;
+ int len;
+ double time; /* execution time in msec when the latest plan was updated */
+ TimestampTz timestamp;
+} pgssPlan;
+
/*
* Statistics per statement
*
@@ -178,6 +189,8 @@ typedef struct pgssEntry
Counters counters; /* the statistics for this query */
Size query_offset; /* query text offset in external file */
int query_len; /* # of valid bytes in query string, or -1 */
+ pgssPlan good_plan;
+ pgssPlan bad_plan;
int encoding; /* query text encoding */
slock_t mutex; /* protects the counters only */
} pgssEntry;
@@ -265,11 +278,22 @@ static const struct config_enum_entry track_options[] =
{NULL, 0, false}
};
+static const struct config_enum_entry format_options[] =
+{
+ {"text", EXPLAIN_FORMAT_TEXT, false},
+ {"xml", EXPLAIN_FORMAT_XML, false},
+ {"json", EXPLAIN_FORMAT_JSON, false},
+ {"yaml", EXPLAIN_FORMAT_YAML, false},
+ {NULL, 0, false}
+};
+
static int pgss_max; /* max # statements to track */
static int pgss_track; /* tracking level */
static bool pgss_track_utility; /* whether to track utility commands */
static bool pgss_save; /* whether to save stats across shutdown */
-
+static bool pgss_good_plan_enable; /* whether to save good_plans */
+static bool pgss_bad_plan_enable; /* whether to save good_plans */
+static int pgss_plan_format; /* id which sets the output format */
#define pgss_enabled() \
(pgss_track == PGSS_TRACK_ALL || \
@@ -291,7 +315,11 @@ void _PG_fini(void);
PG_FUNCTION_INFO_V1(pg_stat_statements_reset);
PG_FUNCTION_INFO_V1(pg_stat_statements_1_2);
PG_FUNCTION_INFO_V1(pg_stat_statements_1_3);
+PG_FUNCTION_INFO_V1(pg_stat_statements_1_5);
PG_FUNCTION_INFO_V1(pg_stat_statements);
+PG_FUNCTION_INFO_V1(pg_stat_statements_good_plan_reset);
+PG_FUNCTION_INFO_V1(pg_stat_statements_bad_plan_reset);
+
static void pgss_shmem_startup(void);
static void pgss_shmem_shutdown(int code, Datum arg);
@@ -309,12 +337,17 @@ static void pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
static uint64 pgss_hash_string(const char *str, int len);
static void pgss_store(const char *query, uint64 queryId,
int query_location, int query_len,
+ const char *plan,
double total_time, uint64 rows,
const BufferUsage *bufusage,
pgssJumbleState *jstate);
+Datum pg_stat_statements_plan_reset(uint64 query_id, uint8 plan_type);
static void pg_stat_statements_internal(FunctionCallInfo fcinfo,
pgssVersion api_version,
bool showtext);
+static int fill_plan_times(Datum values[], bool nulls[], int i, pgssPlan *plan);
+static int fill_plan_str(Datum values[], bool nulls[], int i, pgssPlan *plan,
+ pgssEntry *entry, char *qbuffer, Size qbuffer_size);
static Size pgss_memsize(void);
static pgssEntry *entry_alloc(pgssHashKey *key, Size query_offset, int query_len,
int encoding, bool sticky);
@@ -407,6 +440,40 @@ _PG_init(void)
NULL,
NULL);
+ DefineCustomBoolVariable("pg_stat_statements.good_plan_enable",
+ "Enable bad plan detection",
+ NULL,
+ &pgss_good_plan_enable,
+ true,
+ PGC_SUSET,
+ 0,
+ NULL,
+ NULL,
+ NULL);
+
+ DefineCustomBoolVariable("pg_stat_statements.bad_plan_enable",
+ "Enable bad plan detection",
+ NULL,
+ &pgss_bad_plan_enable,
+ true,
+ PGC_SUSET,
+ 0,
+ NULL,
+ NULL,
+ NULL);
+
+ DefineCustomEnumVariable("pg_stat_statements.plan_format",
+ "Sets the output format for the plans.",
+ "Notice that the plan format can not be changed after a plan is saved. Valid values are text, json, xml and yaml.",
+ &pgss_plan_format,
+ EXPLAIN_FORMAT_TEXT,
+ format_options,
+ PGC_SUSET,
+ 0,
+ NULL,
+ NULL,
+ NULL);
+
EmitWarningsOnPlaceholders("pg_stat_statements");
/*
@@ -470,7 +537,11 @@ pgss_shmem_startup(void)
int32 pgver;
int32 i;
int buffer_size;
+ int good_plan_buffer_size;
+ int bad_plan_buffer_size;
char *buffer = NULL;
+ char *good_plan_buffer = NULL;
+ char *bad_plan_buffer = NULL;
if (prev_shmem_startup_hook)
prev_shmem_startup_hook();
@@ -561,7 +632,11 @@ pgss_shmem_startup(void)
}
buffer_size = 2048;
+ good_plan_buffer_size = 2048;
+ bad_plan_buffer_size = 2048;
buffer = (char *) palloc(buffer_size);
+ good_plan_buffer = (char *) palloc(good_plan_buffer_size);
+ bad_plan_buffer = (char *) palloc(bad_plan_buffer_size);
if (fread(&header, sizeof(uint32), 1, file) != 1 ||
fread(&pgver, sizeof(uint32), 1, file) != 1 ||
@@ -595,8 +670,34 @@ pgss_shmem_startup(void)
if (fread(buffer, 1, temp.query_len + 1, file) != temp.query_len + 1)
goto read_error;
+ /* Resize good plan_buffer and read into it */
+ if (temp.good_plan.len >= good_plan_buffer_size)
+ {
+ good_plan_buffer_size =
+ Max(good_plan_buffer_size * 2, temp.good_plan.len + 1);
+ good_plan_buffer= repalloc(good_plan_buffer, good_plan_buffer_size);
+ }
+
+ if (fread(good_plan_buffer, 1, temp.good_plan.len + 1, file)
+ != temp.good_plan.len + 1)
+ goto read_error;
+
+ /* Resize bad plan_buffer and read into it */
+ if (temp.bad_plan.len >= bad_plan_buffer_size)
+ {
+ bad_plan_buffer_size =
+ Max(bad_plan_buffer_size * 2, temp.bad_plan.len + 1);
+ bad_plan_buffer= repalloc(bad_plan_buffer, bad_plan_buffer_size);
+ }
+
+ if (fread(bad_plan_buffer, 1, temp.bad_plan.len + 1, file)
+ != temp.bad_plan.len + 1)
+ goto read_error;
+
/* Should have a trailing null, but let's make sure */
buffer[temp.query_len] = '\0';
+ good_plan_buffer[temp.good_plan.len] = '\0';
+ bad_plan_buffer[temp.bad_plan.len] = '\0';
/* Skip loading "sticky" entries */
if (temp.counters.calls == 0)
@@ -608,6 +709,20 @@ pgss_shmem_startup(void)
goto write_error;
pgss->extent += temp.query_len + 1;
+ /* Store the good plan text*/
+ temp.good_plan.offset = pgss->extent;
+ if (fwrite(good_plan_buffer, 1, temp.good_plan.len + 1, qfile)
+ != temp.good_plan.len + 1)
+ goto write_error;
+ pgss->extent += temp.good_plan.len + 1;
+
+ /* Store the bad plan text*/
+ temp.bad_plan.offset = pgss->extent;
+ if (fwrite(bad_plan_buffer, 1, temp.bad_plan.len + 1, qfile)
+ != temp.bad_plan.len + 1)
+ goto write_error;
+ pgss->extent += temp.bad_plan.len + 1;
+
/* make the hashtable entry (discards old entries if too many) */
entry = entry_alloc(&temp.key, query_offset, temp.query_len,
temp.encoding,
@@ -615,9 +730,14 @@ pgss_shmem_startup(void)
/* copy in the actual stats */
entry->counters = temp.counters;
+ /* copy in the plans */
+ entry->good_plan = temp.good_plan;
+ entry->bad_plan = temp.bad_plan;
}
pfree(buffer);
+ pfree(good_plan_buffer);
+ pfree(bad_plan_buffer);
FreeFile(file);
FreeFile(qfile);
@@ -658,6 +778,10 @@ write_error:
fail:
if (buffer)
pfree(buffer);
+ if (good_plan_buffer)
+ pfree(good_plan_buffer);
+ if (bad_plan_buffer)
+ pfree(bad_plan_buffer);
if (file)
FreeFile(file);
if (qfile)
@@ -680,6 +804,11 @@ fail:
static void
pgss_shmem_shutdown(int code, Datum arg)
{
+
+ //DEBUG
+// FILE *debugfile;
+
+
FILE *file;
char *qbuffer = NULL;
Size qbuffer_size = 0;
@@ -687,6 +816,11 @@ pgss_shmem_shutdown(int code, Datum arg)
int32 num_entries;
pgssEntry *entry;
+ //DEBUG
+// debugfile = fopen("/tmp/shutdown.log", "w");
+// fprintf(debugfile, "entered pgss_shmem_shutdown\n");
+// fflush(debugfile);
+
/* Don't try to dump during a crash. */
if (code)
return;
@@ -715,6 +849,10 @@ pgss_shmem_shutdown(int code, Datum arg)
if (qbuffer == NULL)
goto error;
+ //DEBUG
+// fprintf(debugfile, "loaded qtexts\n");
+// fflush(debugfile);
+
/*
* When serializing to disk, we store query texts immediately after their
* entry data. Any orphaned query texts are thereby excluded.
@@ -723,21 +861,78 @@ pgss_shmem_shutdown(int code, Datum arg)
while ((entry = hash_seq_search(&hash_seq)) != NULL)
{
int len = entry->query_len;
+ int good_plan_len = entry->good_plan.len;
+ int bad_plan_len = entry->bad_plan.len;
char *qstr = qtext_fetch(entry->query_offset, len,
qbuffer, qbuffer_size);
+ char *good_plan_str;
+ char *bad_plan_str;
+ if (good_plan_len > 0)
+ {
+ /* A good plan is available */
+ good_plan_str = qtext_fetch(entry->good_plan.offset, good_plan_len,
+ qbuffer, qbuffer_size);
+ } else {
+ /*
+ * There is no good plan available. This can be caused by a query
+ * which has no plan (for example insert or delete queries) or
+ * because good plans are disabled. In this case we have to store
+ * an empty string instead of null.
+ */
+ good_plan_str = palloc(1 * sizeof(char));
+ *good_plan_str = '\0';
+ //good_plan_str="\0";
+ }
+ if (bad_plan_len > 0)
+ {
+ /* A bad plan is available */
+ bad_plan_str = qtext_fetch(entry->bad_plan.offset, bad_plan_len,
+ qbuffer, qbuffer_size);
+ } else {
+ /*
+ * There is no bad plan available. This can be caused by a query
+ * which has no plan (for example insert or delete queries) or
+ * because bad plans are disabled. In this case we have to store
+ * an empty string instead of null.
+ */
+ bad_plan_str = palloc(1 * sizeof(char));
+ *bad_plan_str = '\0';
+ //bad_plan_str="\0";
+ }
if (qstr == NULL)
continue; /* Ignore any entries with bogus texts */
+ //DEBUG
+// fprintf(debugfile, "trying to write entry, query, plans...\n");
+// fprintf(debugfile, "query_len: %d \t good_plan_len: %d \t bad_plan_len: %d \n", len, good_plan_len, bad_plan_len);
+// fflush(debugfile);
+// fprintf(debugfile, "query: %s \t good_plan: %s \t bad_plan %s \n", qstr, good_plan_str, bad_plan_str);
+// fflush(debugfile);
+
+ /* Write entries, queries and plans serialized to the dump file */
if (fwrite(entry, sizeof(pgssEntry), 1, file) != 1 ||
- fwrite(qstr, 1, len + 1, file) != len + 1)
+ fwrite(qstr, 1, len + 1, file) != len + 1 ||
+ fwrite(good_plan_str, 1, good_plan_len + 1, file) != good_plan_len + 1 ||
+ fwrite(bad_plan_str, 1, bad_plan_len + 1, file) != bad_plan_len + 1)
{
/* note: we assume hash_seq_term won't change errno */
hash_seq_term(&hash_seq);
goto error;
}
+
+ //DEBUG
+// fprintf(debugfile, "wrote entry, qstr, plans to dump file.\n");
+// fflush(debugfile);
+
}
+ //DEBUG
+// fprintf(debugfile, ">>>>>wrote all the things to dump file.\n");
+// fflush(debugfile);
+// if(debugfile)
+// fclose(debugfile);
+
free(qbuffer);
qbuffer = NULL;
@@ -835,6 +1030,7 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query)
query->queryId,
query->stmt_location,
query->stmt_len,
+ NULL,
0,
0,
NULL,
@@ -928,6 +1124,8 @@ pgss_ExecutorFinish(QueryDesc *queryDesc)
static void
pgss_ExecutorEnd(QueryDesc *queryDesc)
{
+ /* *es is used to retrieve the plan associated with the statement*/
+ ExplainState *es = NewExplainState();
uint64 queryId = queryDesc->plannedstmt->queryId;
if (queryId != UINT64CONST(0) && queryDesc->totaltime && pgss_enabled())
@@ -938,15 +1136,47 @@ pgss_ExecutorEnd(QueryDesc *queryDesc)
*/
InstrEndLoop(queryDesc->totaltime);
+ /* The plan is retrieved whenever any plan tracking is enabled,
+ * as we do not know at this point, wether the plan was better
+ * or worse than before.
+ */
+ if(pgss_good_plan_enable || pgss_bad_plan_enable){
+ es->analyze = (queryDesc->instrument_options && false);
+ es->verbose = false;
+ es->buffers = (es->analyze && false);
+ es->timing = (es->analyze && true);
+ es->format = pgss_plan_format;
+
+ ExplainBeginOutput(es);
+ ExplainQueryText(es, queryDesc);
+ ExplainPrintPlan(es, queryDesc);
+ ExplainEndOutput(es);
+
+ /* Remove last line break */
+ if (es->str->len > 0 && es->str->data[es->str->len - 1] == '\n')
+ es->str->data[--es->str->len] = '\0';
+
+ //TODO:wieso kann hier data[0] gleich '{' gesetzt werden? Was stand da vorher?
+ /* Fix JSON to output an object */
+ if (pgss_plan_format == EXPLAIN_FORMAT_JSON)
+ {
+ es->str->data[0] = '{';
+ es->str->data[es->str->len - 1] = '}';
+ }
+ }
+
pgss_store(queryDesc->sourceText,
queryId,
queryDesc->plannedstmt->stmt_location,
queryDesc->plannedstmt->stmt_len,
+ es->str->data, /* plan */
queryDesc->totaltime->total * 1000.0, /* convert to msec */
queryDesc->estate->es_processed,
&queryDesc->totaltime->bufusage,
NULL);
}
+ pfree(es->str->data);
+ pfree(es);
if (prev_ExecutorEnd)
prev_ExecutorEnd(queryDesc);
@@ -1053,6 +1283,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
0, /* signal that it's a utility stmt */
pstmt->stmt_location,
pstmt->stmt_len,
+ NULL,
INSTR_TIME_GET_MILLISEC(duration),
rows,
&bufusage,
@@ -1083,6 +1314,26 @@ pgss_hash_string(const char *str, int len)
len, 0));
}
+/*
+ * Update a plan in the text file.
+ * We can re-use qtext_store to save the plan.
+ */
+static void
+update_plan(volatile pgssPlan* pgssPlan_ptr, const char* plan_str, int plan_len,
+ double total_time)
+{
+ if (plan_len > 0)
+ {
+ Size plan_offset;
+ qtext_store(plan_str, plan_len, &plan_offset, NULL);
+ pgssPlan_ptr->offset = plan_offset;
+ pgssPlan_ptr->len = plan_len;
+ pgssPlan_ptr->time = total_time;
+ pgssPlan_ptr->timestamp = GetCurrentTimestamp();
+ }
+ return;
+}
+
/*
* Store some statistics for a statement.
*
@@ -1096,6 +1347,7 @@ pgss_hash_string(const char *str, int len)
static void
pgss_store(const char *query, uint64 queryId,
int query_location, int query_len,
+ const char *plan,
double total_time, uint64 rows,
const BufferUsage *bufusage,
pgssJumbleState *jstate)
@@ -1104,6 +1356,7 @@ pgss_store(const char *query, uint64 queryId,
pgssEntry *entry;
char *norm_query = NULL;
int encoding = GetDatabaseEncoding();
+ int plan_len = 0;
Assert(query != NULL);
@@ -1134,6 +1387,9 @@ pgss_store(const char *query, uint64 queryId,
query_len = strlen(query);
}
+ if(plan)
+ plan_len = strlen(plan);
+
/*
* Discard leading and trailing whitespace, too. Use scanner_isspace()
* not libc's isspace(), because we want to match the lexer's behavior.
@@ -1214,7 +1470,11 @@ pgss_store(const char *query, uint64 queryId,
if (!stored)
goto done;
- /* OK to create a new hashtable entry */
+ /* OK to create a new hashtable entry
+ * We have to set the good- and the bad planlength to zero. Otherwise the
+ * pgss_shmem_startup method will expect this number of chars which crashes
+ * if there is no plan yet.
+ */
entry = entry_alloc(&key, query_offset, query_len, encoding,
jstate != NULL);
@@ -1230,10 +1490,56 @@ pgss_store(const char *query, uint64 queryId,
* Grab the spinlock while updating the counters (see comment about
* locking rules at the head of the file)
*/
- volatile pgssEntry *e = (volatile pgssEntry *) entry;
+ volatile pgssEntry *e = (volatile pgssEntry *) entry;
+ double interquartile_dist = 0.0;
SpinLockAcquire(&e->mutex);
+ /*
+ * Both good and bad plans are updated, if no previous plan has beed recorded.
+ */
+
+ if (pgss_good_plan_enable && e->good_plan.time == 0)
+ {
+ update_plan(&e->good_plan, plan, plan_len, total_time);
+ }
+
+ if (pgss_bad_plan_enable && e->bad_plan.time == 0)
+ {
+ update_plan(&e->bad_plan, plan, plan_len, total_time);
+ }
+
+ /*
+ * The Z-scores allows us to estimate the values at any quantiles
+ * in a list of values with (assumed) normal distribution, known mean,
+ * and known standard deviation. The value at any quantile is equal to
+ * z*stddev + mean. The distance to the mean is thus z*stddev,
+ * which we'll use to calculate the interquartile distance.
+ */
+ interquartile_dist = 2.0*(0.6745 * sqrt(e->counters.sum_var_time / e->counters.calls));
+ if(interquartile_dist > 0.0)
+ {
+ /*
+ * If the execution time is smaller than the minimum of mean - 1.5*IQD,
+ * and the previous good_plan's time, the good_plan is updated.
+ */
+ if (pgss_good_plan_enable && total_time < e->good_plan.time
+ && total_time < (e->counters.mean_time - 1.5 * interquartile_dist))
+ {
+ update_plan(&e->good_plan, plan, plan_len, total_time);
+ }
+
+ /*
+ * If the execution time is greater than the maximum of mean + 1.5*IQD,
+ * and the previous bad_plan's time, the bad_plan is updated.
+ */
+ if (pgss_bad_plan_enable && total_time > e->bad_plan.time
+ && total_time > (e->counters.mean_time + 1.5 * interquartile_dist))
+ {
+ update_plan(&e->bad_plan, plan, plan_len, total_time);
+ }
+ }
+
/* "Unstick" entry if it was previously sticky */
if (e->counters.calls == 0)
e->counters.usage = USAGE_INIT;
@@ -1305,12 +1611,89 @@ pg_stat_statements_reset(PG_FUNCTION_ARGS)
PG_RETURN_VOID();
}
+Datum
+pg_stat_statements_plan_reset(uint64 query_id, uint8 plan_type)
+{
+ pgssEntry *entry;
+
+ pgssHashKey key;
+
+ if (!pgss || !pgss_hash)
+ ereport(ERROR,
+ (errcode(ERRCODE_OBJECT_NOT_IN_PREREQUISITE_STATE),
+ errmsg("pg_stat_statements must be loaded via shared_preload_libraries")));
+
+ /* Set up key for hashtable search */
+ key.userid = GetUserId();
+ key.dbid = MyDatabaseId;
+ key.queryid = query_id;
+
+ /* Lookup the hash table entry with shared lock. */
+ LWLockAcquire(pgss->lock, LW_SHARED);
+
+ entry = (pgssEntry *) hash_search(pgss_hash, &key, HASH_FIND, NULL);
+
+ if (entry)
+ {
+ if(superuser() || entry->key.userid == key.userid)
+ {
+ pgssPlan *pgssPlan_ptr;
+ switch (plan_type)
+ {
+ case 1:
+ pgssPlan_ptr = &entry->good_plan;
+ break;
+ case 2:
+ pgssPlan_ptr = &entry->bad_plan;
+ break;
+ default:
+ ereport(ERROR,
+ (errcode(ERRCODE_INVALID_PARAMETER_VALUE),
+ errmsg_internal("unrecognized plan type: %d",
+ plan_type)));
+ break;
+ }
+ if(pgssPlan_ptr)
+ {
+ pgssPlan_ptr->offset = -1;
+ pgssPlan_ptr->len = 0;
+ pgssPlan_ptr->time = 0;
+ pgssPlan_ptr->timestamp = 0;
+ }
+ }else{
+ elog(ERROR, "insufficient permission to reset plan");
+ }
+ }
+ LWLockRelease(pgss->lock);
+ PG_RETURN_VOID();
+}
+
+/*
+ * Reset the good_plan of the entry with queryid.
+ */
+Datum
+pg_stat_statements_good_plan_reset(PG_FUNCTION_ARGS)
+{
+ return pg_stat_statements_plan_reset(PG_GETARG_INT64(0), 1);
+}
+
+/*
+ * Reset the bad_plan of the entry with queryid.
+ */
+Datum
+pg_stat_statements_bad_plan_reset(PG_FUNCTION_ARGS)
+{
+ return pg_stat_statements_plan_reset(PG_GETARG_INT64(0), 2);
+}
+
+
/* Number of output arguments (columns) for various API versions */
#define PG_STAT_STATEMENTS_COLS_V1_0 14
#define PG_STAT_STATEMENTS_COLS_V1_1 18
#define PG_STAT_STATEMENTS_COLS_V1_2 19
#define PG_STAT_STATEMENTS_COLS_V1_3 23
-#define PG_STAT_STATEMENTS_COLS 23 /* maximum of above */
+#define PG_STAT_STATEMENTS_COLS_V1_5 29
+#define PG_STAT_STATEMENTS_COLS 29 /* maximum of above */
/*
* Retrieve statement statistics.
@@ -1322,6 +1705,16 @@ pg_stat_statements_reset(PG_FUNCTION_ARGS)
* expected API version is identified by embedding it in the C name of the
* function. Unfortunately we weren't bright enough to do that for 1.1.
*/
+Datum
+pg_stat_statements_1_5(PG_FUNCTION_ARGS)
+{
+ bool showtext = PG_GETARG_BOOL(0);
+
+ pg_stat_statements_internal(fcinfo, PGSS_V1_5, showtext);
+
+ return (Datum) 0;
+}
+
Datum
pg_stat_statements_1_3(PG_FUNCTION_ARGS)
{
@@ -1428,6 +1821,10 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo,
if (api_version != PGSS_V1_3)
elog(ERROR, "incorrect number of output arguments");
break;
+ case PG_STAT_STATEMENTS_COLS_V1_5:
+ if (api_version != PGSS_V1_5)
+ elog(ERROR, "incorrect number of output arguments");
+ break;
default:
elog(ERROR, "incorrect number of output arguments");
}
@@ -1511,6 +1908,8 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo,
bool nulls[PG_STAT_STATEMENTS_COLS];
int i = 0;
Counters tmp;
+ pgssPlan tmp_good_plan;
+ pgssPlan tmp_bad_plan;
double stddev;
int64 queryid = entry->key.queryid;
@@ -1550,6 +1949,18 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo,
/* Just return a null if we fail to find the text */
nulls[i++] = true;
}
+
+ if (api_version >= PGSS_V1_5)
+ {
+ /*
+ * This version requires to print out the good
+ * and the bad plan if they are enabled.
+ */
+ i = fill_plan_str(values, nulls, i, &entry->good_plan,
+ entry, qbuffer, qbuffer_size);
+ i = fill_plan_str(values, nulls, i, &entry->bad_plan,
+ entry, qbuffer, qbuffer_size);
+ }
}
else
{
@@ -1579,6 +1990,8 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo,
SpinLockAcquire(&e->mutex);
tmp = e->counters;
+ tmp_good_plan = e->good_plan;
+ tmp_bad_plan = e->bad_plan;
SpinLockRelease(&e->mutex);
}
@@ -1606,6 +2019,14 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo,
stddev = 0.0;
values[i++] = Float8GetDatumFast(stddev);
}
+
+ if (api_version >= PGSS_V1_5)
+ {
+ /* Set plan times and timestamps */
+ i = fill_plan_times(values, nulls, i, &tmp_good_plan);
+ i = fill_plan_times(values, nulls, i, &tmp_bad_plan);
+ }
+
values[i++] = Int64GetDatumFast(tmp.rows);
values[i++] = Int64GetDatumFast(tmp.shared_blks_hit);
values[i++] = Int64GetDatumFast(tmp.shared_blks_read);
@@ -1629,6 +2050,7 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo,
api_version == PGSS_V1_1 ? PG_STAT_STATEMENTS_COLS_V1_1 :
api_version == PGSS_V1_2 ? PG_STAT_STATEMENTS_COLS_V1_2 :
api_version == PGSS_V1_3 ? PG_STAT_STATEMENTS_COLS_V1_3 :
+ api_version == PGSS_V1_5 ? PG_STAT_STATEMENTS_COLS_V1_5 :
-1 /* fail if you forget to update this assert */ ));
tuplestore_putvalues(tupstore, tupdesc, values, nulls);
@@ -1643,6 +2065,53 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo,
tuplestore_donestoring(tupstore);
}
+/* Fill the plan time and timestamp into the values array. */
+static int
+fill_plan_times(Datum values[], bool nulls[], int i, pgssPlan *plan)
+{
+ values[i++] = Float8GetDatumFast(plan->time);
+
+ /* if there is noting in the timestamp field, we are not interested in it */
+ if (plan->timestamp)
+ values[i++] = TimestampTzGetDatum(plan->timestamp);
+ else
+ nulls[i++] = true;
+ return i;
+}
+
+/* Fill the plan string into the values array. */
+static int
+fill_plan_str(Datum values[], bool nulls[], int i, pgssPlan *plan,
+ pgssEntry *entry, char *qbuffer, Size qbuffer_size)
+{
+ if (plan && plan->len > 0)
+ {
+ char *pstr = qtext_fetch(plan->offset,
+ plan->len,
+ qbuffer,
+ qbuffer_size);
+ if (pstr)
+ {
+ char *enc;
+ enc = pg_any_to_server(pstr,
+ plan->len,
+ entry->encoding);
+ values[i++] = CStringGetTextDatum(enc);
+
+ if (enc != pstr)
+ pfree(enc);
+ } else {
+ /* failed to get the string of the plan */
+ nulls[i++] = true;
+ }
+ } else {
+ /* no plan available or plan_len not greater than 0 */
+ nulls[i++] = true;
+ }
+ return i;
+}
+
+
/*
* Estimate shared memory space needed.
*/
@@ -1694,6 +2163,8 @@ entry_alloc(pgssHashKey *key, Size query_offset, int query_len, int encoding,
/* reset the statistics */
memset(&entry->counters, 0, sizeof(Counters));
+ memset(&entry->good_plan, 0, sizeof(pgssPlan));
+ memset(&entry->bad_plan, 0, sizeof(pgssPlan));
/* set the appropriate initial usage count */
entry->counters.usage = sticky ? pgss->cur_median_usage : USAGE_INIT;
/* re-initialize the mutex each time ... we assume no one using it */
@@ -2104,11 +2575,27 @@ gc_qtexts(void)
qbuffer,
qbuffer_size);
- if (qry == NULL)
+ int good_plan_len = entry->good_plan.len;
+ char *good_plan = qtext_fetch(entry->good_plan.offset,
+ good_plan_len,
+ qbuffer,
+ qbuffer_size);
+
+ int bad_plan_len = entry->bad_plan.len;
+ char *bad_plan = qtext_fetch(entry->bad_plan.offset,
+ bad_plan_len,
+ qbuffer,
+ qbuffer_size);
+
+ if (qry == NULL || good_plan == NULL || bad_plan == NULL)
{
- /* Trouble ... drop the text */
+ /* Trouble ... drop the texts */
entry->query_offset = 0;
entry->query_len = -1;
+ entry->good_plan.offset = 0;
+ entry->good_plan.len = -1;
+ entry->bad_plan.offset = 0;
+ entry->bad_plan.len = -1;
/* entry will not be counted in mean query length computation */
continue;
}
@@ -2125,6 +2612,43 @@ gc_qtexts(void)
entry->query_offset = extent;
extent += query_len + 1;
+
+ if(good_plan_len <= 0)
+ {
+ good_plan = "\0";
+ good_plan_len = 0;
+ }
+ /* Save the good plan */
+ if (fwrite(good_plan, 1, good_plan_len + 1, qfile) != good_plan_len + 1)
+ {
+ ereport(LOG,
+ (errcode_for_file_access(),
+ errmsg("could not write best plan pg_stat_statement file \"%s\": %m",
+ PGSS_TEXT_FILE)));
+ hash_seq_term(&hash_seq);
+ goto gc_fail;
+ }
+ entry->good_plan.offset = extent;
+ extent += good_plan_len + 1;
+
+ if(bad_plan_len <= 0)
+ {
+ bad_plan = "\0";
+ bad_plan_len = 0;
+ }
+ /* Save the bad plan */
+ if (fwrite(bad_plan, 1, bad_plan_len + 1, qfile) != bad_plan_len + 1)
+ {
+ ereport(LOG,
+ (errcode_for_file_access(),
+ errmsg("could not write worst plan pg_stat_statement file \"%s\": %m",
+ PGSS_TEXT_FILE)));
+ hash_seq_term(&hash_seq);
+ goto gc_fail;
+ }
+ entry->bad_plan.offset = extent;
+ extent += bad_plan_len + 1;
+
nentries++;
}
diff --git a/contrib/pg_stat_statements/sql/pg_stat_statements.sql b/contrib/pg_stat_statements/sql/pg_stat_statements.sql
index a8361fd1bf..9e02470dfd 100644
--- a/contrib/pg_stat_statements/sql/pg_stat_statements.sql
+++ b/contrib/pg_stat_statements/sql/pg_stat_statements.sql
@@ -195,4 +195,15 @@ DROP FUNCTION PLUS_TWO(INTEGER);
SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C";
+-- test to see if any plans have been recorded.
+SELECT
+ CASE WHEN good_plan_time > 0 THEN 1 ELSE 0 END,
+ CASE WHEN bad_plan_time > 0 THEN 1 ELSE 0 END,
+ CASE WHEN good_plan_timestamp >= timestamp '1970-01-01 00:00:00' THEN 1 ELSE 0 END,
+ CASE WHEN good_plan_timestamp >= timestamp '1970-01-01 00:00:00' THEN 1 ELSE 0 END
+FROM pg_stat_statements ORDER BY query COLLATE "C";
+
+-- test if there is some text in the recorded plans.
+select substr(good_plan, 0, 11), substr(bad_plan, 0, 11) from pg_stat_statements ORDER BY query COLLATE "C";
+
DROP EXTENSION pg_stat_statements;
smime.p7s
Description: S/MIME Cryptographic Signature
