Logfiles stop logging

Hey guys!

I’m currently having an issue with my log files. When I start openHAB, openhab.log / events.log start logging as expected. At some point though, no new entries get added to the log files. Sometimes it’s 20 minutes later, sometimes 3 hours - totally random. The rest of OH works as usual. There’s also nothing irregular in the logs just before it stops.
I already re-downloaded the log4j2.xml, but that didn’t help.

The only thing I noticed is this in dsmeg, I’m not sure if that could be related though:

[10410.361696] systemd-journald[899]: /var/log/journal/1fb0bf70d28e4417ab7c45e395d422ad/user-1001.journal: Journal file has been deleted, rotating.
[10410.361711] systemd-journald[899]: Failed to write entry to /var/log/journal/1fb0bf70d28e4417ab7c45e395d422ad/user-1001.journal (21 items, 834 bytes), rotating before retrying: Identifier removed

I had the same issues with the logfiles when using an SSD as a test scenario, so I guess that would rule a corrupted SD card out.

Any ideas on what could be causing this are highly appreciated.

  • Platform information:
    • Hardware: Raspberry Pi 5 Model B Rev 1.0, 4GB, 32 GB MicroSD
    • OS: openHABian v1.9c
    • Java Runtime Environment: openjdk version “17.0.11” 2024-04-16
    • openHAB version: 4.1.3

Cheers

I’ve noticed my logs stopped about 24 hours after migration to OH 4.1.2 running on raspberry pi 4 and openhabian 1.9.

Fixed my issues after finding this post, Solution. The last line on /var/lib/openhab/etc/log4j2.xml has a broken tag.

Same issue here. New installation of Openhabian from an image (4.1.2)

There is no issue with log4j2.xml as suggested by pguima. I even tried with a clean version of log4j2.xml from the Openhab repository.

If I type “log:tail” in the console, all messages are shown and the log files start to update.
After a couple of hours the logging stops again (the files show no updates).

Yup, log4j2.xml is fine on my side as well.
However, when I run log:tail on the console, I see like the last (most current) 50 entries or so but then it ends with Error executing command: Unable to set level for logger.
When I run it again a bit later, I also get the latest entries (so it does update), but it still ends with Error executing command: Unable to set level for logger.

Thing is: the log files don’t get updated - events and openhab.log both stopped updating at 0:04 this time.

Try disabling zram sync systemctl disable --now zsync.timer.
issue some log related command on OH console like log:set debug xzy to get logs going again.

Even stranger: Logging worked until 12:02 PM today.
Then suddenly the frontail view started scrolling through older events for several seconds and stopped at 10:25AM.
events.log got a new timestamp of 10:25AM
Logging is now stuck
As soon as I issued the log:tail command the logging started working again, but entries between 10:25 and 12:02 are lost.

zram issue?

Thanks for your reply. I tried what you suggested, unfortunately log:set debug 291 still returns Error executing command: Unable to set level for logger.

I have the same issue but I’m not using zram. I did a full reinstall on a fresh SSD and restored my backup, but it still stops logging after a certain amount of time (usually around 30 mins).

I just tested the log:tail command and then logging resumes.

I just noticed that events.log keeps updating while openhab.log is stuck at midnight 3 days ago.

This thread made me wonder, so i checked. My openhab.log is fine, but my events.log stopped logging in november '23 (!). I’m on Openhabian, 4.1.1 - Release Build and using zram with plenty of space:
df -h /var/log
Filesystem Size Used Avail Use% Mounted on
overlay2 974M 57M 850M 7% /var/log

Hi, I had the same issue, events log stuck.

New install of openhab 4.3.1 on a Raspi 4 via openhabian on a 64bit lite OS just before Xmas.

I thought something was up at the end of a rules coding session on the 30 Dec when I tried to return my binding log setting back to ‘normal’ I saw that pressing the cog “Configure Add-on” for an installed binding no longer came up with the choice to change log levels. May be this precipitated the problem.

The stuck log looked like this:

2024-12-30 21:06:13.309 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'BTTortolaVRssi' changed from -69 dBm to -63 dBm

Also got

openhab> log:tail
[Fatal Error] :126:17: Content is not allowed in trailing section.
                                                                  Error executing command: Unable to retrieve level for logger

The openhab GUI logging looked like

