Re: Patch to implement pg_current_logfile() function

Hi Karl,

I've attached the v15 of the patch that applies your changes/fixes and
remove the call to strtok().

I've not applied patch patch_pg_current_logfile-v14.diff.backoff to
prevent constant call of logfile_writename() on a busy system (errno =
ENFILE | EMFILE). I think this can be done quite simply by testing if
log rotate is still enabled. This is possible because function
logfile_rotate() is already testing if errno = ENFILE | EMFILE and in
this case rotation_disabled is set to true. So the following test should
do the work:

if (log_metainfo_stale && !rotation_disabled)
logfile_writename();

This is included in v15 patch.

I've also not added patches
patch_pg_current_logfile-v14.diff.conditional,
patch_pg_current_logfile-v14.diff.logdest_change and
patch_pg_current_logfile-v14.diff.logdest_change-part2 because the case
your are trying to fix with lot of code can not appears. You said that
when csv logging is turned back on, the stale csv path is written to
current_logfiles. This is not the case, last_csv_file_name is
immediately changed when the log file is open, see open_csvlogfile().
After running your use case I was not able to reproduce the bug you are
describing.

Again, patches patch_pg_current_logfile-v14.diff.doc_linux_default-v2
have not been included because I don't see any reason to talk especially
about systemd. If you talk about systemd you must talk about other
stderr handler by all systems. IMO saying that current_logfile is
present only if logging_collector is enabled and log_destination include
stderr or/and csvlog is enough, no need to talk about systemd and
behavior of Linux distributions.

Regards

