OH randomly updates items

Hi guys,

I’m having some very strange and critical problem which occurs for a longer time but more and more often. I started with OH 2.5 where some of my basic sensors and controls were in place. With OH 2.5 everything was OK (I should also say, at that time I had only few action items/switches). Then I’ve updated to 3.0/3.1/3.2/3.3 and I started to experience some very strange issues. In some special circumstances, when an update happens (an update is triggered), then another item is also getting an update. This means, I’m opening my garage gate and suddenly the lights are turned off in the house. What is strange, this issue is not constantly happening and also the triggered item is different. Sometimes the the rollershutters are closed or the front gate is opened.
The issue also occurs randomly, there are sometimes days or a week and everything is OK, then suddenly happens this.
Originally in OH 3.0 I experienced this issue only ones a month, now I’m running on 3.3M1 and I experience it every day or second day.
In the log, I do not see anything strange, suddenly an item gets an update. The only point what is common, there is always a trigger (another item update) before/after this happens, which is triggered by a user or an automation.

A sample log:

2022-02-23 10:16:45.709 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'ZM_Monitor1_Image' changed from raw type (image/jpeg): 167877 bytes to raw type (image/jpeg): 180873 bytes
2022-02-23 10:16:52.300 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'Switch_FrontGate_OnOff2' received command OFF
2022-02-23 10:16:52.311 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'Switch_FrontGate_OnOff2' predicted to become OFF
2022-02-23 10:16:52.315 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Switch_FrontGate_OnOff2' changed from ON to OFF
2022-02-23 10:16:53.039 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'Switch_LampsIndoorAll' received command OFF
2022-02-23 10:16:53.043 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Switch_LampsIndoorAll' changed from ON to OFF
2022-02-23 10:16:55.923 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'ZM_Monitor1_Image' changed from raw type (image/jpeg): 180873 bytes to raw type (image/jpeg): 175058 bytes
2022-02-23 10:16:59.983 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'Switch_LampsL1_OnOff' received command OFF
2022-02-23 10:16:59.985 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'Switch_LampsL1_OnOff' predicted to become OFF
2022-02-23 10:16:59.995 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'Switch_LampsL2_OnOff' received command OFF
2022-02-23 10:16:59.996 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Switch_LampsL1_OnOff' changed from ON to OFF
2022-02-23 10:16:59.997 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'Switch_LampsL2_OnOff' predicted to become OFF
2022-02-23 10:17:00.015 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Switch_LampsL2_OnOff' changed from ON to OFF
2022-02-23 10:17:00.017 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'gLampsIndoor' changed from ON to OFF through Switch_LampsL2_OnOff
2022-02-23 10:17:00.019 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'gLamps' changed from ON to OFF through gLampsIndoor

The expected item update was ‘Switch_FrontGate_OnOff2’ → OFF
The unexpected item update was ‘Switch_LampsL1_OnOff’ → OFF

An additional information: most of my action items as communicating through MQTT (Sonoff switches, custom nodemcu implementation, tradfri buttons, …). When such update happens, I do not see any incoming message in MQTT explorer, so the event is not coming from the device.

Any help is appreciated, how can I find out, what the hell is going on here …

Do you have rules that interact which the items that get receive commands?

Note: The log shows ItemCommandEvents not Updates.

Does that happen to be a member of a Group, 'Switch_LampsIndoorAll', or is that an Item associated with it in some way ?

It will be important in your investigation to distinguish between commands and updates at the openHAB end, these are different events with different possible sources and different effects.

Yes, I have rules. 90% percent of my rules start with a log messages, what I do not see in the log. I just walked through all rules now and added message to every.

This virtual switch is used to turn on/off multiple real switches, but not trough a group operation. Below you can see the relations and also the only rule which is reacting to ‘Switch_LampsIndoorAll’.

