Hi,
i recently changed from OH1 to OH2…now observed two days in a row that by itself several of my zwave plugs turned on arround 19h30…as it happened twice i started to be irritated and annoyed to face some instability in my installation.
So I did check the logs…arround that time I can see the following in openhab.log…due to the time it happens it looks like related to a rule i use to start a switch when sunset starts…but in my rule only a single switch should go ON and not arround 10.
2017-09-06 19:25:00.083 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression ‘0 25 19 6 9 ? 2017’ has no future executions anymore
2017-09-06 19:25:00.114 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression ‘0 25 19 6 9 ? 2017’ has no future executions anymore
2017-09-06 19:25:00.116 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression ‘0 25 19 6 9 ? 2017’ has no future executions anymore
2017-09-06 19:26:11.360 [ERROR] [org.openhab.io.net.http.HttpUtil ] - Fatal transport error: java.net.NoRouteToHostException: No route to host (Host unreachable)
2017-09-06 19:26:11.361 [ERROR] [ab.binding.http.internal.HttpBinding] - No response received from ‘http://192.168.1.10:8080/user/var/120/10251/0/0/12528’
2017-09-06 19:28:00.096 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression ‘0 28 19 6 9 ? 2017’ has no future executions anymore
2017-09-06 19:28:00.099 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression ‘0 28 19 6 9 ? 2017’ has no future executions anymore
2017-09-06 19:28:00.123 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression ‘0 28 19 6 9 ? 2017’ has no future executions anymore
Have you set up associations between your switch and the other zwave devices?
There is nothing in the logs that are relevant to the behavior you are describing.
Look in your events.log and see if you can see commands being sent to these other Items (which is what would happen if the commands are coming from OH) or whether the Items are just being updated, which is what I would expect if there are associations set up between your switch and the other devices.
If there are associations, that is all handled outside of OH. Essentially the device your HouseNr_Switch is attached to is sending ON commands to the other zwave devices directly, bypassing OH.
here is what happens (HouseNr_Switch receives ON as the sunset is set for 19:23 which seems the trigger for all the other switches below o as well change from OFF to ON…
For me, like you write above, the others do not receive anything…but change. Is this an indicator that there is communication going on beween devices not involving the controller.
Again, its strange as this was never before in OH1 + I now checked all associations again in HABMIN but only set-able and set is the OpenhabController Group which I guess is Nr1 - meaning “send to controller”…
2017-09-07 19:20:05.704 [ItemCommandEvent ] - Item ‘RTonline_Switch’ received command ON
2017-09-07 19:20:07.749 [ItemCommandEvent ] - Item ‘NG4vidOnline_Switch’ received command ON
2017-09-07 19:23:00.042 [ItemCommandEvent ] - Item ‘HouseNr_Switch’ received command ON
2017-09-07 19:23:00.049 [ItemStateChangedEvent ] - HouseNr_Switch changed from OFF to ON
2017-09-07 19:23:03.515 [ItemStateChangedEvent ] - Solar_Switch changed from OFF to ON
2017-09-07 19:23:08.565 [ItemStateChangedEvent ] - HomeOffice_Switch changed from OFF to ON
2017-09-07 19:23:10.272 [ItemStateChangedEvent ] - PVng4_Switch changed from OFF to ON
2017-09-07 19:23:11.932 [ItemStateChangedEvent ] - Devolo3_Switch changed from OFF to ON
2017-09-07 19:23:19.269 [ItemStateChangedEvent ] - AxisVideo_Switch changed from OFF to ON
I occasionally see similar ghost behavior and haven’t been able to identify what’s causing the issue. I usually find a reboot clears it or sometimes it clears itself after a couple of days.
That is how I’m interpreting it. OH is not commanding them to turn ON, they are, from OH’s perspective, spontaneously turning on. So the problem isn’t with your Rule.
This is well beyond my skill to diagnose. I’m going to recommend putting the zwave binding into debug mode and post the logs that take place between the times HouseNR_Switch receives its command and the others turn ON. Perhaps the binding/controller is seeing the traffic that is causing the Items to switch.
Install Habmin if you haven’t already and look at the all the properties on all of these nodes. Pay particular attention to their assoiation groups. I’m no expert in this stuff so I’m not sure what to tell you after that…
With the logs come back here and post the and then we will summon the expert: [rubs the geini lamp and whispers the name @chris ].
Strange - at least tonight (again sunset like the two days before) nothing happened. So at least its good to see that @rgerrans has same behavior. What usb stick are you using? I have a zwave vision stick.
Any chance you are using an MQTT broker. Mine seem to have started when I made the migration. I did uninstall the OH Cloud Connector thinking that might be doing it but I’ve had it happen even after that.
Yes - heavily using MQTT broker (mosquitto) + MQTT1 binding.
Would not have suspected this area…
Not using OH Cloud connector…(is this the former myOpenhab binding?)
I have the same problem and I think it is not the problem of the stick because I use a ZME_UZB1 Me USB Stick. I also observed the symptoms starting after upgrading to openHAB 2. There are no associations between them. The switches are from Fibaro (Wall Plugs).
In my case they started switching on a IR heating in my garden lodge - three times in 3 months. Mostly starting in the night, so the heating was running the whole night and mostly a day. It was like a Finnish sauna.
Two times I did not notice but could see it later in my grafana log. I am glad that nothing happened like starting a fire.
Now I have a workaround that if the heating switches are turned on there is a check if a master switch is turned on also. But this is not solving the error.
I have also installed the MQTT but I do not use it actively, I only played around a bit.
Should I try to uninstall it? But results are showing in months (if nothing happened).
I’m using zwave, mqtt and the openhab cloud since more than one year (with an ZME_UZB1) and never had any “ghost” switching going on.
So it might be something else …
The only chance is to monitor the event.log and taking a look what is going on right before the “ghost” event. And don’t forget to take a look at your timers, thread:sleeps and expire binding events …
I’ve tried following the event log in the the past and it’s totally random. As far as the others, all my rules are offloaded to Node-RED and the change in states are passed back through MQTT. I only have a few proxy rules in place but not for the items that change.
@norbert_jordan & @sihui Are you using individual item configs or the event bus for MQTT? Also, what are your settings for QOS and Retain?
Mine are:
MQTT Items
QOS = 2
Retain = true
I suspect that the issue is related to Retain holding the values in MQTT and for some reason they randomly get sent over as a new publish for those devices. It can’t be a Node-RED trigger because for the lights in questions, the rules only respond to a state change of the same lights (I set dimmer values based on time of day). I guess I need to try to correlate my MQTT logs with my event log when a random trigger event happens to see if I can see any communication going back and forth.
hi,
I have a scenario where you can see what happens…in my home system.
HouseNr Switch is triggerd by a sunset rule at 19h23…Solar_Switch, HomeOffice,PVng5,Devolo3, AxisVideo follow without any reason…
2017-09-07 19:23:00.042 [ItemCommandEvent ] - Item ‘HouseNr_Switch’ received command ON
2017-09-07 19:23:00.049 [ItemStateChangedEvent ] - HouseNr_Switch changed from OFF to ON
2017-09-07 19:23:03.515 [ItemStateChangedEvent ] - Solar_Switch changed from OFF to ON
2017-09-07 19:23:08.565 [ItemStateChangedEvent ] - HomeOffice_Switch changed from OFF to ON
2017-09-07 19:23:10.272 [ItemStateChangedEvent ] - PVng4_Switch changed from OFF to ON
2017-09-07 19:23:11.932 [ItemStateChangedEvent ] - Devolo3_Switch changed from OFF to ON
2017-09-07 19:23:19.269 [ItemStateChangedEvent ] - AxisVideo_Switch changed from OFF to ON
2017-09-07 19:25:03.978 [ItemCommandEvent ] - Item ‘RepPres_Switch’ received command ON
2017-09-07 19:25:06.082 [ItemCommandEvent ] - Item ‘RTonline_Switch’ received command ON
2017-09-07 19:25:08.132 [ItemCommandEvent ] - Item ‘NG4vidOnline_Switch’ received command ON
2017-09-07 19:30:03.995 [ItemCommandEvent ] - Item ‘RepPres_Switch’ received command ON
2017-09-07 19:30:06.082 [ItemCommandEvent ] - Item ‘RTonline_Switch’ received command ON
2017-09-07 19:30:08.291 [ItemCommandEvent ] - Item ‘NG4vidOnline_Switch’ received command ON
2017-09-07 19:00:04.306 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:03:03.668 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:05:43.596 [WARN ] [essage.ApplicationUpdateMessageClass] - Got ApplicationUpdateMessage without request, ignoring. Last message was SendData.
2017-09-07 19:06:03.534 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:09:04.312 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:12:04.379 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:15:03.972 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:15:10.186 [ERROR] [tocol.commandclass.ZWaveCommandClass] - Error extracting value - length=9, offset=6, size=4.
2017-09-07 19:15:10.206 [ERROR] [tocol.commandclass.ZWaveCommandClass] - Error extracting value - length=9, offset=6, size=4.
2017-09-07 19:15:10.240 [ERROR] [tocol.commandclass.ZWaveCommandClass] - Error extracting value - length=9, offset=6, size=4.
2017-09-07 19:15:50.967 [WARN ] [essage.ApplicationUpdateMessageClass] - Got ApplicationUpdateMessage without request, ignoring. Last message was SendData.
2017-09-07 19:16:28.936 [WARN ] [l.serialmessage.SendDataMessageClass] - NODE 44: Already processed another send data request for this callback Id, ignoring.
2017-09-07 19:16:29.096 [WARN ] [essage.ApplicationUpdateMessageClass] - Got ApplicationUpdateMessage without request, ignoring. Last message was SendData.
2017-09-07 19:18:04.239 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:21:04.171 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:23:00.089 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression ‘0 23 19 7 9 ? 2017’ has no future executions anymore
2017-09-07 19:23:00.118 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression ‘0 23 19 7 9 ? 2017’ has no future executions anymore
2017-09-07 19:23:00.122 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression ‘0 23 19 7 9 ? 2017’ has no future executions anymore
2017-09-07 19:24:03.742 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:26:00.092 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression ‘0 26 19 7 9 ? 2017’ has no future executions anymore
2017-09-07 19:26:00.112 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression ‘0 26 19 7 9 ? 2017’ has no future executions anymore
2017-09-07 19:26:00.118 [INFO ] [Manager$ExpressionThreadPoolExecutor] - Expression ‘0 26 19 7 9 ? 2017’ has no future executions anymore
2017-09-07 19:27:03.660 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:30:04.197 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:31:51.527 [WARN ] [l.serialmessage.SendDataMessageClass] - NODE 43: Already processed another send data request for this callback Id, ignoring.
2017-09-07 19:33:03.727 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:36:03.671 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:38:01.469 [WARN ] [andclass.ZWaveApplicationStatusClass] - Unsupported status 0x17 for command class APPLICATION_STATUS (0x22).
2017-09-07 19:38:01.513 [WARN ] [andclass.ZWaveApplicationStatusClass] - Unsupported status 0x17 for command class APPLICATION_STATUS (0x22).
2017-09-07 19:38:03.214 [WARN ] [andclass.ZWaveApplicationStatusClass] - Unsupported status 0x17 for command class APPLICATION_STATUS (0x22).
2017-09-07 19:38:13.729 [WARN ] [andclass.ZWaveApplicationStatusClass] - Unsupported status 0x17 for command class APPLICATION_STATUS (0x22).
2017-09-07 19:38:17.046 [WARN ] [andclass.ZWaveApplicationStatusClass] - Unsupported status 0x17 for command class APPLICATION_STATUS (0x22).
2017-09-07 19:39:04.209 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:42:04.056 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:45:03.692 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:48:04.209 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:51:04.138 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:51:42.258 [WARN ] [l.serialmessage.SendDataMessageClass] - NODE 43: Already processed another send data request for this callback Id, ignoring.
2017-09-07 19:51:42.675 [WARN ] [l.serialmessage.SendDataMessageClass] - NODE 43: Already processed another send data request for this callback Id, ignoring.
2017-09-07 19:54:03.689 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item 'RestO2state’
2017-09-07 19:57:03.584 [WARN ] [.classic.internal.servlet.CmdServlet] - Received unknown command ‘—’ for item ‘RestO2state’
In my case it happened 2 days in a row…always arround the time where Astro binding does trigger a sunset event…
But again, last 2 days nothing happened…strange and highly annoying when you go on holidays and all night long some devices are ON…that should not
Regarding RestO2state…its a value from my wood heating that is pushed via RestAPI. As it is off right now it does not provide useful values…so its a ‘—’, which seems to produce the Error Extracting stuff.
Since my transfer to OH2 its still little messy but right now i try to get the major items smooth.
When you say “long ago”…how can I fix this if i’m using 2.1 OH (so quite outdated)…with .kar binding file and i do not want to update the complete system to 2.2 (as several users see more instability)…
Can i upload the latest Astro jar file to addons and it takes the latest one…so the single file and not the one from kar file?
I have never used that but as far as I understand several other posts regarding this “offline” file it always draws the binding versions from that kar file during binding re-installation and not the latest/newest.
As long as you don’t have a slow data connection I would not use the kar file …
Nope, astro binding is part from ESH and therefore there is no jar file to download. But their is a hack for it which seems to work:
But do note that sometimes the further development of a binding requires also changes in the runtime (don’t know if that is the case with this hack) so you could encounter even more problems because of the “mismatch”.
Actually that was only the case from #1025 to #1033 where there was a critical bug which has been fixed now.
I’m using #1034 at the moment and it runs pretty smoothly. This was also the case before #1025. There have been several issues with the astro binding lately but at the moment it runs without any problems.
Hm, thats funny - i did update via web often and after build 1025 it was a mess. So i decided to leave oh2.2 away from my home for a while…will give it another try now…
The only problem I found today was that Alexa does not switch my tv via harmony binding anymore, although it works fine with my zwave lights.
No time yet to dig into it any deeper, but maybe it’s just a hickup …
ok…maybe i was too quick. lets see how the snapshotting goes this time…
Could you please link me to some place where backup is described so i do also get all the paper ui DB entries…would be a nightmare if i loose all that stuff. also how to restore. Did not see anything in the doc.manual section…thanks!
