Log rotation failure originating from fancylogger

[holstgr-kaust]

The log rotation functionality in fancylogger appears to be broken. When log files are rotated, the existing writer ends up with a stale file handle.

For example, this appears as a log rotation failure issue in EasyBuild:
easybuilders/easybuild-framework#1094

Traceback (most recent call last):
  File "/usr/lib64/python2.7/logging/handlers.py", line 77, in emit
    self.doRollover()
  File "/usr/lib64/python2.7/logging/handlers.py", line 140, in doRollover
    os.rename(self.baseFilename, dfn)
OSError: [Errno 13] Permission denied

Changing line:

178: MAX_BYTES = 100 * 1024 * 1024 # max bytes in a file with rotating file handler```

to:

178: MAX_BYTES = 0

Is a hacky, but effective fix.

[stdweird]

@holstgr-kaust how does it fix it? it just disables the logrotation, no?

[stdweird]

@holstgr-kaust @boegel anyhow, this is an issue with python logging, and not (only) with fancylogger.
i advise to support disabling (or disabke al together) the logrotation in EB. fancylogger.logToFile calls support the max_bytes paramter, set it to 0 in eg https://github.com/easybuilders/easybuild-framework/blob/25bd8222bb6569f33f721f5cf4199e1f9aa7fd6e/easybuild/tools/build_log.py#L183 (there's another occurence).

[holstgr-kaust]

Yes, it just disables the log rotation feature (which doesn't work anyway, so it seemed like a safe place to change). Thank you for the EB suggestions too.

[stdweird]

@holstgr-kaust for completeness, can you post the logfile destination and permissions on th eparent dir? i'm a bit intregued by the permission error. it's a bit odd to get one from a rename

[boegel]

Log rotation is being disabled in EasyBuild via easybuilders/easybuild-framework#2347.

[holstgr-kaust]

@stdweird
just did a fresh build with EasyBuild v3.4.1. The build command, performed by the bldr user, in their home directory, was*:

eb -r "~/tmp/sw/ebconfigs" --debug --tmpdir=~/tmp/sw/buildtmp --tmp-logdir=~/tmp/sw/buildlog --disable-cleanup-builddir --disable-cleanup-tmpdir "~/tmp/sw/ebconfigs/ParaView-5.4.1-kvl-defaults.eb"

The rollover errors still appeared (during build phase), but EB now appears to be able to continue the build to successful installation:

Traceback (most recent call last):
  File "/usr/lib64/python2.7/logging/handlers.py", line 77, in emit
    self.doRollover()
  File "/usr/lib64/python2.7/logging/handlers.py", line 140, in doRollover
    os.rename(self.baseFilename, dfn)
OSError: [Errno 13] Permission denied
Logged from file run.py, line 478
Traceback (most recent call last):
  File "/usr/lib64/python2.7/logging/handlers.py", line 77, in emit
    self.doRollover()
  File "/usr/lib64/python2.7/logging/handlers.py", line 140, in doRollover
    os.rename(self.baseFilename, dfn)
OSError: [Errno 13] Permission denied
Logged from file run.py, line 488

Full listings of the buildlog and buildtmp directories show the following permissions (bldr user owns the files, has write permissions, and there appears to be sufficient space):

~/tmp/sw/buildlog$ ls -al

total 596M
drwxr-x---. 2 bldr bldr 4.0K Nov 20 10:29 ./
drwxr-x---. 9 bldr bldr 4.0K Nov 20 08:59 ../
-rw-r-----. 1 bldr bldr 4.7K Nov 20 10:29 easybuild-ParaView-5.4.1-20171120.090624.nnPui.log
-rw-r-----. 1 bldr bldr 297M Nov 20 10:29 easybuild-ParaView-5.4.1-20171120.090624.nnPui.log.1
-rw-r-----. 1 bldr bldr 297M Nov 20 10:29 easybuild-ParaView-5.4.1-20171120.090624.nnPui.log.2
-rw-r-----. 1 bldr bldr 323K Nov 20 09:33 easybuild-ParaView-5.4.1-20171120.090624.nnPui.log.3

~/tmp/sw/buildtmp/eb-jZo56_$ ls -al

total 605M
drwx------. 2 bldr bldr 8.0K Nov 20 10:48 ./
drwxr-x---. 3 bldr bldr 4.0K Nov 20 08:57 ../
-rw-r-----. 1 bldr bldr 5.8M Nov 20 10:51 easybuild-3ZrUFR.log
-rw-r-----. 1 bldr bldr 297M Nov 20 10:29 easybuild-3ZrUFR.log.1
-rw-r-----. 1 bldr bldr 297M Nov 20 10:28 easybuild-3ZrUFR.log.2
-rw-------. 1 bldr bldr 3.3M Nov 20 09:33 easybuild-3ZrUFR.log.3

df -h ~/tmp/sw shows 5.5T space available.

Hope that helps. Thank you.

*PS. I've re-written the command slightly to simplify paths