Switch Switch_LampsIndoorAll "Switch lamps (All indoor)" (gLampsIndoor, gHouse)
Group:Switch:OR(ON, OFF) gLampsIndoor "Lamps indoor" <light> (gLamps, gHouse)
Group:Switch:OR(ON, OFF) gLamps "Lamps" <light>
Group gHouse "House" <house>
rule "All internal lights - on/off"
    Item Switch_LampsIndoorAll changed
    if(Switch_LampsL1_OnOff.state != Switch_LampsIndoorAll.state)
        sendCommand(Switch_LampsL1_OnOff, Switch_LampsIndoorAll.state.toString)

    if(Switch_LampsL2_OnOff.state != Switch_LampsIndoorAll.state)
        sendCommand(Switch_LampsL2_OnOff, Switch_LampsIndoorAll.state.toString)

Okay, so that rule explains the -L1 and -L2 commands, so we can now ignore those.

Who/what can command Switch_LampsIndoorAll is the next thing to look for.

@rossko57 what did you exactly mean by this? Do you have any suggestion what I could do to find out more about my mystery?

I mean that in your original post, you talked a lot about updates. But the events.log (and well done for including it) shows that the unwanted actions are really commands. These are different things in openHAB, like cause and effect.

Already made my suggestion to find out what can issue commands to Switch_LampsIndoorAll, likely that will be rules, or GUI.

I’ve searched through all my rule files (luckily I’m writing the rules in files), and the only place where the ‘Switch_LampsIndoorAll’ was found is that rule, I’ve posted earlier, but this is also just reading but not writing the item.
When searching the whole OH strucuture, here are the results:

rules\scenes.rules - Found in that only rule, mentioned above
sitemaps\watch.sitemap - There is a switch item defined
sitemaps\ _quickaccess.sitemap - There is a switch item defined
items\scenes.items - Definition of the item

Have you ever, at any time, created a rule in the UI which you may have forgotten about?

This link will help you make sure rule activity gets logged.

Alright, then that leaves any GUI as suspects for issuing commands. What was open at the time? Includes phone apps and MainUI in a browser window at the back.

  1. I have a wall mounted tablet where habpanel is running (always), but habpanel does not control this switch
  2. I’m using the OH mobile app (iOS), but was not used at that time
  3. I’m using the OH iWatch app, but was not used at that time - this is quite new, the issues were happening also in the past
  4. My wife is using the OH mobile app (android) - she was triggering the garage close event

BUT, this is the situation what happened today. Sometimes the same or similar happens also when the app (or her app) is not used.

Frankly, I have a feeling, that OH server is triggering it and not the apps.

Yes and no. I have also some test rules created on the UI, but I have also checked them (have only 3-4).

Searching for this special item-name is not enough! The item is member of group in more then one level. Do you have rules that act upon changes to those groups, possibly sending commands to members of the group? That way the item-name would not show in the rule!

It’s really unlikely that you would have the only OH server in the world that spontaneously issues commands to non-random devices.

Get yourself a good idea of what Items exactly are affected. As @opus points out, “parent” Group hierarchies are meant to pass commands down the line.

We should see commands to Groups in your events.log, no sign in the sample shown, but do keep it in mind.

Check in your MainUI that your Item has no unexpected links - Items defined from file with no links may later be given links from UI. This is an unlikely source of commands, though.

1 Like

Sorry for the long quiet here, I did not have much time for OH. In the meanwhile, I’ve removed the hierarchies for groups as these were not used for anything and could complicate the life.
I’ve also checked the group rules, but did not find anything yet.

Yes, I know and most probably you are right, but the facts, that these strange things does not happen every time and always some other switch is getting an action lead me to this conclusion. If there would be a rule which is wrongly implemented, then always the same would happen. But this is not true.

Never mind, I’ll check all the group actions and items to see, if there is no duplicate assignments and will give here a feedback.

Hi guys,

An update here! I was able to see a very similar issue, when I save my item file, which holds all my MQTT items. In such case some of my items are receiving a command. What is strange, that not all items are receiving a command. Do you have any answer what the hell is going one?

Here is the result of one save on the mqtt.items file:

