appender: prune old files at startup

[kaffarell]

The prune_old_logs function only gets called when we rollover the appender. The problem is that at startup we create an initial log file without rolling over, if e.g., the executable then exits before rolling over for the first time, we never call prune_old_logs.

E.g.: If we have a tracing-appender that rolls over every minute and we have a max_files parameter of 2. Running the program (which prints a single log line and exits) every minute, will result in a new log file everytime without deleting the old ones.

Fixes: #2937

[kaffarell]

Thanks for this thorough writeup!

On consideration, I think it's fine to occasionally prune to max - 1 — after all, it's a maximum, not a guaranteed count. However, this needs an edit to documentation so users can calibrate their expectations — if you must retain N days of logs, then max = N + 1!

This is kind of where my approach has a flaw. Because the prune_old_logs function expects to be called before refresh_writer (which creates a new file) it truncates the files to n-1 (as it is written in a comment in the function). BUT as you said, if we document this I would be fine with it.

It looks like everything's already set up to do that properly, IF Inner::should_rollover happens to return an affirmative on the first check. I think you can provoke this by changing line 531 of Inner::new() to be let next_date = rotation.round_date(&now); — the inner will still start out with the correct writer filename, but refresh_writer will get called on the first write and will immediately re-open that correct file after doing a prune.

This will call create_writer twice and do this (for two log lines):

create_writer
write
should rollover: yes
refresh_writer
prune_old_logs
create_writer
write
should rollover: no

instead of this:

prune_old_logs
create_writer
write
should rollover: no
write
should rollover: no

And for a max_log_files of 2 it will never create more than 1 file.

[nfagerlund]

Yeah, gotta admit the extra thrash from doing create_writer twice on the first write isn't ideal. 🤨 I feel like there's got to be an elegant design for this, but ah well.

At any rate, I'd accept "purge on startup" as long as it was accompanied by a docs change. Any performance hit is likely negligible.

[kaffarell]

@nfagerlund Added a commit with the documentation update. I don't really like my explanation and wording, so please correct me!

[kaffarell]

Thanks!