Hi, for some weeks we have observed some really mysterious behavior when enabling one of our appenders. This appender was configured specially to use the `FixedWindowRollingPolicy`. What we observed, was that after some time of debug logging, the CPU would suddenly hit the roof and have at least one core fully pegged at 100%. Using Jprofiler we found the issue to be various cases of `logger.debug()` that would be used by this special appender. Disabling the appender immediately fixed the issue (as we have `scan=true`)
I debugged this yesterday and found the answer partly in the logs and in the logback code. This is the line that basically shows the issue:
if (!file2zip.delete()) {
addStatus(new WarnStatus("Could not delete [" + nameOfFile2zip + "].", this));
}
The logs were full of this and I also found references to this online. I documented the entire process and findings in this repo:
https://github.com/fatso83/logback-bug. The repo also contains a minimal attempt at recreating what I saw on the Windows servers on my local machine.
I was unable to reproduce this locally, which I kind of need in order to fix this bug. So, I was just wondering if any of you had any tips? What could cause the file to be "locked" / prevented from being deleted? Would it be enough if someone had a read-handle on the file, for instance a log reader like `
glogg`? I made sure to close my own programs when looking at this, but there are multiple users that look at these logs.
There is a single JVM running this app.
--
Carl-Erik Kopseng |
Senior developer |
Diffia AS |