From e9247b42b078560df502f7652c6b274deb8d9ec1 Mon Sep 17 00:00:00 2001 From: "okbob@github.com" Date: Sun, 14 Jun 2026 19:43:04 +0200 Subject: [PATCH] auto_explain.log_queryids this patch implements new auto_explain configuration - auto_explain.log_queryids. It allow to specify list of queryid. Only plans of queries with queryid from specified list will be logged. This allows to use auto_explain in higher load environment for monitoring problematic or extra important queries with lower risk of high log bloating. --- contrib/auto_explain/auto_explain.c | 147 ++++++++++++++++++++- contrib/auto_explain/t/001_auto_explain.pl | 53 ++++++++ doc/src/sgml/auto-explain.sgml | 19 +++ 3 files changed, 218 insertions(+), 1 deletion(-) diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c index 97ce498d0c1..ba571de156e 100644 --- a/contrib/auto_explain/auto_explain.c +++ b/contrib/auto_explain/auto_explain.c @@ -22,6 +22,7 @@ #include "common/pg_prng.h" #include "executor/instrument.h" #include "nodes/makefuncs.h" +#include "nodes/queryjumble.h" #include "nodes/value.h" #include "parser/scansup.h" #include "utils/guc.h" @@ -48,6 +49,7 @@ static int auto_explain_log_level = LOG; static bool auto_explain_log_nested_statements = false; static double auto_explain_sample_rate = 1; static char *auto_explain_log_extension_options = NULL; +static char *auto_explain_log_queryids = NULL; /* * Parsed form of one option from auto_explain.log_extension_options. @@ -81,6 +83,17 @@ static const struct config_enum_entry format_options[] = { {NULL, 0, false} }; +/* + * parsed form of auto_explain.log_queryids. + */ +typedef struct auto_explain_queryids +{ + int nqueryids; + int64 queryId[FLEXIBLE_ARRAY_MEMBER]; +} auto_explain_queryids; + +static auto_explain_queryids *queryId_filter = NULL; + static const struct config_enum_entry loglevel_options[] = { {"debug5", DEBUG5, false}, {"debug4", DEBUG4, false}, @@ -129,6 +142,9 @@ static int auto_explain_split_options(char *rawstring, auto_explain_option *options, int maxoptions, char **errmsg); +static bool check_log_queryids(char **newval, void **extra, GucSource source); +static void assign_log_queryids(const char *newval, void *extra); + /* * Module load callback */ @@ -307,6 +323,17 @@ _PG_init(void) NULL, NULL); + DefineCustomStringVariable("auto_explain.log_queryids", + "Only queries with qyeryid from list will be logged.", + NULL, + &auto_explain_log_queryids, + NULL, + PGC_SUSET | GUC_LIST_INPUT, + 0, + check_log_queryids, + assign_log_queryids, + NULL); + MarkGUCPrefixReserved("auto_explain"); /* Install hooks. */ @@ -318,6 +345,17 @@ _PG_init(void) ExecutorFinish_hook = explain_ExecutorFinish; prev_ExecutorEnd = ExecutorEnd_hook; ExecutorEnd_hook = explain_ExecutorEnd; + + /* + * In almost all cases, the queryid is computed due pg_stat_statements. + * Without log_queryids computing queryid is not necessary, but it can + * be hard to enable or disable queryid in dependecy of log_queryids. + * There are two possibilities - force queryid computing, or ignore + * queries without computed queryid (computing should be forced by setting + * compute_query_id). Boths probably can work, first looks more clean + * at this moment. + */ + EnableQueryId(); } /* @@ -424,6 +462,7 @@ explain_ExecutorEnd(QueryDesc *queryDesc) { MemoryContext oldcxt; double msec; + bool log_filter = true; /* * Make sure we operate in the per-query context, so any cruft will be @@ -431,9 +470,37 @@ explain_ExecutorEnd(QueryDesc *queryDesc) */ oldcxt = MemoryContextSwitchTo(queryDesc->estate->es_query_cxt); + if (queryId_filter) + { + int64 queryId = queryDesc->plannedstmt->queryId; + + /* check if current queryID is in watched queryIds */ + log_filter = false; + + if (queryId != INT64CONST(0)) + { + int i; + + /* + * We expect small number of watched queryids, and then + * a linear seaching is the fastest. As an alternative + * we can sort the array of queryId, and we can search + * there by bisection. + */ + for (i = 0; i < queryId_filter->nqueryids; i++) + { + if (queryId_filter->queryId[i] == queryId) + { + log_filter = true; + break; + } + } + } + } + /* Log plan if duration is exceeded. */ msec = INSTR_TIME_GET_MILLISEC(queryDesc->query_instr->total); - if (msec >= auto_explain_log_min_duration) + if (log_filter && msec >= auto_explain_log_min_duration) { ExplainState *es = NewExplainState(); @@ -827,3 +894,81 @@ auto_explain_split_options(char *rawstring, auto_explain_option *options, return noptions; } + +/* + * log_queryids + */ +static bool +check_log_queryids(char **newval, void **extra, GucSource source) +{ + char *rawstring; + List *elemlist; + ListCell *l; + Size allocsize; + auto_explain_queryids *result; + int i = 0; + + if (*newval == NULL || *newval[0] == '\0') + { + *extra = NULL; + return true; + } + + /* need a modifiable copy of string */ + rawstring = pstrdup(*newval); + + /* Parse string into list of identifiers */ + if (!SplitGUCList(rawstring, ',', &elemlist)) + { + /* syntax error in list */ + GUC_check_errdetail("List syntax is invalid."); + pfree(rawstring); + list_free(elemlist); + return false; + } + + /* Try to allocate an auto_explain_extension_options object. */ + allocsize = offsetof(auto_explain_queryids, queryId) + + sizeof(int64) * list_length(elemlist); + + result = (auto_explain_queryids *) guc_malloc(LOG, allocsize); + if (result == NULL) + return false; + + foreach(l, elemlist) + { + char *tok = (char *) lfirst(l); + char *endptr; + int64 queryId; + + errno = 0; + queryId = strtol(tok, &endptr, 10); + if (errno != 0 || *endptr != '\0' || queryId == INT64CONST(0)) + { + GUC_check_errmsg("queryId \"%s\" is not valid", tok); + pfree(rawstring); + list_free(elemlist); + guc_free(result); + return false; + } + + result->queryId[i++] = queryId; + } + + result->nqueryids = i; + + pfree(rawstring); + list_free(elemlist); + + *extra = result; + + return true; +} + +static void +assign_log_queryids(const char *newval, void *extra) +{ + auto_explain_queryids *myextra = (auto_explain_queryids *) extra; + + queryId_filter = myextra; +} diff --git a/contrib/auto_explain/t/001_auto_explain.pl b/contrib/auto_explain/t/001_auto_explain.pl index f32a5e84f65..148e83f7545 100644 --- a/contrib/auto_explain/t/001_auto_explain.pl +++ b/contrib/auto_explain/t/001_auto_explain.pl @@ -7,6 +7,7 @@ use warnings FATAL => 'all'; use PostgreSQL::Test::Cluster; use PostgreSQL::Test::Utils; use Test::More; +use JSON::PP; # Runs the specified query and returns the emitted server log. # params is an optional hash mapping GUC names to values; @@ -27,6 +28,15 @@ sub query_log return slurp_file($log, $offset); } +sub get_queryid +{ + my ($node, $sql) = @_; + + my $plan = $node->safe_psql('postgres', 'EXPLAIN (VERBOSE, FORMAT JSON) ' . $sql); + + return int(decode_json($plan)->[0]->{"Query Identifier"}); +} + my $node = PostgreSQL::Test::Cluster->new('main'); $node->init(auth_extra => [ '--create-role' => 'regress_user1' ]); $node->append_conf('postgresql.conf', @@ -239,4 +249,47 @@ WHERE module_name = 'auto_explain'; }); like($res, qr/^auto_explain\|t\|auto_explain$/, "pg_get_loaded_modules() ok"); +# test detection of broken format +$log_contents = query_log($node, "SELECT 1;", + { "auto_explain.log_queryids" => "x" }); + +like( + $log_contents, + qr/queryId "x" is not valid/, + "invalid queryid detected"); + +my $query1 = "SELECT * FROM pg_class LIMIT 1"; +my $query2 = "SELECT * FROM pg_proc LIMIT 1"; +my $query3 = "SELECT * FROM pg_namespace LIMIT 1"; + +my $queryid1 = get_queryid($node, $query1); +my $queryid2 = get_queryid($node, $query2); +my $queryid3 = get_queryid($node, $query3); + +my $qids = "$queryid1,$queryid2"; + +$log_contents = query_log($node, $query1, + { "auto_explain.log_queryids" => $qids }); + +like( + $log_contents, + qr/Query Text: SELECT \* FROM pg_class LIMIT 1/, + "plan for query specified by queryid found"); + +$log_contents = query_log($node, $query2, + { "auto_explain.log_queryids" => $qids }); + +like( + $log_contents, + qr/Query Text: SELECT \* FROM pg_proc LIMIT 1/, + "plan for query specified by queryid found"); + +$log_contents = query_log($node, $query3, + { "auto_explain.log_queryids" => $qids }); + +unlike( + $log_contents, + qr/Query Text: SELECT \* FROM pg_namespace LIMIT 1/, + "plan for query with disallowed queryid not found"); + done_testing(); diff --git a/doc/src/sgml/auto-explain.sgml b/doc/src/sgml/auto-explain.sgml index 06a8fcc6c5b..d5d0be08ba5 100644 --- a/doc/src/sgml/auto-explain.sgml +++ b/doc/src/sgml/auto-explain.sgml @@ -63,6 +63,25 @@ LOAD 'auto_explain'; + + + auto_explain.log_queryids (list of integers) + + auto_explain.log_queryids configuration parameter + + + + + auto_explain.log_queryids allows to specify list of queryid. + Only plan of query with queryid from specified list will be logged. When this + parameter is empty (default), the queryid is not used for filtering. This doesn't + disable auto_explain.log_min_duration. auto_explain.log_queryids + and auto_explain.log_min_duration works together. + Only superusers can change this setting. + + + + auto_explain.log_parameter_max_length (integer) -- 2.54.0