Weird state update behaviour

[El_Duderino]

Hi everyone,

I have been a long-time openHAB user and have recently upgraded to version 4.
While I can’t be sure, I do believe that that is when the issue I’m about to describe started.
My installation runs on a Raspberry 4 (4GB). For the sake of attempting to debug it, I actually removed pretty much all files of my 99% file-based configuration.
I only left my mqtt thing and my fritzbox (dsl router) thing in there as both of them are reacting to periodic updates from the binding.
In my events.log I do see updates, that from my point of view are no updates, because the state is not changing.
For example I have my light switches configured to publish their state on MQTT (Shelly) and they do so evrey 30sec no matter if something changed. I can see these periodic updates with a MQTT viewer.
While this had me think that this is about the MQTT binding I then noticed that it also happens for other items. So I also put my fritzbox thing in (dsl router), which periodically deals with updates showing whether device with a specific mac adress is online.
In the events.log file I see:

2023-11-06 10:15:41.035 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'F2_Office_Light' updated to ON
2023-11-06 10:16:11.036 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'F2_Office_Light' updated to ON
2023-11-06 10:16:41.044 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'F2_Office_Light' updated to ON
2023-11-06 10:17:11.050 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'F2_Office_Light' updated to ON
2023-11-06 10:17:41.069 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'F2_Office_Light' updated to ON
2023-11-06 10:18:11.077 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'F2_Office_Light' updated to ON
...
2023-11-06 10:16:28.618 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'AndreasOnline' updated to ON
2023-11-06 10:17:33.307 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'AndreasOnline' updated to ON
2023-11-06 10:18:38.223 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'AndreasOnline' updated to ON
2023-11-06 10:19:41.967 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'AndreasOnline' updated to ON
2023-11-06 10:20:46.094 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'AndreasOnline' updated to ON
2023-11-06 10:21:51.048 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'AndreasOnline' updated to ON
2023-11-06 10:22:56.223 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'AndreasOnline' updated to ON

I am now wondering if it’s not so much an issue with a specific binding, but a general openHAB issue. Any idea what might cause this?

Thanks in advance!

[hmerk (Hans-Jörg Merk)]

This is not an issue, but expected behavior.
You configured MQTT to send updates every 30 seconds, no matter if it changed or not. This is exactly what you see in events log. Updates coming in every 30 seconds without a change.

[El_Duderino]

But this has not always been like this, no?

I am very certain it was not like this in the past, especially becaus my logfiles are blowing up now…

[sihui]

@El_Duderino

But this has not always been like this, no?

Check this out:

Openhab 4.0.1 and ipcamera

During the upgrade process you kept your log4j2.xml config instead of accepting the new default one. There are two new lines: <Logger level="ERROR" name="openhab.event.ItemStateUpdatedEvent"/> <Logger level="ERROR" name="openhab.event.GroupStateUpdatedEvent"/> Note that this has nothing to do with any binding. events.log shows the events on the event bus and is not directly driven by any binding.

[El_Duderino]

Hi sihui,

Thanks a lot, that was it!!!

I have made changes to that file, which is why it didn’t get overwritten when I upgraded.

Thanks again!