Interoperate with external log rotation

[mmirate]

flexi_logger's log rotation system is okay, but sometimes there are external requirements to do really creative things like calendar-based rotation or gzipping of rotated files. The best way to do such things is to let the logrotate daemon handle the rotation, and arrange for it to send a SIGHUP to the program after the file has been renamed, at which point the program knows it should reopen the configured logging filename in order to continue writing to the new file rather than the rotated file. (This also has the advantage that if the program crashes, there is no chance of losing an entire logfile because the background thread was doing some work during the crash.) However, it seems there is no functionality here to simply tell the file writer to reopen a new file at the same path.

[emabee]

The now published version 0.22.1 has an optional feature external_rotation which is supposed to deliver what you need. It works well on windows, but the dedicated tests break on linux and macos - it is not yet clear to me where the issue is and whether it is just a test issue.

[mmirate]

Ouch. logrotate is Unix-specific. I'll take a look at those tests this weekend.

[emabee]

There are two new tests, test_external_rotation_1.rs and 2 which currently do not assert, they just print some info. On windows, everything works, the asserts would be fine. On Ubuntu and MacOS (GitHub’s test environment) it looks as if the notifications wouldn’t work.

[emabee]

I extracted the issue into a smaller reproduction scenario, see https://github.com/emabee/dummy; it is an empty lib with a single test.

To ensure that the event receiver and the causing process are two different processes, the test spawns two child processes (with its own image):

• one writes 400 lines into a file and monitors events for this file and recreates the file if a respective event is received
• the other renames and deletes the file a couple of times.

The test is successful if all renames and deletions work, and if finally three renamed files exist, and the original.

Locally, on my windows machine, the test runs successful.
On github, it fails

• on windows, because the deletion events are not received
• on linux, because no events are received at all.
• on macos, the concurrency of the two children seems not to work; but an earlier version where a single process did both jobs also failed to produce the right set of events.

The local successful windows-based runs show output like:

Watcher set up for \\?\C:\dev\rust\projects\dummy\logs

running 1 test
executor 1
Renaming the log file "logs/test.txt" to "logs/moved\\file0.txt"
  Reopening the file! (in loop 30)
Renaming the log file "logs/test.txt" to "logs/moved\\file1.txt"
  Reopening the file! (in loop 56)
Renaming the log file "logs/test.txt" to "logs/moved\\file2.txt"
  Reopening the file! (in loop 82)
Removed the log file "logs/test.txt"
  Reopening the file! (in loop 108)
Removed the log file "logs/test.txt"
  Reopening the file! (in loop 134)
Removed the log file "logs/test.txt"
  Reopening the file! (in loop 160)
test test_rotations ... ok

test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.46s


\\?\C:\dev\rust\projects\dummy\logs\test.txt with 239 lines
\\?\C:\dev\rust\projects\dummy\logs\moved\file0.txt with 30 lines
\\?\C:\dev\rust\projects\dummy\logs\moved\file1.txt with 26 lines
\\?\C:\dev\rust\projects\dummy\logs\moved\file2.txt with 26 lines
Found 321 lines in all files together
Output file ends with ->YYY 399 AAA<-

Note that each "Renaming..." and each "Removed..." is following by a "Reopening ...", which indicates that the event mechanism worked.

[mmirate]

Interesting. It appears that, in short, notify is a leaky abstraction over various platforms' APIs for watching for file events. (For example, under WSL2 the "dummy" repo's test passes but only if I remove the println! on line 149.)

However, using notify is far above and beyond what is necessary here.

logrotate can and should be configured to send a SIGHUP after it performs rotation. So trying to automatically and internally detect the rotation using inotify, is not useful. What is useful, is a way for flexi_logger to be told, "a rotation has just happened, please act accordingly".

[emabee]

But signal handling should definitely be done by the program/main. So, a method on the logger handle to trigger reopening the log file would be the only thing we need, do you agree?

[mmirate]

But signal handling should definitely be done by the program/main. So, a method on the logger handle to trigger reopening the log file would be the only thing we need, do you agree?

Yes, precisely.

[emabee]

Version 0.22.2 is published and has a simpler solution, based on LoggerHandle::reopen_outputfile.

And the tests are stabilized :-)