Re: [logback-user] TimeBasedRollingPolicy

Hi, sorry for popping up an old thread but i don't catch something: shouldn't the Logger when new event arrives check the last modification time of the log file and if it "is time" roll it over? i have the same configuration in servlet and script - rollover at midnight. in servlet everything works just fine. but in script, that is run from cron every 2 hours, events are always written in the same log. How can i make something, that doesn't run continually trigger rollover? -- View this message in context: http://www.nabble.com/TimeBasedRollingPolicy-tp19756004p22517998.html Sent from the Logback User mailing list archive at Nabble.com.

The first cron job launched after midnight will trigger rollover. Isn't that the behavior you are observing? By the way, for obvious reasons, triggering at midnight cannot happen every 2 hours. paha wrote:
Hi, sorry for popping up an old thread but i don't catch something: shouldn't the Logger when new event arrives check the last modification time of the log file and if it "is time" roll it over? i have the same configuration in servlet and script - rollover at midnight. in servlet everything works just fine. but in script, that is run from cron every 2 hours, events are always written in the same log. How can i make something, that doesn't run continually trigger rollover?
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch

Ceki Gulcu wrote:
The first cron job launched after midnight will trigger rollover. Isn't that the behavior you are observing? i wouldn't ask in that case :) . no it never rolls over. for the case if you ask, my configuration
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender"> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <FileNamePattern>/var/log/cgp/archive/${script.name}.%d.log.zip</FileNamePattern> <MaxHistory>30</MaxHistory> </rollingPolicy> <layout class="ch.qos.logback.classic.PatternLayout"> </layout> </appender> <root level="info"> <appender-ref ref="FILE"/> </root> Logback version - the last available Ceki Gulcu wrote:
By the way, for obvious reasons, triggering at midnight cannot happen every 2 hours. didn't get it. could you please explain? if it starts at 12-00 am, the file modification time must be still from previous day, and roll over should happen with the next event. doesn't it? anyway, it doesn't roll over at all, even if script starts ones per day at for instance 14-30.
-- View this message in context: http://www.nabble.com/TimeBasedRollingPolicy-tp19756004p22588225.html Sent from the Logback User mailing list archive at Nabble.com.

Could you please enter a jira issue We'll continue the discussion within the jira issue. paha wrote:
Ceki Gulcu wrote:
The first cron job launched after midnight will trigger rollover. Isn't that the behavior you are observing? i wouldn't ask in that case :) . no it never rolls over. for the case if you ask, my configuration
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<FileNamePattern>/var/log/cgp/archive/${script.name}.%d.log.zip</FileNamePattern> <MaxHistory>30</MaxHistory> </rollingPolicy>
<layout class="ch.qos.logback.classic.PatternLayout">
</layout> </appender> <root level="info"> <appender-ref ref="FILE"/> </root>
Logback version - the last available
Ceki Gulcu wrote:
By the way, for obvious reasons, triggering at midnight cannot happen every 2 hours. didn't get it. could you please explain? if it starts at 12-00 am, the file modification time must be still from previous day, and roll over should happen with the next event. doesn't it? anyway, it doesn't roll over at all, even if script starts ones per day at for instance 14-30.
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch

ok, i try to reproduce this behavior on windows and post jira issue -- View this message in context: http://www.nabble.com/TimeBasedRollingPolicy-tp19756004p22588884.html Sent from the Logback User mailing list archive at Nabble.com.

I don't think this is Windows related. As such, you don't need to reproduce the behavior on Windows. Please just create the jira issue. paha wrote:
ok, i try to reproduce this behavior on windows and post jira issue
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch

Ceki Gulcu wrote:
I don't think this is Windows related. i don't think either. i just experience it in debian (production environment), wanted to reproduce on windows (development environment) in simple scenario to be sure i'm not drunk ;)
Ceki Gulcu wrote:
Please just create the jira issue. i found an old issue with the same symptoms and posted a new comment with configuration file and test case. please read a comment below java-code.
http://jira.qos.ch/browse/LBCORE-26 if i should create a new issue, fell free to tell me that, i'll do -- View this message in context: http://www.nabble.com/TimeBasedRollingPolicy-tp19756004p22597465.html Sent from the Logback User mailing list archive at Nabble.com.

paha wrote:
i found an old issue with the same symptoms and posted a new comment with configuration file and test case. please read a comment below java-code.
http://jira.qos.ch/browse/LBCORE-26
if i should create a new issue, fell free to tell me that, i'll do
Thank you. Your comment in LBCORE-26 is fine. -- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch

