Logging TimeBasedTriggeringPolicy

Spaceman_Spiff · December 31, 2017, 1:41pm

Hi,

I wanted to rollover my custom logfiles every week so I don’t have to search so long for entries.
On the official doc for log4j2 it sais:
http://logging.apache.org/log4j/2.x/manual/appenders.html#RolloverStrategies

      <Policies>
        <TimeBasedTriggeringPolicy interval="6" modulate="true"/>
        <SizeBasedTriggeringPolicy size="250 MB"/>
      </Policies>

Unfortunately in openhab2 the nice xml config file is gone so I can not transfer knowledge from the docs.
Can anyone elaborate why this was choosen?

I tried this but the logger stopped completely:

log4j2.appender.MyRule.fileName    = ${openhab.logdir}/MyRule.log
log4j2.appender.MyRule.filePattern = ${openhab.logdir}/MyRule_%d{w}.log.%i
log4j2.appender.MyRule.policies.date.type     = TimeBasedTriggeringPolicy 
log4j2.appender.MyRule.policies.date.interval = 1

Does anyone have an idea how I can achieve weekly rollover?

rlkoshak · January 19, 2018, 3:42pm

I think it would be something like the following, based on my working appender for zwave:

log4j2.appender.MyRule.name = MyRule
log4j2.appender.MyRule.type = RollingRandomAccessFile
log4j2.appender.MyRule.fileName = ${openhab.logdir}/MyRule.log
log4j2.appender.MyRule.filePattern = ${openhab.logdir}/MyRule_%d{w}.log.%i
log4j2.appender.MyRule.immediateFlush = true
log4j2.appender.MyRule.append = true
log4j2.appender.MyRule.layout.type = PatternLayout
log4j2.appender.MyRule.layout.pattern = %d{dd-MMM-yyyy HH:mm:ss.SSS} [%-5.5p] [%-50.50c] - %m%n
log4j2.appender.MyRule.policies.type = Policies
log4j2.appender.MyRule.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.MyRule.policies.size.size = 250MB
log4j2.appender.MyRule.policies.time.type = TimeBasedTriggeringPolicy
log4j2.appender.MyRule.policies.time.interval = 6
log4j2.appender.MyRule.policies.time.modulate = true
log4j2.appender.MyRule.policies.strategy.type = DefaultRolloverStrategy
log4j2.appender.MyRule.policies.strategy.max = 10

Everything above is the same as my zwave logger except the the addition of the policies.time parameters which I’m guessing at based on the policies.size parameters. Good luck!

andirs · January 22, 2018, 4:59pm

Thanks for your example. For me it is not working, because logging stops entirely. Here is my config:

# Event log appender
log4j2.appender.event.type = RollingRandomAccessFile
log4j2.appender.event.name = EVENT
log4j2.appender.event.fileName = ${openhab.logdir}/events.log
log4j2.appender.event.filePattern = ${openhab.logdir}/events.log.%i
log4j2.appender.event.immediateFlush = true
log4j2.appender.event.append = true
log4j2.appender.event.layout.type = PatternLayout
log4j2.appender.event.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} [%-26.26c] - %m%n
log4j2.appender.event.policies.type = Policies
log4j2.appender.event.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.event.policies.size.size = 5MB
log4j2.appender.event.policies.time.type = TimeBasedTriggeringPolicy
log4j2.appender.event.policies.time.interval = 1
log4j2.appender.event.policies.time.modulate = true
log4j2.appender.event.strategy.type=DefaultRolloverStrategy
log4j2.appender.event.strategy.max=6

Could you explain the lines the ‘interval’ and ‘modulate’ attributes? I looked them up but didn’t quite understand. What is the “siginificant time unit” in OH logging? Is it the day? Then interval = 1 should rotate the log once a day?!

rlkoshak · January 22, 2018, 5:06pm

I just copied from an example. I don’t know what all the parameters mean.

Spaceman_Spiff · January 22, 2018, 5:15pm

That’s what happened to me, too.

usambara · January 29, 2018, 6:43pm

Do you have tried the CronTriggeringPolicy?

log4j2.appender.CalDAV.policies.cron.type = CronTriggeringPolicy
log4j2.appender.CalDAV.policies.cron.schedule = 0 0 0 ? * * *

This should switch the file everyday at midnight.

