Hi all, While reviewing the code of elog.c to plug in JSON as a file-based log destination, I have found what looks like a bug in send_message_to_server_log(). If LOG_DESTINATION_CSVLOG is enabled, we would do the following to make sure that the log entry is not missed: - If redirection_done or in the logging collector, call write_csvlog() to write the CSV entry using the piped protocol or write directly if the logging collector does the call. - If the log redirection is not available yet, we'd just call write_console() to redirect the message to stderr, which would be done if it was not done in the code block for stderr before handling CSV to avoid duplicates. This uses a condition that matches the one based on Log_destination and whereToSendOutput.
Now, in the stderr code path, we would actually do more than that: - write_pipe_chunks() for a non-syslogger process if redirection is done. - If there is no redirection, redirect to eventlog when running as a service on WIN32, or simply stderr with write_console(). So at the end, if one enables only csvlog, we would not capture any logs if the redirection is not ready yet on WIN32 when running as a service, meaning that we could lose some precious information if there is for example a startup failure. This choice comes from fd801f4 in 2007, that introduced csvlog as a log_destination. I think that there is a good argument for back-patching a fix, but I don't recall seeing anybody complaining about that and I just need that for the business with JSON. I have thought about various ways to fix that, and finished with a solution where we handle csvlog first, and fallback to stderr after so as there is only one code path for stderr, as of the attached. This reduces a bit the confusion around the handling of the stderr data that gets free()'d in more code paths than really needed. Thoughts or objections? -- Michael
From a7b10adbe871a2330ddde9e593480171a3ef83f2 Mon Sep 17 00:00:00 2001
From: Michael Paquier <mich...@paquier.xyz>
Date: Wed, 6 Oct 2021 14:07:20 +0900
Subject: [PATCH] Fix fallback to stderr when using only csvlog
send_message_to_server_log() would force a redirection of a log entry to
stderr in some cases, like the syslogger not being available yet. If
this happens, csvlog falls back to stderr to log something. The code
was organized so as stderr was happening before csvlog, with csvlog
calling checking for the same conditions as the stderr code path for a
second time, with a log handling buggy for Windows.
Instead, move the csvlog handling to be before stderr, tracking down if
it is necessary to log something to stderr after. The reduces the
handling of stderr to a single code path, and fixes one issue with the
case of a Windows service, where stderr is not available, where we would
lose log entries that should have been redirected from csvlog to
stderr.
---
src/backend/utils/error/elog.c | 56 ++++++++++++++++------------------
1 file changed, 26 insertions(+), 30 deletions(-)
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index 2af87ee3bd..2a88ef9e3b 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -3008,6 +3008,7 @@ static void
send_message_to_server_log(ErrorData *edata)
{
StringInfoData buf;
+ bool fallback_to_stderr = false;
initStringInfo(&buf);
@@ -3159,8 +3160,29 @@ send_message_to_server_log(ErrorData *edata)
}
#endif /* WIN32 */
- /* Write to stderr, if enabled */
- if ((Log_destination & LOG_DESTINATION_STDERR) || whereToSendOutput == DestDebug)
+ /* Write to CSV log, if enabled */
+ if ((Log_destination & LOG_DESTINATION_CSVLOG) != 0)
+ {
+ /*
+ * Send CSV data if it's safe to do so (syslogger doesn't need the
+ * pipe). If this is not possible, fallback to an entry written
+ * to stderr.
+ */
+ if (redirection_done || MyBackendType == B_LOGGER)
+ {
+ write_csvlog(edata);
+ }
+ else
+ fallback_to_stderr = true;
+ }
+
+ /*
+ * Write to stderr, if enabled or if required because of a previous
+ * limitation.
+ */
+ if ((Log_destination & LOG_DESTINATION_STDERR) ||
+ whereToSendOutput == DestDebug ||
+ fallback_to_stderr)
{
/*
* Use the chunking protocol if we know the syslogger should be
@@ -3189,34 +3211,8 @@ send_message_to_server_log(ErrorData *edata)
if (MyBackendType == B_LOGGER)
write_syslogger_file(buf.data, buf.len, LOG_DESTINATION_STDERR);
- /* Write to CSV log if enabled */
- if (Log_destination & LOG_DESTINATION_CSVLOG)
- {
- if (redirection_done || MyBackendType == B_LOGGER)
- {
- /*
- * send CSV data if it's safe to do so (syslogger doesn't need the
- * pipe). First get back the space in the message buffer.
- */
- pfree(buf.data);
- write_csvlog(edata);
- }
- else
- {
- /*
- * syslogger not up (yet), so just dump the message to stderr,
- * unless we already did so above.
- */
- if (!(Log_destination & LOG_DESTINATION_STDERR) &&
- whereToSendOutput != DestDebug)
- write_console(buf.data, buf.len);
- pfree(buf.data);
- }
- }
- else
- {
- pfree(buf.data);
- }
+ /* No more need of the message formatted for stderr */
+ pfree(buf.data);
}
/*
--
2.33.0
signature.asc
Description: PGP signature
