From b5e779771e8a7582951aff6f43a716e9e5975884 Mon Sep 17 00:00:00 2001 From: "Sergey Solovev" Date: Thu, 4 Jul 2024 17:02:13 +0300 Subject: [PATCH] Add log_transaction configuration setting This setting has same behaviour as log_statement - it filter out statements that should not be logged. But works with trasactions, that were sampled using log_transaction_sample_rate setting. Such feature might be helpful to avoid excessive log messages count. At least, filter out SELECTs. --- doc/src/sgml/config.sgml | 23 +++++++++++++ src/backend/tcop/fastpath.c | 2 +- src/backend/tcop/postgres.c | 51 +++++++++++++++++++++++++---- src/backend/utils/misc/guc_tables.c | 11 +++++++ src/include/tcop/tcopprot.h | 3 +- 5 files changed, 81 insertions(+), 9 deletions(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index 17d84bd321..41939b4e3b 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -7049,6 +7049,29 @@ local0.* /var/log/postgresql + + log_transaction (enum) + + log_transaction configuration parameter + + + + + Controls which SQL statements in sampled transaction are logged. Transaction is + getting sampled according to setting. + Valid values are same as for : none (off), + ddl, mod, and all (all statements). + Behaviour also similar to . + + + + The default is all. + Only superusers and users with the appropriate SET + privilege can change this setting. + + + + log_startup_progress_interval (integer) diff --git a/src/backend/tcop/fastpath.c b/src/backend/tcop/fastpath.c index deac71335c..3293f75400 100644 --- a/src/backend/tcop/fastpath.c +++ b/src/backend/tcop/fastpath.c @@ -306,7 +306,7 @@ HandleFunctionRequest(StringInfo msgBuf) /* * Emit duration logging if appropriate. */ - switch (check_log_duration(msec_str, was_logged)) + switch (check_log_duration(msec_str, was_logged, NIL)) { case 1: ereport(LOG, diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c index e39c6804a7..7f264fa07b 100644 --- a/src/backend/tcop/postgres.c +++ b/src/backend/tcop/postgres.c @@ -94,6 +94,8 @@ bool Log_disconnections = false; int log_statement = LOGSTMT_NONE; +int log_transaction = LOGSTMT_ALL; + /* GUC variable for maximum stack depth (measured in kilobytes) */ int max_stack_depth = 100; @@ -180,6 +182,7 @@ static int SocketBackend(StringInfo inBuf); static int ReadCommand(StringInfo inBuf); static void forbidden_in_wal_sender(char firstchar); static bool check_log_statement(List *stmt_list); +static bool check_log_transaction_statement(List *stmt_list); static int errdetail_execute(List *raw_parsetree_list); static int errdetail_params(ParamListInfo params); static int errdetail_abort(void); @@ -1358,7 +1361,7 @@ exec_simple_query(const char *query_string) /* * Emit duration logging if appropriate. */ - switch (check_log_duration(msec_str, was_logged)) + switch (check_log_duration(msec_str, was_logged, parsetree_list)) { case 1: ereport(LOG, @@ -1594,7 +1597,7 @@ exec_parse_message(const char *query_string, /* string to execute */ /* * Emit duration logging if appropriate. */ - switch (check_log_duration(msec_str, false)) + switch (check_log_duration(msec_str, false, NIL)) { case 1: ereport(LOG, @@ -2048,7 +2051,7 @@ exec_bind_message(StringInfo input_message) /* * Emit duration logging if appropriate. */ - switch (check_log_duration(msec_str, false)) + switch (check_log_duration(msec_str, false, NIL)) { case 1: ereport(LOG, @@ -2298,7 +2301,7 @@ exec_execute_message(const char *portal_name, long max_rows) /* * Emit duration logging if appropriate. */ - switch (check_log_duration(msec_str, was_logged)) + switch (check_log_duration(msec_str, was_logged, portal->stmts)) { case 1: ereport(LOG, @@ -2358,6 +2361,27 @@ check_log_statement(List *stmt_list) return false; } +static bool +check_log_transaction_statement(List *stmt_list) +{ + ListCell *stmt_item; + if (log_transaction == LOGSTMT_NONE) + return false; + if (log_transaction == LOGSTMT_ALL) + return true; + + /* Else we have to inspect the statement(s) to see whether to log */ + foreach (stmt_item, stmt_list) + { + Node *stmt = (Node *)lfirst(stmt_item); + + if (GetCommandLogLevel(stmt) <= log_transaction) + return true; + } + + return false; +} + /* * check_log_duration * Determine whether current command's duration should be logged @@ -2374,9 +2398,13 @@ check_log_statement(List *stmt_list) * * was_logged should be true if caller already logged query details (this * essentially prevents 2 from being returned). + * + * stmts can be either raw grammar output or a list of planned + * statements that were executed during current transaction or NIL if + * tag could not be determined. */ int -check_log_duration(char *msec_str, bool was_logged) +check_log_duration(char *msec_str, bool was_logged, List *stmts) { if (log_duration || log_min_duration_sample >= 0 || log_min_duration_statement >= 0 || xact_is_sampled) @@ -2418,11 +2446,20 @@ check_log_duration(char *msec_str, bool was_logged) (log_statement_sample_rate == 1 || pg_prng_double(&pg_global_prng_state) <= log_statement_sample_rate); - if (exceeded_duration || in_sample || log_duration || xact_is_sampled) + /* + * Check than current statement should be logged as transaction sampled statement according + * to log_transaction paramenter. Some statements' tags could not be determined (like PARSE or BIND), + * for this kinds of statements NIL passed - this is indicator to log it without paramenter check + * for compatibility with old code. + */ + if (!in_sample) + in_sample = (stmts == NIL || check_log_transaction_statement(stmts)) && xact_is_sampled; + + if (exceeded_duration || in_sample || log_duration) { snprintf(msec_str, 32, "%ld.%03d", secs * 1000 + msecs, usecs % 1000); - if ((exceeded_duration || in_sample || xact_is_sampled) && !was_logged) + if ((exceeded_duration || in_sample) && !was_logged) return 2; else return 1; diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c index d28b0bcb40..a6f80550cb 100644 --- a/src/backend/utils/misc/guc_tables.c +++ b/src/backend/utils/misc/guc_tables.c @@ -4864,6 +4864,17 @@ struct config_enum ConfigureNamesEnum[] = NULL, NULL, NULL }, + { + {"log_transaction", PGC_SUSET, LOGGING_WHAT, + gettext_noop("Sets the type of statements logged when transaction is sampled."), + NULL + }, + &log_transaction, + LOGSTMT_ALL, log_statement_options, + NULL, NULL, NULL + }, + + { {"syslog_facility", PGC_SIGHUP, LOGGING_WHERE, gettext_noop("Sets the syslog \"facility\" to be used when syslog enabled."), diff --git a/src/include/tcop/tcopprot.h b/src/include/tcop/tcopprot.h index 643ce9cffa..a1a4474b1c 100644 --- a/src/include/tcop/tcopprot.h +++ b/src/include/tcop/tcopprot.h @@ -42,6 +42,7 @@ typedef enum extern PGDLLIMPORT bool Log_disconnections; extern PGDLLIMPORT int log_statement; +extern PGDLLIMPORT int log_transaction; /* Flags for restrict_nonsystem_relation_kind value */ #define RESTRICT_RELKIND_VIEW 0x01 @@ -82,7 +83,7 @@ extern void PostgresMain(const char *dbname, extern long get_stack_depth_rlimit(void); extern void ResetUsage(void); extern void ShowUsage(const char *title); -extern int check_log_duration(char *msec_str, bool was_logged); +extern int check_log_duration(char *msec_str, bool was_logged, List *stmts); extern void set_debug_options(int debug_flag, GucContext context, GucSource source); extern bool set_plan_disabling_options(const char *arg, -- 2.34.1