From 6a9f79190b42ab8a6df655b1c290fa2b15b8480e Mon Sep 17 00:00:00 2001 From: diphantxm Date: Fri, 31 Jan 2025 13:31:50 +0300 Subject: [PATCH] parameter max_log_size to truncate logs There is no need to log the entire query, because it may be large and take lots of space on disk. Parameter max_log_size set the maximum length for logged query. Everything beyond that length is truncated. Value 0 disables the parameter. --- doc/src/sgml/config.sgml | 16 +++++++ src/backend/tcop/postgres.c | 18 ++++++- src/backend/utils/error/elog.c | 47 +++++++++++++++++++ src/backend/utils/misc/guc_tables.c | 12 +++++ src/backend/utils/misc/postgresql.conf.sample | 2 + src/bin/pg_ctl/t/004_logrotate.pl | 15 ++++++ src/include/utils/elog.h | 4 ++ 7 files changed, 112 insertions(+), 2 deletions(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index c1674c22cb21..450377de327d 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -8135,6 +8135,22 @@ log_line_prefix = '%m [%p] %q%u@%d/%a ' + + max_log_size (integer) + + max_log_size configuration parameter + + + + + If greater than zero, each query logged is truncated to this many bytes. + Zero disables the setting. + If this value is specified without units, it is taken as bytes. + This feature is disabled by default. + + + + diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c index dc4c600922df..a4163a21fc76 100644 --- a/src/backend/tcop/postgres.c +++ b/src/backend/tcop/postgres.c @@ -71,6 +71,7 @@ #include "tcop/pquery.h" #include "tcop/tcopprot.h" #include "tcop/utility.h" +#include "utils/elog.h" #include "utils/guc_hooks.h" #include "utils/injection_point.h" #include "utils/lsyscache.h" @@ -1018,11 +1019,22 @@ exec_simple_query(const char *query_string) bool was_logged = false; bool use_implicit_block; char msec_str[32]; + char* truncated_query = NULL; + const char* query_log; /* * Report query to various monitoring facilities. */ debug_query_string = query_string; + if (need_truncate_query_log(query_string)) + { + truncated_query = truncate_query_log(query_string); + query_log = truncated_query; + } + else + { + query_log = query_string; + } pgstat_report_activity(STATE_RUNNING, query_string); @@ -1067,7 +1079,7 @@ exec_simple_query(const char *query_string) if (check_log_statement(parsetree_list)) { ereport(LOG, - (errmsg("statement: %s", query_string), + (errmsg("statement: %s", query_log), errhidestmt(true), errdetail_execute(parsetree_list))); was_logged = true; @@ -1367,7 +1379,7 @@ exec_simple_query(const char *query_string) case 2: ereport(LOG, (errmsg("duration: %s ms statement: %s", - msec_str, query_string), + msec_str, query_log), errhidestmt(true), errdetail_execute(parsetree_list))); break; @@ -1378,6 +1390,8 @@ exec_simple_query(const char *query_string) TRACE_POSTGRESQL_QUERY_DONE(query_string); + if (truncated_query) + pfree(truncated_query); debug_query_string = NULL; } diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c index 47af743990fe..9ed798cf8322 100644 --- a/src/backend/utils/error/elog.c +++ b/src/backend/utils/error/elog.c @@ -112,6 +112,7 @@ int Log_destination = LOG_DESTINATION_STDERR; char *Log_destination_string = NULL; bool syslog_sequence_numbers = true; bool syslog_split_messages = true; +int max_log_size = 0; /* Processed form of backtrace_functions GUC */ static char *backtrace_function_list; @@ -1693,11 +1694,18 @@ EmitErrorReport(void) { ErrorData *edata = &errordata[errordata_stack_depth]; MemoryContext oldcontext; + char* truncated_query = NULL; recursion_depth++; CHECK_STACK_DEPTH(); oldcontext = MemoryContextSwitchTo(edata->assoc_context); + if (need_truncate_query_log(debug_query_string)) + { + truncated_query = truncate_query_log(debug_query_string); + debug_query_string = truncated_query; + } + /* * Reset the formatted timestamp fields before emitting any logs. This * includes all the log destinations and emit_log_hook, as the latter @@ -1738,6 +1746,9 @@ EmitErrorReport(void) MemoryContextSwitchTo(oldcontext); recursion_depth--; + + if (truncated_query) + pfree(truncated_query); } /* @@ -3814,3 +3825,39 @@ write_stderr(const char *fmt,...) #endif va_end(ap); } + +/* + * Apply truncation to build query that will be logged. + * + * If query needs to be truncated, copied will be set to true + * and returned string must be freed +*/ +char* +truncate_query_log(const char* query) +{ + size_t truncated_query_len; + char* truncatd_query; + size_t query_len; + + if (!query) + return NULL; + + query_len = strlen(query); + truncated_query_len = pg_mbcliplen(query, query_len, max_log_size); + truncatd_query = (char *) palloc(truncated_query_len+1); + memcpy(truncatd_query, query, truncated_query_len); + truncatd_query[truncated_query_len] = '\0'; + return truncatd_query; +} + +/* + * Checks if query should be truncated + * according to max_log_size +*/ +bool +need_truncate_query_log(const char* query) +{ + if (!query) + return false; + return !(max_log_size == 0 || strlen(query) < max_log_size); +} diff --git a/src/backend/utils/misc/guc_tables.c b/src/backend/utils/misc/guc_tables.c index 60b12446a1c9..b935195230b7 100644 --- a/src/backend/utils/misc/guc_tables.c +++ b/src/backend/utils/misc/guc_tables.c @@ -3860,6 +3860,18 @@ struct config_int ConfigureNamesInt[] = NULL, NULL, NULL }, + { + {"max_log_size", PGC_SUSET, LOGGING_WHAT, + gettext_noop("Sets max size in bytes of logged statement."), + NULL, + GUC_UNIT_BYTE + }, + &max_log_size, + 0, + 0, INT_MAX, + NULL, NULL, NULL + }, + /* End-of-list marker */ { {NULL, 0, 0, NULL, NULL}, NULL, 0, 0, 0, NULL, NULL, NULL diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index 34826d01380b..14b2fa456181 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -638,6 +638,8 @@ # bind-parameter values to N bytes; # -1 means print in full, 0 disables #log_statement = 'none' # none, ddl, mod, all +#max_log_size = 0 # max size of logged statement + # 0 disables the feature #log_replication_commands = off #log_temp_files = -1 # log temporary files equal or larger # than the specified size in kilobytes; diff --git a/src/bin/pg_ctl/t/004_logrotate.pl b/src/bin/pg_ctl/t/004_logrotate.pl index d78360e6d1ae..c072b68c68ab 100644 --- a/src/bin/pg_ctl/t/004_logrotate.pl +++ b/src/bin/pg_ctl/t/004_logrotate.pl @@ -69,6 +69,7 @@ sub check_log_pattern # these ensure stability of test results: log_rotation_age = 0 lc_messages = 'C' +max_log_size = 32 )); $node->start(); @@ -135,6 +136,20 @@ sub check_log_pattern check_log_pattern('csvlog', $new_current_logfiles, 'syntax error', $node); check_log_pattern('jsonlog', $new_current_logfiles, 'syntax error', $node); +$node->psql('postgres', 'INSERT INTO SOME_NON_EXISTANT_TABLE VALUES (TEST)'); +for (my $attempts = 0; $attempts < $max_attempts; $attempts++) +{ + eval { + $current_logfiles = slurp_file($node->data_dir . '/current_logfiles'); + }; + last unless $@; + usleep(100_000); +} +die $@ if $@; +check_log_pattern('stderr', $current_logfiles, 'INSERT INTO SOME_NON_EXISTANT_TA(?!(BLE VALUES \(TEST\)))', $node); +check_log_pattern('csvlog', $current_logfiles, 'INSERT INTO SOME_NON_EXISTANT_TA(?!(BLE VALUES \(TEST\)))', $node); +check_log_pattern('jsonlog', $current_logfiles, 'INSERT INTO SOME_NON_EXISTANT_TA(?!(BLE VALUES \(TEST\)))', $node); + $node->stop(); done_testing(); diff --git a/src/include/utils/elog.h b/src/include/utils/elog.h index 5eac0e16970c..859bead4d5a8 100644 --- a/src/include/utils/elog.h +++ b/src/include/utils/elog.h @@ -493,6 +493,7 @@ extern PGDLLIMPORT int Log_destination; extern PGDLLIMPORT char *Log_destination_string; extern PGDLLIMPORT bool syslog_sequence_numbers; extern PGDLLIMPORT bool syslog_split_messages; +extern PGDLLIMPORT int max_log_size; /* Log destination bitmap */ #define LOG_DESTINATION_STDERR 1 @@ -508,6 +509,9 @@ extern void DebugFileOpen(void); extern char *unpack_sql_state(int sql_state); extern bool in_error_recursion_trouble(void); +extern bool need_truncate_query_log(const char* query); +extern char* truncate_query_log(const char* query); + /* Common functions shared across destinations */ extern void reset_formatted_start_time(void); extern char *get_formatted_start_time(void);