Problem with log file rotation

[lcarreon@…]

There seems to be a problem with log file rotation because I occasionally encountering the following exception when logging to rotated files:

std::runtime_error: boost::filesystem::last_write_time: No such file or directory: "/home/Devel/projects/id3v23/test/log/20130720_110200.log

I'm using the following settings for log file rotation:

rotation size = 1024 target = logs max size = 10240

My test environment is Fedora 18 32/64 bits.

[lcarreon@…]

Sorry, forgot to mention that the filename template is:

log/%Y%m%d_%H%M%S.log

[lcarreon@…]

Here is a list of the created log files based on a single run of my test program using the above-mentioned configuration.

-rw-rw----. 1 dev11 dev 973 Jul 22 10:21 20130722_102108.log

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00000

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00001

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00002

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00003

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00004

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00005

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00006

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00007

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00008

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00009

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00010

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00011

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00012

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00013

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00014

-rw-rw----. 1 dev11 dev 139 Jul 22 10:21 20130722_102108.log00015

Each log record contains the following 139-byte message where only the timestamp is changing:

2013-07-22 10:36:05.118868 [warning] test_library:000000x9f3:0x00007f7d21cf5740 (src/ctag.cpp, 823) Unknown frame 'UNKN' has been detected

The size of the first log file is correct based on the rotation size of 1024 bytes. I also noticed that due to the speed of the logging, the same log file name is used. The other issue is that the succeeding log files are smaller than expected. Finally, I'm expecting only 8 log records but I'm seeing 22 log records spread in 16 log files.

I tried changing the filename template to "log/log.log" but is still giving me the same result where only the log file names changed.

[lcarreon@…]

I have decided to experiment and tried removing the settings to do with rotated log file collection (i.e. removed target, maximum size and scan method).

The result is log files being rotated correctly with the correct number of log records in each of them based on the logging that my test program has performed.

This seems to indicate that managing the collection of log files is faulty although I have observed that the original location of the log files must be different to the location where they collected. If the original location and the collection location are identical, a different kind of problem occurs.

Unfortunately, I could not assist in locating the problem because the source code of the logging library is too complex for me because I have not studied how Boost.Parameter and Boost.Phoenix works making it difficult to comprehend the code.

[Andrey Semashev]

Could you provide a minimal compilable test case that reproduces the problem?

[lcarreon@…]

I was trying to produce the minimal compilable test case that produces the problem when I have discovered what was wrong. I was initializing Boost.Log in a test suite fixture instead of a global fixture. This was what was causing the incorrect behaviour.

Sorry for the trouble that I have caused. You may close this bug because it was my mistake.