I have a question regarding the event log and openhab log files. In the past when I restarted the system it would archive the prior log files and create new ones. Now it seems that the openhab log file is not archived and recreated on system restart, but rather the output continues to be appended to the prior existing file. I think the behavior changed after the update from OH 4.2 prior Milestone to the latest Milestone. Running on a Rasp Pi openhabian…
Does your rolling file appender still have the “one startup” triggering policy for both appenders?
This is the latest appender for openhab.log in the distro repo.
<!-- Rolling file appender -->
<RollingFile fileName="${sys:openhab.logdir}/openhab.log" filePattern="${sys:openhab.logdir}/openhab.log.%i.gz" name="LOGFILE">
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
<Policies>
<OnStartupTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="16 MB"/>
</Policies>
<DefaultRolloverStrategy max="7"/>
</RollingFile>
I’m on 4.2 M2 and can confirm that the the files are recreated on an OH restart for me. Are you on the snapshots?
Dunno 
… where is that setting located?
$OH_USERDATA/etc/log4j2.xml
Apparently yes. I noticed this odd behavior in the openhab.log file but not the events.log file. I see the only difference in the settings is that one is a RollingFile entry and the other is a RollingRandomAccessFile entry. All seems rather wierd…
<!-- Rolling file appender -->
<RollingFile fileName="${sys:openhab.logdir}/openhab.log" filePattern="${sys:openhab.logdir}/openhab.log.%i.gz" name="LOGFILE">
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
<Policies>
<OnStartupTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="16 MB"/>
</Policies>
<DefaultRolloverStrategy max="7"/>
</RollingFile>
<!-- Event log appender -->
<RollingRandomAccessFile fileName="${sys:openhab.logdir}/events.log" filePattern="${sys:openhab.logdir}/events.log.%i.gz" name="EVENT">
<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
<Policies>
<OnStartupTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="16 MB"/>
</Policies>
<DefaultRolloverStrategy max="7"/>
</RollingRandomAccessFile>
And org.ops4j.pax.logging.cfg in same directory?
I remember I had an issue a few months back and then this file did have somehow a special character in path. Never found out why. Does it look like this?
org.ops4j.pax.logging.log4j2.config.file=${karaf.etc}/log4j2.xml
Are you on an SD card? Once I discovered that my log files wouldn’t rollover was caused by a worn out card.
Beyond that, I don’t really have anything of value to offer. It works as expected for me on 4.2 M2 and your XML matches mine. The “OnstartupTriggeringPolicy” is what causes it to roll over the log fiule when OH starts instead of writing to the already existing file.
I would imagine that if that were the problem there would be more than just a failure to roll over the file when OH restarts. That file and that line in the file tells OH to use the log4j2.xml file for the config.
Or issue with ZRAM? Because log files are in ZRAM, correct?
I have also seen that behavior if I had the log file open in an editor and had some pending change locking the file due to something like copying a line out and causing a change. When openhab starts back up do you see all of the log entries from the beginning of the new instance?
They are written to zram on a default openHABian install, which would exclude the SD card being the problem.
I am on an SD card. But it is brand new.
Anyway I can’t believe that a bit error on a card or zram would cause just such one specific problem.
Just for the purposes of reminder I see the problem with openhab.log but not with event.log or audit.log.
That one looks good to me.
Nope. The log files are published via SMB shares, but I don’t have any other consoles editors open on those files; and I close Windows explorer on the SMB share too (so it can’t be holding the file in any way).
Yes. I see everything that was in the prior instance until shutdown completed, followed by all the messages you would expect to see during a normal startup.
FWIW
Noticed the same problem. Put a Rpi3 back in service with new openhabian on OH4.2M2 for some testing a few days ago (5/4). It had been so long since I had done that figured it had something to do with Zram or maybe the SMB shares setup. Initially it seemed to work, but now have just one big log. I have other concerns, so have not tried anything.
Yup. I am pretty sure the issue started when I upgraded to OH4.2M2 too…
That’s a good clarification. My initial install was a stable version and then upgraded to OH4.2M2. The last compressed at 3:36 PM in the screen shot was on 4.1.2 and then the long log despite several restarts was OH4.2M2
I had a case where my SD card wore out and the reason I found out was because the syslog never rotated and it filled up the filesystem. I manually deleted the file, reboot, and the log file came back.
When an SD card wears out it’s not just a bit error. It inconsistently saves changes made to the file system. Sometimes it works (e.g. appending to the file) and sometimes it doesn’t (e.g. deleting the file). Sometime it works temporarily as the changes are cached in memory.
Corruption caused by pulling the power during a write is definitely that sort of error, but a worn out SD card behaves weirdly.
I doubt it’s what’s happening here, but it’s worth mentioning to eliminate it as a source.
As for zram, you have the issue that when zram is stopped (e.g. during a shutdown of the machine) it flushes it’s contents to the SD card. When it’s started, it loads the contents previously flushed into zram. If something goes off in that process (e.g. the rotated file didn’t flush during a shutdown) weird things can happen with files seeming to disappear or reappearing after being deleted. I doubt that’s occurring here though.
I just ordered a new SD and will check when it arrives. But my working hypothesis is its M2 related…
Just a thought but maybe this… (Pax Logging v2.2.6)
Same here, works still fine on 4.2.M2.
No ZRAM or SD involved on my side (I am not using openHABian)
Given that the logging config hasn’t changed between versions and it’s still working the same for many (most?) of us, there has to be something specific about your specific system causing problems. Maybe it’s Samba? Frontail? ARM CPU?
To be clear, I’m not saying it’s not a problem. I’m just saying it’s not a universal problem so the differences between systems where it works and where it doesn’t work is going to be important to figure out.
For my part I’m running OH in Docker on an Ubuntu VM. I do not use Frontail nor samba nor NFS to access the logs.
Indeed. That is why I asked the question.
I am not using Frontail. But … indeed maybe it’s Samba? … ARM CPU?