From 71498543013ce48be0ae35e6e10b781baf849975 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 | 163 ++++++++++++++++++++- contrib/auto_explain/t/001_auto_explain.pl | 53 +++++++ doc/src/sgml/auto-explain.sgml | 19 +++ 3 files changed, 234 insertions(+), 1 deletion(-) diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c index 97ce498d0c1..6f6db386c41 100644 --- a/contrib/auto_explain/auto_explain.c +++ b/contrib/auto_explain/auto_explain.c @@ -22,8 +22,10 @@ #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/builtins.h" #include "utils/guc.h" #include "utils/varlena.h" @@ -48,6 +50,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 +84,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 +143,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 +324,16 @@ _PG_init(void) NULL, NULL); + DefineCustomStringVariable("auto_explain.log_queryids", + "Only queries with queryId from list will be logged.", + NULL, + &auto_explain_log_queryids, + NULL, + PGC_SUSET, GUC_LIST_INPUT, + check_log_queryids, + assign_log_queryids, + NULL); + MarkGUCPrefixReserved("auto_explain"); /* Install hooks. */ @@ -318,6 +345,12 @@ _PG_init(void) ExecutorFinish_hook = explain_ExecutorFinish; prev_ExecutorEnd = ExecutorEnd_hook; ExecutorEnd_hook = explain_ExecutorEnd; + + /* + * Inform the postmaster that we want to enable query_id calculation if + * compute_query_id is set to auto. + */ + EnableQueryId(); } /* @@ -424,6 +457,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 +465,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 +889,102 @@ 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 = NIL; + ListCell *l; + Size allocsize; + auto_explain_queryids *result; + int i = 0; + + if (*newval == NULL) + { + *extra = NULL; + return true; + } + + /* need a modifiable copy of string */ + rawstring = pstrdup(*newval); + + if (!SplitGUCList(rawstring, ',', &elemlist)) + { + pfree(rawstring); + list_free(elemlist); + + /* syntax error in list */ + GUC_check_errdetail("List syntax is invalid."); + return false; + } + + if (list_length(elemlist) == 0) + { + pfree(rawstring); + list_free(elemlist); + + *extra = NULL; + return true; + } + + /* 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) + { + pfree(rawstring); + list_free(elemlist); + + return false; + } + + foreach(l, elemlist) + { + char *tok = (char *) lfirst(l); + int64 queryId; + ErrorSaveContext escontext = {T_ErrorSaveContext}; + + /* + * queryid is 64bit integer. strtol fails on 32bit or on MSWin. + * In other places, queryid passed (from, to SQL) as generic int8, + * so we can use int8in routine. int8in can raise an exception, + * so pg_strtoint64_safe is used instead. + */ + queryId = pg_strtoint64_safe(tok, (Node *) &escontext); + if (escontext.error_occurred || 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