Hi, any news? Were you able to reproduce the behavior? -- View this message in context: http://www.nabble.com/TimeBasedRollingPolicy-tp19756004p22717821.html Sent from the Logback User mailing list archive at Nabble.com.

Hi, i tried today to reproduce the behavior using logback source instead of compiled jar and it works as expected with rollover. What could be a problem when using jar? i will try to make one jar from source and test it again -- View this message in context: http://www.nabble.com/TimeBasedRollingPolicy-tp19756004p22755861.html Sent from the Logback User mailing list archive at Nabble.com.

paha wrote:
Hi, i tried today to reproduce the behavior using logback source instead of compiled jar and it works as expected with rollover. What could be a problem when using jar? i will try to make one jar from source and test it again
Sorry, it doesn't work either. Till now i found the following problem In TimeBasedRollingPolicy.java at start() there is a check where modification date of the file is inspected if (getParentsRawFileProperty() != null) at this point the result is always null. At FileAppender<E> the name of the log file seems to be filled from configuration later than the check is run. That's why modification time of the file is not retrieved, an file is never rolled over. -- View this message in context: http://www.nabble.com/TimeBasedRollingPolicy-tp19756004p22756013.html Sent from the Logback User mailing list archive at Nabble.com.

Correct. The if(getParentsRawFileProperty != null) property is insufficient if the user only specifies a FileNamePattern but not the File property. Specifying only the FileNamePattern property is perfectly legal by the way. paha wrote:
Sorry, it doesn't work either. Till now i found the following problem
In TimeBasedRollingPolicy.java at start() there is a check where modification date of the file is inspected
if (getParentsRawFileProperty() != null)
at this point the result is always null. At FileAppender<E> the name of the log file seems to be filled from configuration later than the check is run. That's why modification time of the file is not retrieved, an file is never rolled over.
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch

Ceki Gulcu wrote:
Correct. The if(getParentsRawFileProperty != null) property is insufficient if the user only specifies a FileNamePattern but not the File property. Specifying only the FileNamePattern property is perfectly legal by the way.
right but...i set this property explicitly. and i set a breakpoint at setFile method of FileAppender. It seems to be set after the check "if (getParentsRawFileProperty() != null)" so that the modification time of the correctly set log file is not retrieved at the right time. Sadly i didn't have time at this weekend to find out more. -- View this message in context: http://www.nabble.com/TimeBasedRollingPolicy-tp19756004p22767675.html Sent from the Logback User mailing list archive at Nabble.com.

Hi again, is there any chance of making the TimebasedRollingPolicy ever run properly? I've run the tests once more. The current flaw of execution is following: Stage 1: RollingPolicyBase.setParent(FileAppender appender) is called at this stage appender.rawFileProperty() is still Null in spite of configuration file entry Stage 2: TimeBasedRollingPolicy.start() is called at this stage lastCheck time is set and because File property of FileAppender is still Null, last modification time of the log is not read Stage 3: FileAppender.setFile is finally called to set the file name of the log. At this stage it is too late because current system time was assigned to lastCheck at Stage 2 That is the reason, why all applications that do not run as long as TimebasedRollingPolicy trigger event needs, will never ever roll the log file over. Please make it work right if possible. I would do it myself if i could, but i'm pretty new in java and the logback code is too complex for me to make myself comfortable with it. -- View this message in context: http://www.nabble.com/TimeBasedRollingPolicy-tp19756004p23123245.html Sent from the Logback User mailing list archive at Nabble.com.

Well ... i found the solution :jumping: in GenericConfigurator class in method doConfigure the event chain is build with recorder.recordEvents(inputSource). at this stage the event for setting the file property is recordered AFTER event, that defines RollingPolicy because...the configuration file looks like
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<FileNamePattern>logfile.%d{yyyy-MM-dd_HH-mm}.log.zip</FileNamePattern> <MaxHistory>30</MaxHistory> </rollingPolicy>
< param name="File" value= ...
after looking at event chain sequence i found the solution : it is dump and simple - put < param > before <rollingPolicy> in configuration file and everything works as it should %-| -- View this message in context: http://www.nabble.com/TimeBasedRollingPolicy-tp19756004p23123386.html Sent from the Logback User mailing list archive at Nabble.com.
participants (2)
-
Ceki Gulcu
-
paha