Btw. I understood the documentation that the interval value is in minutes…

Spaceman_Spiff · January 30, 2018, 5:33am

@usambara:

interval:
How often a rollover should occur based on the most specific time unit in the date pattern.
For example, with a date pattern with hours as the most specific item and and increment of 4 rollovers would occur every 4 hours.

The most specific item in my case would be weeks, so I expected it to roll over on a weekly basis. I will try your suggestion, but it might take a while. Last time I changed the config it broke the logger so bad I had to restart openhab.

@Kai:
Can you explain what kind of file format is used for the logging configuration? I searched the official log4j documentation and find fancy xml files with examples which are easy to read, understand and create. Unfortunately the used file format is different.

rlkoshak · January 30, 2018, 3:30pm

https://logging.apache.org/log4j/2.x/manual/configuration.html#ConfigurationSyntax

Scroll down to the “Configuring with Properties” section of the above page.

Unfortunately, it appears that all the Apache docs provide examples in XML but I believe you can figure out the proper Properties from the XML. For example:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn" name="MyApp" packages="">
  <Appenders>
    <RollingFile name="RollingFile" fileName="logs/app.log"
                 filePattern="logs/app-%d{MM-dd-yyyy}.log.gz">
      <RegexFilter regex=".* test .*" onMatch="ACCEPT" onMismatch="DENY"/>
      <PatternLayout>
        <pattern>%d %p %c{1.} [%t] %m%n</pattern>
      </PatternLayout>
      <TimeBasedTriggeringPolicy />
    </RollingFile>
  </Appenders>
  <Loggers>
    <Root level="error">
      <AppenderRef ref="RollingFile"/>
    </Root>
  </Loggers>
</Configuration>

Would be in Properties

log4j2.rootLogger.level = ERROR
log4j2.rootLogger.appenderRefs = RollingFile

log4j2.appender.RollingFile.name = RollingFile
log4j2.appender.RollingFile.type = RollingFile
log4j2.appender.RollingFile.fileName = logs/app.log
log4j2.appender.RollingFile.filePattern = logs/app-%d{MM-dd-yyyy}.log.gz
log4j2.appender.RollingFile.filter.type = RegexFilter
log4j2.appender.RollingFile.filter.regex = .*test
log4j2.appender.RollingFile.filter.onMatch = ACCEPT
log4j2.appender.RollingFile.filter.onMismatch = DENY
log4j2.appender.RollingFile.trigger.type = TimeBasedTriggeringPolicy
log4j2.appender.RollingFile.layout.type = PatternLayout
log4j2.appender.RollingFile.layout.pattern = %d %p %c{1.} [%t] %m%n

The above is mainly just applying the same pattern as I’ve seen elsewhere. I don’t know if it is exactly correct but it should be close.

Spaceman_Spiff · January 30, 2018, 4:10pm

So why let people figure out stuff on their own if there are official docs with examples in different file format. The amount of threads asking for logging information speaks for themselves. Why not use the file format in the official docs and make it easy for the openhab users?

I tried to translate the example in my first post to the property file format:

log4j2.appender.MyRule.policies.type          = Policies
log4j2.appender.MyRule.policies.size.type     = SizeBasedTriggeringPolicy
log4j2.appender.MyRule.policies.size.size     = 10MB
log4j2.appender.MyRule.policies.date.type     = TimeBasedTriggeringPolicy 
log4j2.appender.MyRule.policies.date.interval = 1
log4j2.appender.MyRule.policies.date.modulate = true
log4j2.appender.MyRule.strategy.type = DefaultRolloverStrategy
log4j2.appender.MyRule.strategy.max = 2

This crashes the logger unrecoverably (it won’t log anything without and does not show any error message).
Any idea? If I comment out the .date. entries I have to restart to make logging work again.

rlkoshak · January 30, 2018, 4:53pm

I wasn’t privy to any of these decisions but know enough about the maintainers to know that there were reasons. Maybe it was to keep the config closer to the format that was used in OH 1. Maybe it was going to be an excessive amount of work internally to move to a different format. Perhaps the ops4j.pax library can only process .properties configs. I don’t know what they are, but I’m confident there were reasons and they were good reasons at the time.

But since it is a problem you can open an issue. Maybe there is something that can be done.

Hmmm, some googleling showed an example policies section.

Your policies look right.

