Thread: Lost logs with csvlog redirected to stderr under WIN32 service

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

On 10/6/21 12:10 AM, Michael Paquier wrote:
> 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.

I don't have a windows machine to test, but this refactor looks good to me.

> +    /* Write to CSV log, if enabled */
> +    if ((Log_destination & LOG_DESTINATION_CSVLOG) != 0)

This was originally "if (Log_destination & LOG_DESTINATION_CSVLOG)" and
other conditions nearby still lack the "!= 0". Whatever the preferred
style, the lines touched by this patch should probably do this consistently.

-- Chris

On Wed, Oct 06, 2021 at 09:33:24PM -0500, Chris Bandy wrote:
> I don't have a windows machine to test, but this refactor looks good to me.

Thanks for the review!  I did test this on Windows, only MSVC builds.

>> +    /* Write to CSV log, if enabled */
>> +    if ((Log_destination & LOG_DESTINATION_CSVLOG) != 0)
>
> This was originally "if (Log_destination & LOG_DESTINATION_CSVLOG)" and
> other conditions nearby still lack the "!= 0". Whatever the preferred
> style, the lines touched by this patch should probably do this consistently.

Yeah.  It looks like using a boolean expression here is easier for my
brain.
--
Michael

On Thu, Oct 07, 2021 at 01:26:46PM +0900, Michael Paquier wrote:
> On Wed, Oct 06, 2021 at 09:33:24PM -0500, Chris Bandy wrote:
>>> +    /* Write to CSV log, if enabled */
>>> +    if ((Log_destination & LOG_DESTINATION_CSVLOG) != 0)
>>
>> This was originally "if (Log_destination & LOG_DESTINATION_CSVLOG)" and
>> other conditions nearby still lack the "!= 0". Whatever the preferred
>> style, the lines touched by this patch should probably do this consistently.
>
> Yeah.  It looks like using a boolean expression here is easier for my
> brain.

I have played with this patch more this morning, adjusted this part,
and applied it as of 8b76f89.
--
Michael