From 83a5bd50da25d6a99e5804b0bd268b3a9e86644e Mon Sep 17 00:00:00 2001 From: Michael Paquier Date: Tue, 5 Oct 2021 11:19:46 +0900 Subject: [PATCH v4 2/5] Some refactoring of elog-specific routines This refactors out the following things in elog.c, for ease of use across multiple log destinations: - start_timestamp - log_timestamp - decide if query can be logged - backend type This will be reused by jsonlog. --- src/include/utils/elog.h | 4 + src/backend/utils/error/elog.c | 141 +++++++++++++++++++++------------ 2 files changed, 94 insertions(+), 51 deletions(-) diff --git a/src/include/utils/elog.h b/src/include/utils/elog.h index f53607e12e..bc6f362b6a 100644 --- a/src/include/utils/elog.h +++ b/src/include/utils/elog.h @@ -441,6 +441,10 @@ extern bool syslog_split_messages; extern void DebugFileOpen(void); extern char *unpack_sql_state(int sql_state); extern bool in_error_recursion_trouble(void); +extern char *get_formatted_start_time(void); +extern char *get_formatted_log_time(void); +extern bool check_log_of_query(ErrorData *edata); +extern const char *get_backend_type_for_log(void); #ifdef HAVE_SYSLOG extern void set_syslog_parameters(const char *ident, int facility); diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c index 2af87ee3bd..3d89937322 100644 --- a/src/backend/utils/error/elog.c +++ b/src/backend/utils/error/elog.c @@ -175,8 +175,6 @@ static const char *err_gettext(const char *str) pg_attribute_format_arg(1); static pg_noinline void set_backtrace(ErrorData *edata, int num_skip); static void set_errdata_field(MemoryContextData *cxt, char **ptr, const char *str); static void write_console(const char *line, int len); -static void setup_formatted_log_time(void); -static void setup_formatted_start_time(void); static const char *process_log_prefix_padding(const char *p, int *padding); static void log_line_prefix(StringInfo buf, ErrorData *edata); static void write_csvlog(ErrorData *edata); @@ -2289,14 +2287,23 @@ write_console(const char *line, int len) } /* - * setup formatted_log_time, for consistent times between CSV and regular logs + * get_formatted_log_time -- compute and get the log timestamp. + * + * The timestamp is computed if not set yet, so as it is kept consistent + * among all the log destinations that require it to be consistent. Note + * that the computed timestamp is returned in a static buffer, not + * palloc()'d. */ -static void -setup_formatted_log_time(void) +char * +get_formatted_log_time(void) { pg_time_t stamp_time; char msbuf[13]; + /* leave if already computed */ + if (formatted_log_time[0] != '\0') + return formatted_log_time; + if (!saved_timeval_set) { gettimeofday(&saved_timeval, NULL); @@ -2318,16 +2325,25 @@ setup_formatted_log_time(void) /* 'paste' milliseconds into place... */ sprintf(msbuf, ".%03d", (int) (saved_timeval.tv_usec / 1000)); memcpy(formatted_log_time + 19, msbuf, 4); + + return formatted_log_time; } /* - * setup formatted_start_time + * get_formatted_start_time -- compute and get the start timestamp. + * + * The timestamp is computed if not set yet. Note that the computed + * timestamp is returned in a static buffer, not palloc()'d. */ -static void -setup_formatted_start_time(void) +char * +get_formatted_start_time(void) { pg_time_t stamp_time = (pg_time_t) MyStartTime; + /* leave if already computed */ + if (formatted_start_time[0] != '\0') + return formatted_start_time; + /* * Note: we expect that guc.c will ensure that log_timezone is set up (at * least with a minimal GMT value) before Log_line_prefix can become @@ -2336,6 +2352,49 @@ setup_formatted_start_time(void) pg_strftime(formatted_start_time, FORMATTED_TS_LEN, "%Y-%m-%d %H:%M:%S %Z", pg_localtime(&stamp_time, log_timezone)); + + return formatted_start_time; +} + +/* + * check_log_of_query -- check if a query can be logged + */ +bool +check_log_of_query(ErrorData *edata) +{ + /* log required? */ + if (!is_log_level_output(edata->elevel, log_min_error_statement)) + return false; + + /* query log wanted? */ + if (edata->hide_stmt) + return false; + + /* query string available? */ + if (debug_query_string == NULL) + return false; + + return true; +} + +/* + * get_backend_type_for_log -- backend type for log entries + * + * Returns a pointer to a static buffer, not palloc()'d. + */ +const char * +get_backend_type_for_log(void) +{ + const char *backend_type_str; + + if (MyProcPid == PostmasterPid) + backend_type_str = "postmaster"; + else if (MyBackendType == B_BG_WORKER) + backend_type_str = MyBgworkerEntry->bgw_type; + else + backend_type_str = GetBackendTypeDesc(MyBackendType); + + return backend_type_str; } /* @@ -2466,14 +2525,7 @@ log_line_prefix(StringInfo buf, ErrorData *edata) break; case 'b': { - const char *backend_type_str; - - if (MyProcPid == PostmasterPid) - backend_type_str = "postmaster"; - else if (MyBackendType == B_BG_WORKER) - backend_type_str = MyBgworkerEntry->bgw_type; - else - backend_type_str = GetBackendTypeDesc(MyBackendType); + const char *backend_type_str = get_backend_type_for_log(); if (padding != 0) appendStringInfo(buf, "%*s", padding, backend_type_str); @@ -2561,7 +2613,10 @@ log_line_prefix(StringInfo buf, ErrorData *edata) appendStringInfo(buf, "%ld", log_line_number); break; case 'm': - setup_formatted_log_time(); + /* force a log timestamp reset */ + formatted_log_time[0] = '\0'; + (void) get_formatted_log_time(); + if (padding != 0) appendStringInfo(buf, "%*s", padding, formatted_log_time); else @@ -2602,12 +2657,14 @@ log_line_prefix(StringInfo buf, ErrorData *edata) } break; case 's': - if (formatted_start_time[0] == '\0') - setup_formatted_start_time(); - if (padding != 0) - appendStringInfo(buf, "%*s", padding, formatted_start_time); - else - appendStringInfoString(buf, formatted_start_time); + { + char *start_time = get_formatted_start_time(); + + if (padding != 0) + appendStringInfo(buf, "%*s", padding, start_time); + else + appendStringInfoString(buf, start_time); + } break; case 'i': if (MyProcPort) @@ -2763,6 +2820,8 @@ write_csvlog(ErrorData *edata) { StringInfoData buf; bool print_stmt = false; + char *start_time; + char *log_time; /* static counter for line numbers */ static long log_line_number = 0; @@ -2785,17 +2844,9 @@ write_csvlog(ErrorData *edata) initStringInfo(&buf); - /* - * timestamp with milliseconds - * - * Check if the timestamp is already calculated for the syslog message, - * and use it if so. Otherwise, get the current timestamp. This is done - * to put same timestamp in both syslog and csvlog messages. - */ - if (formatted_log_time[0] == '\0') - setup_formatted_log_time(); - - appendStringInfoString(&buf, formatted_log_time); + /* timestamp with milliseconds */ + log_time = get_formatted_log_time(); + appendStringInfoString(&buf, log_time); appendStringInfoChar(&buf, ','); /* username */ @@ -2853,9 +2904,8 @@ write_csvlog(ErrorData *edata) appendStringInfoChar(&buf, ','); /* session start timestamp */ - if (formatted_start_time[0] == '\0') - setup_formatted_start_time(); - appendStringInfoString(&buf, formatted_start_time); + start_time = get_formatted_start_time(); + appendStringInfoString(&buf, start_time); appendStringInfoChar(&buf, ','); /* Virtual transaction id */ @@ -2906,10 +2956,7 @@ write_csvlog(ErrorData *edata) appendStringInfoChar(&buf, ','); /* user query --- only reported if not disabled by the caller */ - if (is_log_level_output(edata->elevel, log_min_error_statement) && - debug_query_string != NULL && - !edata->hide_stmt) - print_stmt = true; + print_stmt = check_log_of_query(edata); if (print_stmt) appendCSVLiteral(&buf, debug_query_string); appendStringInfoChar(&buf, ','); @@ -2943,13 +2990,7 @@ write_csvlog(ErrorData *edata) appendStringInfoChar(&buf, ','); /* backend type */ - if (MyProcPid == PostmasterPid) - appendCSVLiteral(&buf, "postmaster"); - else if (MyBackendType == B_BG_WORKER) - appendCSVLiteral(&buf, MyBgworkerEntry->bgw_type); - else - appendCSVLiteral(&buf, GetBackendTypeDesc(MyBackendType)); - + appendCSVLiteral(&buf, get_backend_type_for_log()); appendStringInfoChar(&buf, ','); /* leader PID */ @@ -3100,9 +3141,7 @@ send_message_to_server_log(ErrorData *edata) /* * If the user wants the query that generated this error logged, do it. */ - if (is_log_level_output(edata->elevel, log_min_error_statement) && - debug_query_string != NULL && - !edata->hide_stmt) + if (check_log_of_query(edata)) { log_line_prefix(&buf, edata); appendStringInfoString(&buf, _("STATEMENT: ")); -- 2.33.0