Logs rotate on service restart, and numbered backwards?

Setup, Configuration and Use Runtime
1
  • Platform information:
    • Hardware: Ryzen 1700 / 32GB RAM / 1TB SSD
    • OS: Debian 11
    • Java Runtime Environment: OpenJDK 11.0.13+8-1~deb11u1
    • openHAB version: 3.2.0
  • Issue of the topic: please be detailed explaining your issue

I’m not sure when this changed (it was before 3.2.0 and the whole log4j thing), but openHAB used to rotate log files once the log got big enough, and they were numbered in order (latest = events.log, next latest = events.log.1, oldest = events.log.7.gz). This is “normal” logrotate behavior to me and matches other services I use.

Now, it rotates the log file every time the service is restarted, and the numbering is reversed (latest = events.log, next latest = events.log.7.gz, oldest = events.log.1). Here’s an example where I restarted the service a few times on Dec 27

/var/log/openhab$ ls -halt
total 1.9M
-rw-r--r--  1 openhab openhab 133K Dec 28 10:53 events.log
drwxr-xr-x 14 root    root    4.0K Dec 28 07:36 ..
-rw-r--r--  1 openhab openhab 2.0K Dec 27 17:37 openhab.log
drwxr-xr-x  2 openhab openhab 4.0K Dec 27 17:37 .
-rw-r--r--  1 openhab openhab 1.4K Dec 27 17:37 events.log.7.gz
-rw-r--r--  1 openhab openhab  921 Dec 27 17:37 openhab.log.7.gz
-rw-r--r--  1 openhab openhab 3.3K Dec 27 17:19 events.log.6.gz
-rw-r--r--  1 openhab openhab 1.5K Dec 27 17:19 openhab.log.6.gz
-rw-r--r--  1 openhab openhab  961 Dec 27 15:11 events.log.5.gz
-rw-r--r--  1 openhab openhab  908 Dec 27 15:11 openhab.log.5.gz
-rw-r--r--  1 openhab openhab 1.1K Dec 27 15:02 events.log.4.gz
-rw-r--r--  1 openhab openhab 1.2K Dec 27 15:02 openhab.log.4.gz
-rw-r--r--  1 openhab openhab  84K Dec 27 15:01 events.log.3.gz
-rw-r--r--  1 openhab openhab  843 Dec 27 15:01 openhab.log.3.gz
-rw-r--r--  1 openhab openhab  14K Dec 20 13:03 events.log.2.gz
-rw-r--r--  1 openhab openhab  850 Dec 20 13:03 openhab.log.2.gz
-rwxr-xr-x  1 openhab openhab    0 Dec 20 00:21 Readme.txt
-rw-r--r--  1 openhab openhab 2.1K Dec 19 06:46 openhab.log.1
-rw-r--r--  1 openhab openhab 1.7M Dec 19 06:46 events.log.1
-rw-r--r--  1 openhab openhab    0 Mar 10  2021 audit.log

I prefer the old behavior (rotate based on size, and events.log.7.gz is the oldest log file). Is the new behavior intentional, or a bug? Is there a way for me to customize it?

2

Intentional

All the logging config can be customized by editing $OH_USERDATA/etc/log4j2.xml. However note that the file might be replaced on upgrades so you might have to go back and readd your customizations. See Log4j – Log4j 2 Appenders, specifically the RollingFileAppender.

1 Like
3

Thanks for the quick reply. Having to go through the whole documentation for log4j was a bit intimidating so it really helps to have you point me in the right direction. I made two changes in that file (just listing them here for my own reference or if someone else is interested)

  1. remove <OnStartupTriggeringPolicy/> from the first 3 appenders to prevent it from rotating every time the service starts
  2. change <DefaultRolloverStrategy max="7"/> to <DefaultRolloverStrategy fileIndex="min"/> to switch the numbering order from [blank],7,6,5,4,3,2,1 to [blank],1,2,3,4,5,6,7 . It seems like max=“7” is the default so I just removed it.

I can see the 1st one is working already. Since they don’t roll over until they hit 16MB now, it’ll be a while before I can test the 2nd one but here’s hoping! Thanks again for your help

4

I’m using them with cron triggers and monthly / weekly / daily rotation:

		<!-- Rolling file appender -->
		<RollingFile fileName="${sys:openhab.logdir}/openhab.log" filePattern="${sys:openhab.logdir}/History/openhab.log.%i" name="LOGFILE">
			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
			<Policies>
				<CronTriggeringPolicy schedule="0 0 0 1 1/1 ? *"/>
			</Policies>
			<DefaultRolloverStrategy fileIndex="min" min="1" max="7"/>
		</RollingFile>

		<!-- Event log appender -->
		<RollingRandomAccessFile fileName="${sys:openhab.logdir}/events.log" filePattern="${sys:openhab.logdir}/History/events.log.%i" name="EVENT">
			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
			<Policies>
				<CronTriggeringPolicy schedule="0 0 0 ? * * *"/>
			</Policies>
			<DefaultRolloverStrategy fileIndex="min" min="1" max="7"/>
		</RollingRandomAccessFile>

		<!-- own loggers -->
		<RollingRandomAccessFile fileName="${sys:openhab.logdir}/automation.log" filePattern="${sys:openhab.logdir}/History/automation.log.%i" name="AUTOMATION">
			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
			<Policies>
				<CronTriggeringPolicy schedule="0 0 0 ? * MON *"/>
			</Policies>
			<DefaultRolloverStrategy fileIndex="min" min="1" max="7"/>
		</RollingRandomAccessFile>
1 Like