Le 23/11/2016 à 10:21, Karl O. Pinc a écrit :
> Hi Gilles,
>
> On Sat, 19 Nov 2016 12:58:47 +0100
> Gilles Darold <gilles(dot)darold(at)dalibo(dot)com> wrote:
>
>> ... attached v14 of the patch.
> Attached are patches for your consideration and review.
> (Including your latest v14 patch for completeness.)
>
> Some of the attached patches (like the GUC symbol
> patch you've seen before) are marked to be submitted
> as separate patches to the maintainers when we send
> them code for review. These need looking over by
> somebody, I hope you, before they get sent on so
> please comment on these if you're not going to look
> at them or if you see a problem with them. (Or if
> you like them. :) Thanks.
>
> I also have comments at the bottom regards problems
> I see but haven't patched.
>
> ---
>
> patch_pg_current_logfile-v14.diff
>
> Applies on top of master.
>
> The current patch.
>
> ---
>
> patch_pg_current_logfile-v14.diff.startup_docs
>
> For consideration of inclusion in "main" patch.
>
> Applies on top of patch_pg_current_logfile-v14.diff
>
> A documentation fix.
>
> (Part of) my previous doc patch was wrong; current_logfiles is not
> unconditionally written on startup.
>
> ---
>
> patch_pg_current_logfile-v14.diff.bool_to_int
>
> Do not include in "main" patch, submit to maintainers separately.
>
> Applies on top of patch_pg_current_logfile-v14.diff
>
> The bool types on the stack in logfile_rotate() are
> my work. Bools on the stack don't make sense as far
> as hardware goes, so the compiler's optimizer should change
> them to int. This patch changes the bools to ints
> should that be to someone's taste.
>
> ---
>
> patch_pg_current_logfile-v14.diff.logdest_change
>
> For consideration of inclusion in "main" patch.
>
> Applies on top of patch_pg_current_logfile-v14.diff.
>
> Fixes a bug where, when log_destination changes and the config
> file is reloaded, a no-longer-used logfile path may be written
> to the current_logfiles file. The chain of events would be
> as follows:
>
> 1) PG configured with csvlog in log_destination. Logs are written.
>
> This makes last_csv_file_name non-NULL.
>
>
> 2) PG config changed to remove csvlog from log_destination
> and SIGHUP sent.
>
> This removes the csvlog path from current_logfiles but does not
> make last_csv_file_name NULL. last_csv_file_name has the old
> path in it.
>
>
> 3) PG configured to add csvlog back to log_destination and
> SIGHUP sent.
>
> When csvlogging is turned back on, the stale csv path is written
> to current_logfiles. This is overwritten as soon as some csv logs
> are written because the new csv logfile must be opened, but this is
> still a problem. Even if it happens to be impossible at the moment
> to get past step 2 to step 3 without having some logs written it seems
> a lot more robust to manually "expire" the last*_file_name variable
> content when log_destination changes.
>
>
> So what the patch does is "scrub" the "last_*file_name" variables
> when the config file changes.
>
> FWIW, I moved the logfile_writename() call toward the top of the
> if block just to keep all the code which sorta-kinda involves
> the old_log_destination variable together.
>
> ---
>
> patch_pg_current_logfile-v14.diff.logdest_change-part2
>
> Do not include in "main" patch, submit to maintainers separately.
>
> Applies on top of patch_pg_current_logfile-v14.diff.logdest_change
>
> Adds a PGLogDestination typedef. A separate patch since this may be
> overkill and more about coding style than anything else.
>
> ---
>
> And now, a series of patches to fix the problem where, at least
> potentially, logfile_writename() gets a ENFILE or EMFILE and
> therefore a log file path does not ever get written to the
> current_logfiles file. The point of this patch series is to retry until
> the content of current_logfiles is correct.
>
> All of these are for consideration of inclusion in "main" patch.
>
>
> patch_pg_current_logfile-v14.diff.retry_current_logfiles-part1
>
> Applies on top of patch_pg_current_logfile-v14.diff.logdest_change
>
> A documentation patch. Notes that (even with retrying) the
> current_logfiles content might not be right.
>
>
> patch_pg_current_logfile-v14.diff.retry_current_logfiles-part2
>
> Applies on top of
> patch_pg_current_logfile-v14.diff.retry_current_logfiles-part1
>
> Remove arguments from logfile_writename(). Use static storage
> instead. We always update last_file_name and last_csv_file_name
> whenever logfile_writename() is called so there's not much of
> a change here.
>
>
>
> patch_pg_current_logfile-v14.diff.retry_current_logfiles-part3
>
> Applies on top of
> patch_pg_current_logfile-v14.diff.retry_current_logfiles-part2
>
> Re-try the write of current_logfiles should it fail because the
> system is too busy.
>
> ---
>
> patch_pg_current_logfile-v14.diff.backoff
>
> Do not include in "main" patch, submit to maintainers separately.
>
> Applies on top of
> patch_pg_current_logfile-v14.diff.retry_current_logfiles-part3
>
> Introduces a backoff when retrying to write the current_logfiles file,
> because retrying when failure is due to a busy system only makes the
> system more busy. This may well be over-engineering but I thought
> I'd present the code and let more experienced people decide.
>
> I have yet to really test this patch.
>
> ---
>
> The remaining patches have to do with coding style and code clarity.
>
> ---
>
> patch_pg_current_logfile-v14.diff.deletion
>
> For consideration of inclusion in "main" patch, otherwise submit to
> maintainers separately.
>
> Applies on top of
> patch_pg_current_logfile-v14.diff.retry_current_logfiles-part3
>
> I find the code to be more understandable if the deletion
> of the current_logfiles file is separated from the updating
> of current_logfiles. It's not that without this patch
> that unnecessary code execution is inefficient, it's that
> the unnecessary code execution makes it hard (for me) to think about
> what's happening where and why.
>
> ---
>
> patch_pg_current_logfile-v14.diff.conditional
>
> For consideration of inclusion in "main" patch, otherwise submit to
> maintainers separately.
>
> Applies on top of patch_pg_current_logfile-v14.diff.deletion
> (Could be changed to apply on top of
> patch_pg_current_logfile-v14.diff.retry_current_logfiles-part3.)
>
> Only change the current_logfiles content on SIGHUP when the content needs
> to be changed.
>
> As above, I understand the code more readily when statements are only
> executed when they need to be executed.
>
> My analysis here is as follows:
>
> There are 9 cases, the combination of 2 sets of 3 possibilities.
>
> syslog is removed from log_destination
> the presence or absence of syslog in log_destination is unchanged
> syslog is added to log_destination
>
> the same 3 cases only regards csvlog
>
> In the no-change case we don't need to do anything
>
> If either syslog or csvlog are added to log_destination then
> the current_logfiles file will be updated on rotation or, in
> the case of adding a csvlog file, on file open.
>
> It is only the removal cases that require the current_logfiles
> file be changed, and that's what the patch does.
>
> ---
>
> patch_pg_current_logfile-v14.diff.codecomment
>
> Do not include in "main" patch, submit to maintainers separately.
>
> Applies on top of
> patch_pg_current_logfile-v14.diff.retry_current_logfiles-part3
>
> Add a comment to the code explaining how an unusual case can come to
> pass.
>
> ---
>
> patch_pg_current_logfile-v14.diff.cleanup_rotate
>
> Do not include in "main" patch, submit to maintainers separately.
>
> Applies on top of
> patch_pg_current_logfile-v14.diff.retry_current_logfiles-part3
>
> Removes a net 10 lines of code, eliminating unnecessary if statements.
> (Refactoring aside, pfree() does nothing when given a NULL pointer.)
>
> It might be a little cleaner to move the declarations of "filename" and
> "csvfilename" into the if blocks that use them, but I didn't do this.
>
> ---
>
> A series of patches which creates symbols for some GUC values which
> appear in multiple places in the code.
>
> Do not include in "main" patch, submit to maintainers separately.
>
>
> patch_pg_current_logfile-v14.diff.abstract_guc_part1
>
> Applies on top of
> patch_pg_current_logfile-v14.diff.retry_current_logfiles-part3
> (And also applies on top of master branch, or really, any of the
> other patches presented in this email.)
>
> Changes code in master branch to create symbols for some GUC values.
>
>
> patch_pg_current_logfile-v14.diff.abstract_guc_part2
>
> Applies on top of patch_pg_current_logfile-v14.diff.abstract_guc_part1
> (and also applies on top of patch_pg_current_logfile-v14.diff, or
> probably any of the other patches in this email)
>
> Changes code in this patch series to use symbols for some GUC values.
>
> ---
>
> I've just started to look at pg_current_logfile() in
> src/backend/utils/adt/misc.c. I believe I've noticed a couple
> of problems. I probably won't have time to write patches until
> next week so I thought I'd simply report what I see and
> let you review what I've got so far.
>
> It looks like under some conditions (typically errors) you
> can return an uninitialized value in log_filename. The
> answer here is probably to write :
>
> log_filename[0] = 0;
>
> somewhere toward the top of the function. And (as now written)
> you also need to put the same statement after the error that
> reports "unexpected line format in file %s" to be sure that
> in that case you're not going to return a pointer to the C
> NULL value.
>
> But also, you can't use strtok() to parse lbuffer because
> the path you're returning can contain a space. (I suspect using
> strstr() to parse on the the first space you find is the way
> to go. You can use the same trick that strtok() uses of sticking
> a 0 byte in in place of the space to get the log format string.)
>
> ---
>
> I'm going to put together a patch, to be sent separately to the
> maintainers when we ask them for final review, which shows what the
> docs/code looks like when current_logfiles always exists and can be an
> empty file. And argue for that. But I've not gotten to this yet.
>
> The good news is that I don't see anything else in syslogger.c to
> comment on or patch. :-)
>
> Regards,
>
>
> Karl <kop(at)meme(dot)com>
> Free Software: "You don't pay back, you pay forward."
> -- Robert A. Heinlein

--
Gilles Darold
Consultant PostgreSQL
http://dalibo.com - http://dalibo.org