@Chris - did you get a chance to take a further look at this? Thanks
There’s nothing obvious. The only thing I can see is it’s possible there’s a thread sync issue, although I’m not sure why two threads would be starting polling at the same time. In any case, I’ll add some synchronisation and we can see if it helps.
Thanks. Let me know when it’s ready to test and I’ll see if that helps.
Edit: I’m using the test binding 
hi, sorry for the delay. was busy the last 2 weeks and moved backward to OH1. Again all was way smoother and all problems gone i had with OH2…even though i of course enjoyed the changes that came with OH2…
Today i had an interesting observation…OH1…my old setup running for few days now…and suddenly the same ghost behaviour i had with OH2. AND again…its all coming immediately after sunset is coming…so for me its definitely related to ASTRO binding. My question if there is anything i can do/try to proof this…
2017-09-22 19:09:00 - MySunset_Event state updated to ON
2017-09-22 19:09:00 - MySunset_Event state updated to OFF
2017-09-22 19:09:00 - HouseNr_Switch received command ON This one should go on
2017-09-22 19:09:00 - HouseNr_Switch state updated to ON
2017-09-22 19:09:00 - Axis_Power state updated to 0
2017-09-22 19:09:00 - Sonnenkraft_Power state updated to 0
2017-09-22 19:09:01 - Router_Power state updated to 7
2017-09-22 19:09:01 - FGS223_Switch1 state updated to ON GHOST
2017-09-22 19:09:01 - FGS223_Switch1 state updated to ON
2017-09-22 19:09:04 - PowerTotal received command 122.4
2017-09-22 19:09:05 - Hofer_OGwater state updated to 979
2017-09-22 19:09:07 - HomeOffice_Switch state updated to ON GHOST
2017-09-22 19:09:08 - HomeOffice_Power state updated to 1.1
2017-09-22 19:09:09 - Sonnenkraft_Switch state updated to ON GHOST
2017-09-22 19:09:09 - PVng5mono_Power state updated to 0
2017-09-22 19:09:09 - pvmeter state updated to 0.3
2017-09-22 19:09:09 - PVng5mono_Switch state updated to ON
2017-09-22 19:09:09 - PVng5poly_Power state updated to 0.4
2017-09-22 19:09:09 - pvmeter state updated to 0.4
2017-09-22 19:09:09 - PVng5poly_Switch state updated to ON
2017-09-22 19:09:09 - Sonnenkraft_Power state updated to 2.5
2017-09-22 19:09:09 - FGS223_Switch1 state updated to ON
2017-09-22 19:09:10 - HomeOffice_Power state updated to 1.4
2017-09-22 19:09:11 - HomeOffice_Power state updated to 0.6
2017-09-22 19:09:12 - HomeOffice_Power state updated to 0.4
2017-09-22 19:09:13 - PVng4_Power state updated to 0.7
2017-09-22 19:09:13 - HomeOffice_Switch state updated to ON
2017-09-22 19:09:13 - Axis_Switch state updated to ON GHOST
2017-09-22 19:09:13 - PVng4_Switch state updated to ON GHOST
2017-09-22 19:09:14 - Axis_Power state updated to 0.5
2017-09-22 19:09:14 - PVng5mono_Switch state updated to ON
2017-09-22 19:09:14 - PVng4_Power state updated to 0.9
2017-09-22 19:09:14 - PVng5poly_Power state updated to 0.4
2017-09-22 19:09:14 - PVng5poly_Switch state updated to ON
2017-09-22 19:09:14 - PVng5mono_Power state updated to 0.3
2017-09-22 19:09:14 - PVng5mono_Switch state updated to ON
2017-09-22 19:09:14 - pvmeter state updated to 0.7
2017-09-22 19:09:15 - FGS223_Switch1 state updated to ON
2017-09-22 19:09:15 - HomeOffice_Power state updated to 0.3
2017-09-22 19:09:15 - Axis_Power state updated to 0.7
2017-09-22 19:09:16 - PVng5mono_Power state updated to 0.3
2017-09-22 19:09:16 - Fristar_Power state updated to 123.1
2017-09-22 19:09:16 - Axis_Power state updated to 0.9
2017-09-22 19:09:17 - FGS223_Switch1 state updated to ON
2017-09-22 19:09:17 - HomeOffice_Power state updated to 0.4
2017-09-22 19:09:17 - Axis_Power state updated to 1.2
2017-09-22 19:09:18 - Fristar_Power state updated to 82.4
2017-09-22 19:09:18 - HomeOffice_Power state updated to 0.3
2017-09-22 19:09:19 - LivingRoom_Power state updated to 0
2017-09-22 19:09:19 - Fristar_Power state updated to 46.8
2017-09-22 19:09:19 - PowerTotal received command 121.1
2017-09-22 19:09:20 - Fristar_Power state updated to 36.5
2017-09-22 19:09:20 - HomeOffice_Power state updated to 0.4
2017-09-22 19:09:21 - Fristar_Power state updated to 77.3
2017-09-22 19:09:21 - HomeOffice_Power state updated to 0.3
2017-09-22 19:09:22 - CPU_combined state updated to 3.46555768820644072292225246201269328594207763671875
2017-09-22 19:09:22 - HomeOffice_Switch state updated to ON
2017-09-22 19:09:22 - Axis_Power state updated to 1.4
2017-09-22 19:09:23 - PVng4_Power state updated to 0.9
2017-09-22 19:09:24 - PVng5poly_Power state updated to 0.1
2017-09-22 19:09:24 - pvmeter state updated to 0.4
2017-09-22 19:09:24 - PVng5poly_Switch state updated to ON
2017-09-22 19:09:24 - PVng5mono_Power state updated to 0.2
2017-09-22 19:09:24 - PVng5mono_Switch state updated to ON
2017-09-22 19:09:24 - pvmeter state updated to 0.3
2017-09-22 19:09:24 - FGS223_Switch1 state updated to ON
I would suggest to get the logs in debug mode - hopefully they will help identify what’s happening.
will do,…may only take some days as this phenomena did not show up for a week now.
What is interesting to see is that at least in this high level log the gohst switches do not “receive” any ON but simply update to ON as if there never comes a request via openhab.
Could the HouseNr-Switch produce any rubish…as this is the only one really intended to go on when sunset is ON.
I would suggest populating your rules with logInfo statements to see if you can tie it back to any particular point in the rule as well.
EDIT: You might want to setup a separate log file to only capture your debug logs, that way your main OH log will stay easier to read.
On a side note I think mine was residual persistence in my mqtt broker tied to crash/restarts of Node-RED. I finally caught the crase/restart triggering some of my devices and then today I deleted the mosquitto.db file and on restart saw none of those devices.
Just to add my 2 cents… I’ve been noticing this ever since getting on the development binding, I had to disable my rules regarding my smoke alarms because they would randomly turn “ON”. I’ve looked through logs and didn’t see anything obvious. I just assumed that I had a device on my network that was misbehaving. I’m glad to find out that I may not be going insane and there may be an actual issue.
It seems to be an issue that is afraid of debugging. I have never seen it while debugging was on, so eventually I would turn it back to INFO because it seems to slow the system down and a few days later I would get a notification that the doorbell has rung, even though it didn’t.
Looks like I spoke too soon. My ghosts came back last night. I was able to tie out the time and see that nothing happened with Node-RED cycling and there was nothing in my OH info logs and in fact my mqtt logs clearly show the system was sending 0’s as per my earlier issue and then sent a 100 to my dimmer in the middle of the night (and even tried to send another 0 after the 100 but my rules kicked in then and set the value to 15). @chris did you get a chance to look into the timer issue?
I’ll turn on Zwave debug tonight to see if I can catch it if it happens again.
23-Sep-2017 00:44:47.002 [DEBUG] [org.openhab.binding.mqtt.internal.MqttItemBinding ] - Publishing state 0 to home/masterBathroom/masterbathNorthSinkLight
23-Sep-2017 00:44:47.061 [DEBUG] [org.openhab.binding.mqtt.internal.MqttItemBinding ] - Publishing state 0 to home/masterBathroom/masterbathNorthSinkLight
23-Sep-2017 00:44:47.163 [DEBUG] [org.openhab.binding.mqtt.internal.MqttItemBinding ] - Publishing state 0 to home/masterBathroom/masterbathNorthSinkLight
23-Sep-2017 00:44:47.173 [DEBUG] [org.openhab.binding.mqtt.internal.MqttItemBinding ] - Publishing state 0 to home/masterBathroom/masterbathNorthSinkLight
23-Sep-2017 00:44:47.307 [DEBUG] [org.openhab.binding.mqtt.internal.MqttItemBinding ] - Publishing state 0 to home/masterBathroom/masterbathNorthSinkLight
23-Sep-2017 00:44:47.389 [DEBUG] [org.openhab.binding.mqtt.internal.MqttItemBinding ] - Publishing state 0 to home/masterBathroom/masterbathNorthSinkLight
23-Sep-2017 00:44:47.400 [DEBUG] [org.openhab.binding.mqtt.internal.MqttItemBinding ] - Publishing state 0 to home/masterBathroom/masterbathNorthSinkLight
23-Sep-2017 00:44:47.505 [DEBUG] [org.openhab.binding.mqtt.internal.MqttItemBinding ] - Publishing state 0 to home/masterBathroom/masterbathNorthSinkLight
23-Sep-2017 00:44:47.644 [DEBUG] [org.openhab.binding.mqtt.internal.MqttItemBinding ] - Publishing state 100 to home/masterBathroom/masterbathNorthSinkLight
23-Sep-2017 00:44:47.662 [DEBUG] [org.openhab.binding.mqtt.internal.MqttItemBinding ] - Publishing state 0 to home/masterBathroom/masterbathNorthSinkLight
23-Sep-2017 00:44:47.677 [DEBUG] [org.openhab.binding.mqtt.internal.MqttItemBinding ] - Publishing state 15 to home/masterBathroom/masterbathNorthSinkLight
23-Sep-2017 00:44:47.721 [DEBUG] [org.openhab.binding.mqtt.internal.MqttItemBinding ] - Publishing state 15 to home/masterBathroom/masterbathNorthSinkLight
Yes - this was updated a week or so back. As said earlier though, it’s not related to this issue as it can only do polling (unless polling somehow affects device state, but then it would likely do it every 30 minutes).
Thanks. I am running the binding from a couple of days ago which is still doing the 20-30 updates in a row w/i a matter of milliseconds. Agree that it doesn’t always coincide with these ghost triggers, was just grasping at straws. I’ll pull another log on a multi-update and post back to the other thread not to pollute this one.
I don’t guarantee that the multi-polling issue is resolved. I think I mentioned somewhere, but I couldn’t see any obvious problem/reason for the issue so I added some synchronisation between threads in case that was the problem… Let’s see…
Thanks. Here is my latest logs to see if they help diagnose what’s going on:
still struggling a lot recently with my ghost switching effect. I’m also pretty sure that OH is not the issue here. Could you please do me a favour and check the uploaded DEBUG log if you see any central point/item that forces these switches to GO on almost every evening…some evenings its not, but most of the time arround 5pm it starts multiple switches ON. Also the amount of switches that turns on varies, but e.g. today the following have been turned ON.
Can you please check the logs and see if you find any suspect that helps me to start believing in my home automation system again…
2017-11-07 17:15:05.883 [vent.ItemStateChangedEvent] - DBlight_Switch changed from OFF to ON…NODE 4
2017-11-07 17:15:22.859 [vent.ItemStateChangedEvent] - Solar_Switch changed from OFF to ON …NODE 8
2017-11-07 17:23:43.509 [vent.ItemStateChangedEvent] - DriveInRelay_Switch changed from OFF to ON…NODE 45
The Link to the openhab-log file…
https://1drv.ms/u/s!AqVcwrl1pLMGtn6M5MRv7RbPXqYZ
Many Thanks, really suspect everyone from USB stick to KeyFOB…
Strange also, as these switches do not listen to any association group at all…
I don’t see anything in the logs that indicate anything wrong. The state gets updated following a message from the device, but the binding doesn’t send a command to change its state - it appears to be unsolicited.
Just a point on this - devices don’t listen for associations. Other devices get configured to send notifications, so it would be other devices that potentially could be configured with an association to change the state…
Thanks for your check…
That means - OH (the binding) does see the “change state of a switch” but does not sniff what messages made other nodes react like this…hm, then DEBUG logging does not help at all in this case… 
If you say “get configured to send notifications”…where would i find such settings?
Configuration Parameters? or Device Configuration?..
I guess “include in ALL ON Groups” needs to be excluded as well in order to never react to ALL ON notifications, right?
I’m not sure I understand what you mean. The binding only logs ZWave information. In this case, it logs the messages coming in from the device to say that the device has changed state. It doesn’t log what changed the state - either because it wasn’t triggered through ZWave, or at least it wasn’t triggered through the ZWave binding.
This effectively points to either the device randomly changing state (which seems unlikely if there are multiple devices doing this) or to something else in the ZWave network sending the command through a linked association.
Associations are configured in the configuration options in each thing. If a device supports associations then there should be an associations section shown in HABmin (this is a separate section to Configuration Parameters and Device Configuration).
Yes, if you are using “All On” type commands, then you might need to disable this function in switches that don’t require it.
Thanks Chris…
I mean that my hope was that the binding logs all traffic in the zwave network that even is not related to the controller. So i could see if a certain message not intended for the controller is in charge of turning suddenly ON some switches. Relatively sure that it has to be some trigger from a node otherwise not always the same switches turn ON without any defined rule.
Not using SWITCH-ALL, but my thought is that if there is a e.g. alarm from a sensor that sends ALL notifications that some ALL-configured nodes would react…
Strange to me that this behaviour never happened for years but suddenly…but one can also assume that by growing the amount of nodes over time, the “bad” guy came in some day…
Cheers,
No - the controller doesn’t even see all the traffic… It’s a network - nodes can communicate directly, and they don’t have to go via the controller.