Openhab unstable after upgrade to 2.5

Setup, Configuration and Use Beginners
31

As I already wrote, for me it was because two zwave things were reconfigured every hour and that triggered a reloading of the rules.
Now I don’t think that this is supposed to happen, but at leas I was able to mitigate the impact by defining a longer wakeup interval.

32

Yes, I see something similar. Around the time that the rules restart, I see the following lines:

2019-12-23 05:48:12.750 [vent.ItemStateChangedEvent] - MotionSensorDouche_SensorLuminance changed from NULL to 0
2019-12-23 05:48:12.783 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:a93e88d5:node44' has been updated.
2019-12-23 05:48:16.696 [vent.ItemStateChangedEvent] - MotionSensorDouche_SensorLuminance changed from NULL to 0
2019-12-23 05:48:16.710 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:a93e88d5:node44' has been updated.

This is a Fibaro motion sensor. I have about ten of them around the house, but this is the only one that gives these kinds of lines (“changed from NULL to 0”). The wakeup interval is 7200 seconds, which is 2 hours, which corresponds to the rule reloading.

Edit:
To see if changing the wakeup time helps, I changed it to 720000. To speed up the change I pressed the button on the device 3 times. The rules are now reloading.

33

OK so we seem to have tracked it down to what might be the cause:
Zwave things get reconfigured and trigger a reload of the rules including the system startup trigger.

@mark_leonard_tuil can you try and get some debug log when you press the button? (in the console: log:set DEBUG org.openhab.binding.zwave)

I have done the same and we’ll see what it brings up…

1 Like
34

I have made a log. I must say I don’t see anything obvious, but then again, I don’t know what I am looking for. Just to give some background so far:

  • My rules get reloaded every 2 hours.
  • This corresponds to Z-wave node 44 (fibaro motion sensor) getting updated.
  • I have replaced the battery of that device.
  • I can trigger this by pressing the b-button 3x on this device.
  • Pressing the b-button 3x on other devices does not have the same effect.
  • I have made a log that starts with me pressing the b-button and stops with the first message of rules reloading.

openhab.log (71.9 KB)

35

I did another test. I use the Max! binding. It is a system to control heating radiators. Max! uses a local hub called the cube. The various radiotors get their imput form the cube. With the binding you can reset the cube. This results in the same reloading of rules behaviour. I have attached the log. I do not think there are entries that (should) account for the rules reloading behaviour. What I see is lines like:

2019-12-23 15:15:22.581 [hingStatusInfoChangedEvent] - 'max:bridge:KEQ0536973' changed from ONLINE to OFFLINE: Rebooting
2019-12-23 15:15:22.593 [hingStatusInfoChangedEvent] - 'max:wallthermostat:KEQ0536973:OEQ1035689' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2019-12-23 15:15:38.142 [me.event.ThingUpdatedEvent] - Thing 'max:bridge:KEQ0536973' has been updated.
2019-12-23 15:15:38.641 [me.event.ThingUpdatedEvent] - Thing 'max:wallthermostat:KEQ0536973:OEQ1035689' has been updated.
2019-12-23 15:15:38.684 [vent.ItemStateChangedEvent] - WallmountedThermostatSlaapkamer_SetTemperature changed from NULL to 16.0
2019-12-23 15:15:39.487 [hingStatusInfoChangedEvent] - 'max:wallthermostat:KEQ0536973:OEQ1035689' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2019-12-23 15:15:40.052 [vent.ItemStateChangedEvent] - ThermostatRadiatorWoonkamerRechts_SetTemperature changed from 20.5 to 0.0

However, I don’t think these events should cause the rules to reload. Nothing is changing about the things and items. All that is happening is things going offline and online and (as a result) things being updated.

Full log:
openhab.log (7.3 KB)

36

6 posts were split to a new topic: Rules reload on MAX! binding reconnect

38

I have two situation where this happens. One is

2019-12-24 08:38:14.811 [WARN ] [o.internal.handler.SysteminfoHandler] - No information for channel battery#remainingCapacity with device index 0 :
2019-12-24 08:38:14.813 [WARN ] [o.internal.handler.SysteminfoHandler] - No information for channel battery#remainingTime with device index 0 :
2019-12-24 08:38:34.016 [INFO ] [.smarthome.model.script.System Rules] - System (re)started

and the other is