2022-03-15 12:01:16.588 [INFO ][el.core.internal.ModelRepositoryImpl] - Loading model 'mqtt.items'
==> /var/log/openhab/events.log <==
2022-03-15 12:01:18.279 [INFO ][openhab.event.ItemCommandEvent      ] - Item 'Switch_LampsIndoorAll' received commandOFF
2022-03-15 12:01:18.282 [INFO ][openhab.event.ItemStateChangedEvent ] - Item 'Switch_LampsIndoorAll' changed from ON to OFF
2022-03-15 12:01:18.295 [INFO ][openhab.event.ItemCommandEvent      ] - Item 'Switch_LampsL1_OnOff' received commandOFF
2022-03-15 12:01:18.302 [INFO ][openhab.event.ItemCommandEvent      ] - Item 'Switch_LampsL2_OnOff' received commandOFF
2022-03-15 12:01:18.304 [INFO ][penhab.event.ItemStatePredictedEvent] - Item 'Switch_LampsL1_OnOff' predicted to become OFF
2022-03-15 12:01:18.311 [INFO ][penhab.event.ItemStatePredictedEvent] - Item 'Switch_LampsL2_OnOff' predicted to become OFF
2022-03-15 12:01:18.321 [INFO ][openhab.event.ItemCommandEvent      ] - Item 'Switch_GarageLight2_OnOff' received commandON
2022-03-15 12:01:18.323 [INFO ][openhab.event.ItemStateChangedEvent ] - Item 'Switch_LampsL1_OnOff' changed from ON to OFF
2022-03-15 12:01:18.324 [INFO ][openhab.event.ItemStateChangedEvent ] - Item 'Switch_LampsL2_OnOff' changed from ON to OFF
2022-03-15 12:01:18.326 [INFO ][hab.event.GroupItemStateChangedEvent] - Item 'gLampsIndoor' changed from ON to OFF through Switch_LampsL2_OnOff
2022-03-15 12:01:18.328 [INFO ][penhab.event.ItemStatePredictedEvent] - Item 'Switch_GarageLight2_OnOff' predicted to become ON
==> /var/log/openhab/openhab.log <==
2022-03-15 12:01:18.274 [INFO ][enhab.core.model.script.scenes.rules] - Main door remote >> State: toggle; Command: 
2022-03-15 12:01:18.284 [INFO ][enhab.core.model.script.scenes.rules] - All lights on-off triggered OFF
2022-03-15 12:01:18.299 [INFO ][enhab.core.model.script.scenes.rules] - External remote >> State: brightness_up_click; Command: 

I would guess that is likely the work of rules.
When you reload an xxx.items file, it reinitializes the changed Items, as it should. They will get NULL state as a consequence.
A while later, a remote device might check in with a routine status report or similar, and Item will get updated to a sensible value. The delay of some minutes from items file load would support that theory, and also tend to rule out buggy GUI widgets.

Note, that will be a state change event, and will trigger any rules listening for Item changes.

You will not see the reinitialize to NULL in your events.log, but if the theory is correct you would see the later NULL-to-whatever changes. Have a closer look in your log before the time of the snippet shared.

The standard initialization process you mentioned above is known also by me, I’ve seen that couple of times in the log when the OH server was restarted, but I did not see when a file item file was re-saved. I’ve checked the event log and I do not see initialization to null before the save event (BTW: the snippet I’ve shared above start with the save event → loading model ‘mqtt.item’).

For example ‘Switch_LampsIndoorAll’ is a virtual switch, it is not connected to a physical device.

Switch Switch_LampsIndoorAll "Switch lamps (All indoor)" (gLampsIndoor, gHouse)

The “Main door remote” and “External remote” are IKEA Tradfri remotes. Why are these receiving actions (which is a button press on the device)? Also if you see, both are receiving different commands. I think these were the last actions from these remotes.

String Rmt_EntryDoor_Action "Entry door remote [%s]" <button> (gHouse) {channel="mqtt:topic:myMQTTBroker:tradfri_rmt_1:Action"}
Thing topic tradfri_rmt_1 "Tradfri Remote 01" 
            Type string : Action    "Action"                    [ stateTopic="zigbee2mqtt/tradfri_rmt_1/action", postCommand=false ]
            Type number : Battery   "Battery"                   [ stateTopic="zigbee2mqtt/tradfri_rmt_1/battery" ]     
            Type number : Linkquality "Link quality"            [ stateTopic="zigbee2mqtt/tradfri_rmt_1/linkquality" ]               

Another anomaly is, why only these items are getting updates? In the mqtt.items file I have more than 40 items defined.

NOTE: I’ve a persistence service enabled, which is restoring some items states, but these items are not a part of it.