SizeAndTimeBasedArchiveRemover: Unexpected periodsElapsed value 0

Hi, I am seeing the following error when rollover happens (this keeps coming continuously on stdout/err): *20:25:38,351 |-WARN in c.q.l.co.rolling.helper.RenameUtil - Failed to rename file [D:\test.log] to [D:\test.2012-11-08.202336641.log]. ... 20:25:38,351 |-WARN in ch.qos.logback.core.rolling.helper.SizeAndTimeBasedArchiveRemover@6d3374 - Unexpected periodsElapsed value 0 * I am using RollingFileAppender with TimeBasedRollingPolicy and trigger is timeBasedFileNamingAndTriggeringPolicy with class="MyOwnSizeAndTimeBasedFNATP" defined as: @NoAutoStart public class MyOwnSizeAndTimeBasedFNATP<E> extends SizeAndTimeBasedFNATP<E> { private final AtomicBoolean trigger = new AtomicBoolean(); @Override public boolean isTriggeringEvent(final File activeFile, final E event) { if (trigger.compareAndSet(false, true) && activeFile.length() > 0) { String maxFileSize = getMaxFileSize(); setMaxFileSize("1"); super.isTriggeringEvent(activeFile, event); setMaxFileSize(maxFileSize); return true; } return super.isTriggeringEvent(activeFile, event); } Any suggestions on what could have gone wrong here? I tried to dig deeper into the logback code to identify the problem. I feel I am somehow entering RollingFileAppender's subAppend() multiple times or violating the synchronised behaviour as mentioned in the comment in the code. Any pointers please? Thanks!

Forgot to mention, my logback.xml says: file: <dir>/test.log fileNamePattern: <dir>/test.%d{yyyy-MM-dd}.%d{HHmmssSSS,aux}.log and rollover happened appropriately for the first time (so I have test.2012-11-08.202336641.log created) and the mentioned error keeps coming continuously thereafter attempting to rename test.log again to test.2012-11-08.202336641.log everytime. On Thu, Nov 8, 2012 at 9:18 PM, Gaurav Kumar <gaurav419@gmail.com> wrote:
Hi, I am seeing the following error when rollover happens (this keeps coming continuously on stdout/err):
*20:25:38,351 |-WARN in c.q.l.co.rolling.helper.RenameUtil - Failed to rename file [D:\test.log] to [D:\test.2012-11-08.202336641.log]. ... 20:25:38,351 |-WARN in ch.qos.logback.core.rolling.helper.SizeAndTimeBasedArchiveRemover@6d3374- Unexpected periodsElapsed value 0 *
I am using RollingFileAppender with TimeBasedRollingPolicy and trigger is timeBasedFileNamingAndTriggeringPolicy with class="MyOwnSizeAndTimeBasedFNATP" defined as:
@NoAutoStart public class MyOwnSizeAndTimeBasedFNATP<E> extends SizeAndTimeBasedFNATP<E> { private final AtomicBoolean trigger = new AtomicBoolean();
@Override public boolean isTriggeringEvent(final File activeFile, final E event) { if (trigger.compareAndSet(false, true) && activeFile.length() > 0) { String maxFileSize = getMaxFileSize(); setMaxFileSize("1"); super.isTriggeringEvent(activeFile, event); setMaxFileSize(maxFileSize); return true; }
return super.isTriggeringEvent(activeFile, event); }
Any suggestions on what could have gone wrong here? I tried to dig deeper into the logback code to identify the problem. I feel I am somehow entering RollingFileAppender's subAppend() multiple times or violating the synchronised behaviour as mentioned in the comment in the code.
Any pointers please?
Thanks!

Hi, I ran a profiler to analyze this issue. Attaching the output of the calling trace so somebody who is aware of the calling sequence in depth can make out what is going wrong here. Thanks! On Thu, Nov 8, 2012 at 9:22 PM, Gaurav Kumar <gaurav419@gmail.com> wrote:
Forgot to mention, my logback.xml says: file: <dir>/test.log fileNamePattern: <dir>/test.%d{yyyy-MM-dd}.%d{HHmmssSSS,aux}.log
and rollover happened appropriately for the first time (so I have test.2012-11-08.202336641.log created) and the mentioned error keeps coming continuously thereafter attempting to rename test.log again to test.2012-11-08.202336641.log everytime.
On Thu, Nov 8, 2012 at 9:18 PM, Gaurav Kumar <gaurav419@gmail.com> wrote:
Hi, I am seeing the following error when rollover happens (this keeps coming continuously on stdout/err):
*20:25:38,351 |-WARN in c.q.l.co.rolling.helper.RenameUtil - Failed to rename file [D:\test.log] to [D:\test.2012-11-08.202336641.log]. ... 20:25:38,351 |-WARN in ch.qos.logback.core.rolling.helper.SizeAndTimeBasedArchiveRemover@6d3374- Unexpected periodsElapsed value 0 *
I am using RollingFileAppender with TimeBasedRollingPolicy and trigger is timeBasedFileNamingAndTriggeringPolicy with class="MyOwnSizeAndTimeBasedFNATP" defined as:
@NoAutoStart public class MyOwnSizeAndTimeBasedFNATP<E> extends SizeAndTimeBasedFNATP<E> { private final AtomicBoolean trigger = new AtomicBoolean();
@Override public boolean isTriggeringEvent(final File activeFile, final E event) { if (trigger.compareAndSet(false, true) && activeFile.length() > 0) { String maxFileSize = getMaxFileSize(); setMaxFileSize("1"); super.isTriggeringEvent(activeFile, event); setMaxFileSize(maxFileSize); return true; }
return super.isTriggeringEvent(activeFile, event); }
Any suggestions on what could have gone wrong here? I tried to dig deeper into the logback code to identify the problem. I feel I am somehow entering RollingFileAppender's subAppend() multiple times or violating the synchronised behaviour as mentioned in the comment in the code.
Any pointers please?
Thanks!

Hi, I ran a profiler to analyze this issue. Attaching the output of the calling trace so somebody who is aware of the calling sequence in depth can make out what is going wrong here. Thanks! On Thu, Nov 8, 2012 at 9:22 PM, Gaurav Kumar <gaurav419@gmail.com> wrote:
Forgot to mention, my logback.xml says: file: <dir>/test.log fileNamePattern: <dir>/test.%d{yyyy-MM-dd}.%d{HHmmssSSS,aux}.log
and rollover happened appropriately for the first time (so I have test.2012-11-08.202336641.log created) and the mentioned error keeps coming continuously thereafter attempting to rename test.log again to test.2012-11-08.202336641.log everytime.
On Thu, Nov 8, 2012 at 9:18 PM, Gaurav Kumar <gaurav419@gmail.com> wrote:
Hi, I am seeing the following error when rollover happens (this keeps coming continuously on stdout/err):
*20:25:38,351 |-WARN in c.q.l.co.rolling.helper.RenameUtil - Failed to rename file [D:\test.log] to [D:\test.2012-11-08.202336641.log]. ... 20:25:38,351 |-WARN in ch.qos.logback.core.rolling.helper.SizeAndTimeBasedArchiveRemover@6d3374- Unexpected periodsElapsed value 0 *
I am using RollingFileAppender with TimeBasedRollingPolicy and trigger is timeBasedFileNamingAndTriggeringPolicy with class="MyOwnSizeAndTimeBasedFNATP" defined as:
@NoAutoStart public class MyOwnSizeAndTimeBasedFNATP<E> extends SizeAndTimeBasedFNATP<E> { private final AtomicBoolean trigger = new AtomicBoolean();
@Override public boolean isTriggeringEvent(final File activeFile, final E event) { if (trigger.compareAndSet(false, true) && activeFile.length() > 0) { String maxFileSize = getMaxFileSize(); setMaxFileSize("1"); super.isTriggeringEvent(activeFile, event); setMaxFileSize(maxFileSize); return true; }
return super.isTriggeringEvent(activeFile, event); }
Any suggestions on what could have gone wrong here? I tried to dig deeper into the logback code to identify the problem. I feel I am somehow entering RollingFileAppender's subAppend() multiple times or violating the synchronised behaviour as mentioned in the comment in the code.
Any pointers please?
Thanks!

Any pointers here? Am badly stuck on this error: Unexpected periodsElapsed value 0. Thanks! On Thu, Nov 8, 2012 at 10:00 PM, Gaurav Kumar <gaurav419@gmail.com> wrote:
Hi, I ran a profiler to analyze this issue. Attaching the output of the calling trace so somebody who is aware of the calling sequence in depth can make out what is going wrong here.
Thanks!
On Thu, Nov 8, 2012 at 9:22 PM, Gaurav Kumar <gaurav419@gmail.com> wrote:
Forgot to mention, my logback.xml says: file: <dir>/test.log fileNamePattern: <dir>/test.%d{yyyy-MM-dd}.%d{HHmmssSSS,aux}.log
and rollover happened appropriately for the first time (so I have test.2012-11-08.202336641.log created) and the mentioned error keeps coming continuously thereafter attempting to rename test.log again to test.2012-11-08.202336641.log everytime.
On Thu, Nov 8, 2012 at 9:18 PM, Gaurav Kumar <gaurav419@gmail.com> wrote:
Hi, I am seeing the following error when rollover happens (this keeps coming continuously on stdout/err):
*20:25:38,351 |-WARN in c.q.l.co.rolling.helper.RenameUtil - Failed to rename file [D:\test.log] to [D:\test.2012-11-08.202336641.log]. ... 20:25:38,351 |-WARN in ch.qos.logback.core.rolling.helper.SizeAndTimeBasedArchiveRemover@6d3374- Unexpected periodsElapsed value 0 *
I am using RollingFileAppender with TimeBasedRollingPolicy and trigger is timeBasedFileNamingAndTriggeringPolicy with class="MyOwnSizeAndTimeBasedFNATP" defined as:
@NoAutoStart public class MyOwnSizeAndTimeBasedFNATP<E> extends SizeAndTimeBasedFNATP<E> { private final AtomicBoolean trigger = new AtomicBoolean();
@Override public boolean isTriggeringEvent(final File activeFile, final E event) { if (trigger.compareAndSet(false, true) && activeFile.length() > 0) { String maxFileSize = getMaxFileSize(); setMaxFileSize("1"); super.isTriggeringEvent(activeFile, event); setMaxFileSize(maxFileSize); return true; }
return super.isTriggeringEvent(activeFile, event); }
Any suggestions on what could have gone wrong here? I tried to dig deeper into the logback code to identify the problem. I feel I am somehow entering RollingFileAppender's subAppend() multiple times or violating the synchronised behaviour as mentioned in the comment in the code.
Any pointers please?
Thanks!
participants (1)
-
Gaurav Kumar