https://github.com/apache/logging-log4j2/blob/master/log4j-core/src/test/resources/log4j-rolling.properties

appender.rolling.policies.type = Policies
appender.rolling.policies.time.type = TimeBasedTriggeringPolicy
appender.rolling.policies.time.interval = 2
appender.rolling.policies.time.modulate = true
appender.rolling.policies.size.type = SizeBasedTriggeringPolicy
appender.rolling.policies.size.size=100MB

Another example on stack overflow shows the strategy section to look correct as well.

appender.test.strategy.type=DefaultRolloverStrategy
appender.test.strategy.max=5

What is your full appender section?

Mihai_Badea · February 27, 2018, 7:41am

Is there anybody that has a working example using TimeBasedTriggeringPolicy?

idean · April 14, 2018, 1:07pm

No luck at all on my end. Mine’s not even rolling files at all, just throwing old data away.

Max_G · January 2, 2019, 12:04am

Since there was no working solution forthcoming, I decided to revive this tread.

I am having the same issue, wanting a log rotation based on time (not size); like so:
daily
compress
keep 14 days

Reason for daily is the easier management and troubleshooting, without the overhead of grepping, etc., knowing exactly where to look.

While the standard logs:

# Rolling file appender
log4j2.appender.out.type = RollingRandomAccessFile
log4j2.appender.out.name = LOGFILE
log4j2.appender.out.fileName = ${openhab.logdir}/openhab.log
log4j2.appender.out.filePattern = ${openhab.logdir}/openhab.log.%i
log4j2.appender.out.immediateFlush = true
log4j2.appender.out.append = true
log4j2.appender.out.layout.type = PatternLayout
log4j2.appender.out.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n
log4j2.appender.out.policies.type = Policies
log4j2.appender.out.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.out.policies.size.size = 16MB

# Event log appender
log4j2.appender.event.type = RollingRandomAccessFile
log4j2.appender.event.name = EVENT
log4j2.appender.event.fileName = ${openhab.logdir}/events.log
log4j2.appender.event.filePattern = ${openhab.logdir}/events.log.%i
log4j2.appender.event.immediateFlush = true
log4j2.appender.event.append = true
log4j2.appender.event.layout.type = PatternLayout
log4j2.appender.event.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} [%-26.26c] - %m%n
log4j2.appender.event.policies.type = Policies
log4j2.appender.event.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.event.policies.size.size = 16MB

are documented here: Logging | openHAB
and the XML-based config here: Log4j – Log4j 2 Appenders

It simply scares me to see reports of no logging occuring if changes (seemingly correct) lead to no logging at all.

So

… is still a valid questions today.

Anyone?

hannibal29 · January 6, 2019, 4:50pm

No, I also had no luck to get the TimeBasedTriggeringPolicy working …

… but: CronTriggeringPolicy as discribed by @usambara some posts earlier is working for me and can be used to achieve daily rollover.

RolfV · February 2, 2019, 7:21pm

It took me some time to figure this out, but I finally got TimeBasedTriggerPolicy working.
What you need to make sure, is that you have a date format defined in your filePattern:
For example:

log4j2.appender.zwave.filePattern = ${openhab.logdir}/ZWave-%d{yyyy-MM-dd}-%i.log

Then, the interval you set, depends on the smallest number in that date format. So if you use a interval of 2, like below, combined with the date format, the rollover will happen every 2 days.

log4j2.appender.zwave.policies.time.type = TimeBasedTriggeringPolicy
log4j2.appender.zwave.policies.time.interval = 2
log4j2.appender.zwave.policies.time.modulate = true

Now, with that, you can make a whole range of combinations, for example:

filePattern = ${openhab.logdir}/ZWave-%d{yyyy-MM-dd}-%i.log with time.interval = 2 creates a rollover every 2 days
filePattern = ${openhab.logdir}/ZWave-%d{yyyy-MM-dd}-%i.log with time.interval = 14 creates a rollover every 2 weeks
filePattern = ${openhab.logdir}/ZWave-%d{yyyy-MM-dd HH}-%i.log with time.interval = 2 creates a rollover every 2 hours
filePattern = ${openhab.logdir}/ZWave-%d{yyyy-MM-dd HH}-%i.log with time.interval = 24 creates a rollover every 24 hours, so every 2 days

and so on.