20:07:51.033	ERROR	org.openhab.core.items.GenericItem	Tried to set invalid state 1.0 (DecimalType) on item rgbCommandToggle of type StringItem, ignoring it
20:07:51.559	ERROR	org.openhab.core.items.GenericItem	Tried to set invalid state 1.0 (DecimalType) on item HVAC_Z2Use_Anticipate of type StringItem, ignoring it
20:07:56.342	ERROR	org.openhab.core.automation.module.script.internal.handler.AbstractScriptModuleHandler	Script execution of rule with UID 'lighting_outside-1' failed: Could not cast NULL to java.lang.Number; line 21, column 25, length 39 in lighting_outside
20:07:57.897	ERROR	org.openhab.core.items.GenericItem	Tried to set invalid state 0.0 (DecimalType) on item EnergyDirection of type StringItem, ignoring it
20:07:58.266	ERROR	org.openhab.core.items.GenericItem	Tried to set invalid state 1.0 (DecimalType) on item HVAC_Z1Use_Anticipate of type StringItem, ignoring it
20:07:59.064	ERROR	org.openhab.core.automation.module.script.internal.handler.AbstractScriptModuleHandler	Script execution of rule with UID 'hotwatercontrol-1' failed: Could not cast NULL to java.lang.Number; line 34, column 28, length 38 in hotwatercontrol
20:07:59.067	ERROR	org.openhab.core.automation.module.script.internal.handler.AbstractScriptModuleHandler	Script execution of rule with UID 'energy-1' failed: Could not cast NULL to java.lang.Number; line 18, column 50, length 39 in energy
20:08:00.905	ERROR	org.openhab.core.automation.module.script.internal.handler.AbstractScriptModuleHandler	Script execution of rule with UID 'modes&global-13' failed: The name 'sendNotification' cannot be resolved to an item or type; line 243, column 9, length 85 in modes&global
20:08:01.512	ERROR	org.openhab.core.automation.module.script.internal.handler.AbstractScriptModuleHandler	Script execution of rule with UID 'lighting_outside-1' failed: Could not cast NULL to java.lang.Number; line 22, column 25, length 39 in lighting_outside
20:08:01.529	ERROR	org.openhab.core.automation.module.script.internal.handler.AbstractScriptModuleHandler	Script execution of rule with UID 'lighting_outside-1' failed: Could not cast NULL to java.lang.Number; line 22, column 25, length 39 in lighting_outside
20:08:02.040	ERROR	org.openhab.core.automation.module.script.internal.handler.AbstractScriptModuleHandler	Script execution of rule with UID 'Thermostatz1beta-3' failed: Could not cast 19.8 °C to java.lang.Number; line 115, column 24, length 62 in Thermostatz1beta
20:08:02.049	ERROR	org.openhab.core.automation.module.script.internal.handler.AbstractScriptModuleHandler	Script execution of rule with UID 'LoungeSimpler-1' failed: The name 'ON' cannot be resolved to an item or type; line 50, column 33, length 2 in LoungeSimpler
20:08:05.952	ERROR	org.openhab.core.automation.module.script.internal.handler.AbstractScriptModuleHandler	Script execution of rule with UID 'VoiceAnnouncements-3' failed: The name 'sendNotification' cannot be resolved to an item or type; line 69, column 9, length 61 in VoiceAnnouncements
20:08:06.317	ERROR	org.openhab.core.automation.module.script.internal.handler.AbstractScriptModuleHandler	Script execution of rule with UID 'pimp-4' failed: sleep interrupted in pimp
20:08:25.322	ERROR	org.openhab.core.internal.common.AbstractInvocationHandler	An error occurred while calling method 'QueryablePersistenceService.query()' on 'org.openhab.persistence.mapdb.internal.MapDbPersistenceService@7c38882b': null
20:08:25.342	ERROR	org.openhab.core.persistence.internal.PersistenceManagerImpl	Exception occurred while querying persistence service 'mapdb' to restore 'SolarEnergy': null
20:08:27.301	ERROR	org.openhab.core.internal.common.AbstractInvocationHandler	An error occurred while calling method 'QueryablePersistenceService.query()' on 'org.openhab.persistence.mapdb.internal.MapDbPersistenceService@7c38882b': null
20:08:27.320	ERROR	org.openhab.core.persistence.internal.PersistenceManagerImpl	Exception occurred while querying persistence service 'mapdb' to restore 'SolCastEstimateMap': null
20:08:27.447	ERROR	org.openhab.core.internal.common.AbstractInvocationHandler	An error occurred while calling method 'QueryablePersistenceService.query()' on 'org.openhab.persistence.mapdb.internal.MapDbPersistenceService@7c38882b': null
20:08:27.465	ERROR	org.openhab.core.persistence.internal.PersistenceManagerImpl	Exception occurred while querying persistence service 'mapdb' to restore 'SolCastLive': null
20:08:27.510	ERROR	org.openhab.core.internal.common.AbstractInvocationHandler	An error occurred while calling method 'QueryablePersistenceService.query()' on 'org.openhab.persistence.mapdb.internal.MapDbPersistenceService@7c38882b': null
20:08:27.527	ERROR	org.openhab.core.persistence.internal.PersistenceManagerImpl	Exception occurred while querying persistence service 'mapdb' to restore 'SolcastCronTriggerType': null

I tried

sudo systemctl restart openhab.service

didn’t fix it and then a shutdown and cold start, didn’t fix it.
At this point all my rules appeared to have stopped working !!
Tried a reinstall on top via openhabian but both no event logging and no rules persisted.

Then I Googled the openhab Community and came up this topic.

for me this line looked like:

</Loggers>

</Configuration>ion>

Correcting this as below restored the the event logging, logging choices for the binding and my rules started running again.

</Loggers>

</Configuration>

Thanks all for the support! :sweat_smile:
Just thought I would log my experience on this to add to the body of evidence if this needs a bug report.