2019-12-24 09:48:59.284 [INFO ] [l.script.OUTSIDEDIMMABLELIGHTS_RULES] - astro_sun_local_phase_name.state: DAYLIGHT
2019-12-24 09:48:59.285 [INFO ] [.smarthome.model.script.System Rules] - System (re)started

Does this make sense to anyone?

The last one seems to be triggered by the astro add-on.

39

I have also the same behaviour with my fibaro motion sensor since openhab 2.5. After a thing update from my fibaro motion sensor my “system start” rule is triggered.

2019-12-25 14:38:12.393 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:f7e712f7:node25' has been updated.
2019-12-25 14:38:27.905 [INFO ] [e.smarthome.model.script.Systemstart] - Das System wurde neu gestartet
40

It seems like updates to things or things configurations or properties trigger the startup rules.
I tried to retrace the call stack (manually, not sure if this is 100% correct) and is something like this:

BaseThingHandler.updateThing | updateProperties | updateConfiguration
ThingManagerImpl.ThingHandlerCallback.thingUpdated
AbstractManagedProvider.update
AbstractProvider.notifyListeners
AbstractRegistry.updated
ThingRegistryImpl.notifyListenersAboutUpdatedElement
AbstractRegistry.notifyListenersAboutUpdatedElement
AbstractRegistry.notifyListeners
RuleEngineImpl.updated
RuleEngineImpl.added
RuleEngineImpl.scheduleStartupRules

I assume this is a desired behaviour by openHab (?) so the issue might be the bindings updating the things periodically. Now clear why this started apprearing with OH 2.5 though…

41

I notice the same, every few minutes thje system started rule is fired. However I do not see anything weird in the logs or events files. Did not occur with 2.5.Mx versions, only with the release version

42

@stefaanbolle Post both your addons.cfg and addons.config files…maybe something there is an issue.

43

I experienced the same.
For my particular box I solved it by 1) removing restdocs from misc in addons.cfg and restarting OH.
Surprisingly that fixed my zwave binding restarting issues

44

Same setup and behaviour here. My addons.cfg file is as defaults with all commented out (/etc/openhab2/services/addons.cfg, right?). I cleared cache and reseted a dozen of times. I receive the System started notification ramdomly, nothing special in the logs

I’m rolling back to my well proven and stable 2.4 by now… :sweat:

  • Hardware: Rapsberry pi 3b+
  • OS: Raspbian GNU/Linux 9 (stretch)
  • Java Runtime Environment: openjdk version “1.8.0_222”
  • openHAB version: 2.5.0.1
45

Need to verify addons.config also. Location is /var/lib/openhab2/config/org/openhab/addons.config

Do not make a change to this file with OH running. Stop OH, make change, clean cache, and restart.

46

Does this work like other 1.x style config files? i.e. don’t mess with it … just stop OH, delete addons.config, make sure addons.cfg is as you want it, reboot (addons.config recreated automatically)

47

With restdocs getting moved there has been several issues with upgrades and a need to verify both files are correct. Yes, addons.config should be auto created based on addons.cfg.

48

Don’t see anything suspicious on /var/lib/openhab2/config/org/openhab/addons.config. No restdocs references

After upgrade there where some errors in the log files about a “mqtt1” binding not being installed, I thought it was trying to be created as duplicate and removed it from addons.config file (before that binding list was “network,samsungtv,zwave,astro,nest,systeminfo,mptt1,mihome,gpio1,mqtt”)

This is content of mine:

:org.apache.felix.configadmin.revision:=L"2"
action=“telegram”
binding=“network,samsungtv,zwave,astro,nest,systeminfo,mihome,gpio1,mqtt”
felix.fileinstall.filename=“file:/var/lib/openhab2/etc/org.openhab.addons.cfg”
misc=""
package=“standard”
persistence=“mapdb,rrd4j”
service.pid=“org.openhab.addons”
transformation=“jsonpath,map”
ui=“basic,paper,habmin”

49

Did you read any of the update notices?

Stop OH and remove systeminfo binding as I’m sure this one was has changed.

50

I did read them all. I wouldn’t be so brave of upgrading without reading them beforehand!!

I saw sysinfo binding has changed si I had to modify my cpu load item as this channel no longer exist. Updated to cpuload1, it is true that now it reports much lower load than before, but I did not read it is necessary to remove the binding anywhere nor it explains why I get system started events so often. Or am I missing something??

51

Also did all of above, but issue still remains