This was mentioned elsewhere as well. I wonder if ESH has changed something - the binding only enables polling for channels that are linked - it seems that this still works, but the link method maybe isn’t being called under some circumstances now.
I’ll add another log entry when this is called so we can see it, and if it’s not being called, then we probably need to raise this with ESH.
I’ll do a binding update this morning…
Sorry Dan - can you refer me to the discussion on this. Was it related to the association issue we had on the device?
I’ve updated the binding and added two new log entries -:
NODE {}: Channel {} linked - polling started.
(and a corresponding one for stopped).
Let’s see if this shows up in the log - I suspect it doesn’t link on startup, but let’s see.
I think it’s unrelated, but caused by new fibaro firmware which uses the basic command class
See: Fibaro universal binary sensor - very confused
and perhaps also Fibaro FGS-213 (relay switch) problems
Not seeing polling started. Here is the output for one of my lights:
2017-12-10 10:38:44.568 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 47: Polling intialised at 300 seconds - start in 300000 milliseconds.
2017-12-10 10:43:44.569 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 47: Polling...
2017-12-10 10:43:44.569 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 47: Polling deferred until initialisation complete
2017-12-10 10:48:44.569 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 47: Polling...
2017-12-10 10:48:44.569 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 47: Polling deferred until initialisation complete
Also, my previous workaround of unlinking the channel and linking it again does not seem to be working. I don’t think your logging change would have broken this so maybe there are other startup issues. I have to head out for a bit. I can try some more things later.
Just linking in this thread in case it helps…
@chris, do you know why with the latest code I am getting that error? It looks like the new binding automatically adds the node somewhere that I can’t figure out so that when it finds it in zwave.things I get a Duplicate channels error. I have nothing in json config for that thing, where else could the duplicate channel be?
Sorry, but what is “that error” that you’re referring to? I looked back up this thread to see if I could find what you meant, but can’t see anything.
Sorry about that:
I use zwave.things for all my devices. So when I need to add a new device I simply discover it find the channel and then add it to my zwave.things. In this case I added:
Thing zwave:rtc_ct100plus_00_000:controller:node57 "Node 57: CT100 - First Floor" (zwave:serial_zstick:controller) [ node_id=57, binding_pollperiod=600 ] {
Channels:
Type sensor_temperature : sensor_temperature [ config_scale=1 ]
Type thermostat_setpoint : thermostat_setpoint_cooling [ config_scale=1 ]
Type thermostat_setpoint : thermostat_setpoint_heating [ config_scale=1 ]
}
When I do I get:
2017-12-10 13:27:40.510 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'zwave.things'
2017-12-10 13:27:40.719 [ERROR] [.core.internal.folder.FolderObserver] - Error handling update of file '/etc/openhab2/things/zwave.things': Duplicate channels zwave:rtc_ct100plus_00_000:controller:node57:battery-level.
java.lang.IllegalArgumentException: Duplicate channels zwave:rtc_ct100plus_00_000:controller:node57:battery-level
at org.eclipse.smarthome.core.thing.util.ThingHelper.ensureUniqueChannels(ThingHelper.java:162) ~[?:?]
at org.eclipse.smarthome.core.thing.util.ThingHelper.ensureUniqueChannels(ThingHelper.java:138) ~[?:?]
at org.eclipse.smarthome.core.thing.binding.builder.ThingBuilder.withChannels(ThingBuilder.java:82) ~[?:?]
at org.eclipse.smarthome.core.thing.binding.ThingFactory.createThing(ThingFactory.java:102) ~[?:?]
at org.eclipse.smarthome.core.thing.binding.BaseThingHandlerFactory.createThing(BaseThingHandlerFactory.java:279) ~[?:?]
at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.getThingFromThingHandlerFactory(GenericThingProvider.java:483) ~[?:?]
at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.getThingFromThingHandlerFactories(GenericThingProvider.java:466) ~[?:?]
at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.createThing(GenericThingProvider.java:395) ~[?:?]
at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.lambda$20(GenericThingProvider.java:884) ~[?:?]
at java.lang.Iterable.forEach(Iterable.java:75) ~[?:?]
at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.createThingsFromModelForThingHandlerFactory(GenericThingProvider.java:886) ~[?:?]
at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.lambda$3(GenericThingProvider.java:299) ~[?:?]
at java.lang.Iterable.forEach(Iterable.java:75) [?:?]
at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.createThingsFromModel(GenericThingProvider.java:301) [151:org.eclipse.smarthome.model.thing:0.9.0.201712011551]
at org.eclipse.smarthome.model.thing.internal.GenericThingProvider.modelChanged(GenericThingProvider.java:715) [151:org.eclipse.smarthome.model.thing:0.9.0.201712011551]
at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.notifyListeners(ModelRepositoryImpl.java:314) [134:org.eclipse.smarthome.model.core:0.9.0.201712011551]
at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.addOrRefreshModel(ModelRepositoryImpl.java:127) [134:org.eclipse.smarthome.model.core:0.9.0.201712011551]
at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.checkFile(FolderObserver.java:247) [134:org.eclipse.smarthome.model.core:0.9.0.201712011551]
at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.processWatchEvent(FolderObserver.java:311) [134:org.eclipse.smarthome.model.core:0.9.0.201712011551]
at org.eclipse.smarthome.core.service.WatchQueueReader.run(WatchQueueReader.java:209) [109:org.eclipse.smarthome.core:0.9.0.201712011551]
at java.lang.Thread.run(Thread.java:748) [?:?]
Just to make sure I did not have it as a auto defined thing I did:
rm -f /var/lib/openhab2/jsondb/*.json
Probably in the thread you linked to in your previous post 
Yeah - sorry, I was scanning back up this thread looking for messages from @sipvoip and of course that message was from me .
It looks like the database entry for this device has duplicated endpoint 0 and endpoint 1. I’ll delete the battery channel from endpoint 1 and it should sort this out. It looks like the database for the device could probably do with some TLC to remove some of the duplication, although it shouldn’t be a major issue for the most part.
You rock!
So I’ve been restarting the service a bunch of times and keep seeing different behavior. There seems to be a startup issue. I sometimes see the “polling started” debug, but not for all of my linked channels.
183:2017-12-10 20:20:31.806 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 45: Channel zwave:device:93af1255:node45:meter_reset unlinked - polling stopped.
184:2017-12-10 20:20:31.820 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 41: Channel zwave:device:93af1255:node41:time_offset unlinked - polling stopped.
185:2017-12-10 20:20:31.823 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Channel zwave:device:93af1255:node12:meter_reset unlinked - polling stopped.
186:2017-12-10 20:20:31.827 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 33: Channel zwave:device:93af1255:node33:time_offset unlinked - polling stopped.
187:2017-12-10 20:20:31.826 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 78: Channel zwave:device:93af1255:node78:alarm_general unlinked - polling stopped.
188:2017-12-10 20:20:31.828 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 78: Channel zwave:device:93af1255:node78:notification_access_control unlinked - polling stopped.
189:2017-12-10 20:20:31.828 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 51: Channel zwave:device:93af1255:node51:time_offset unlinked - polling stopped.
190:2017-12-10 20:20:31.839 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 45: Channel zwave:device:93af1255:node45:meter_reset linked - polling started.
191:2017-12-10 20:20:31.840 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 41: Channel zwave:device:93af1255:node41:time_offset linked - polling started.
192:2017-12-10 20:20:31.843 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Channel zwave:device:93af1255:node12:meter_reset linked - polling started.
193:2017-12-10 20:20:31.846 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 78: Channel zwave:device:93af1255:node78:alarm_general linked - polling started.
194:2017-12-10 20:20:31.846 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 33: Channel zwave:device:93af1255:node33:time_offset linked - polling started.
195:2017-12-10 20:20:31.846 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 32: Channel zwave:device:93af1255:node32:meter_reset linked - polling started.
196:2017-12-10 20:20:31.847 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 78: Channel zwave:device:93af1255:node78:notification_access_control linked - polling started.
197:2017-12-10 20:20:31.847 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Channel zwave:device:93af1255:node27:meter_reset linked - polling started.
198:2017-12-10 20:20:31.847 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 44: Channel zwave:device:93af1255:node44:meter_reset linked - polling started.
199:2017-12-10 20:20:31.828 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Channel zwave:device:93af1255:node27:meter_reset unlinked - polling stopped.
200:2017-12-10 20:20:31.829 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 44: Channel zwave:device:93af1255:node44:meter_reset unlinked - polling stopped.
201:2017-12-10 20:20:31.828 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 32: Channel zwave:device:93af1255:node32:meter_reset unlinked - polling stopped.
202:2017-12-10 20:20:31.846 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 51: Channel zwave:device:93af1255:node51:time_offset linked - polling started.
Workaround appears to be restarting zwave binding via karaf.
@dan12345, for me the Fibaro Universal sensor suddenly started working after I gave a test drive for hass.io.
E.g. all the same hw - with FGBS included to Aeon stick and attached to raspberry. Just inserted a fresh hass sd card with my wifi preconfigured … booted it up - it discovered the stick by itself and added all the nodes that where there … one of them was FGBS, which suddenly was correctly reporting both channels. Then I shut it down, put back my openhab card - w/out any other changes the FGBS kept working. I even put back a few weeks older binding jar and it still was OK. Still a mistery for me 
are you sure that’s the one with the new firmware? You can tell because the debug logs for the old one will show incoming command class COMMAND_CLASS_SENSOR_BINARY, but the new ones COMMAND_CLASS_BASIC.
Dan
I’m not sure about anything
at the beginning both are added, but, when the incoming message comes - looks to me that that it is the “class_basic”
2017-11-27 23:14:16.759 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes.
2017-11-27 23:14:16.770 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Creating new instance of command class COMMAND_CLASS_BASIC
2017-11-27 23:14:16.772 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2017-11-27 23:14:16.774 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes.
...
2017-11-27 23:14:26.570 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 15: Application update request. Node information received. Transaction TID 1146: [WAIT_DATA] requiresResponse=true callback: 0
2017-11-27 23:14:26.570 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Creating new instance of command class COMMAND_CLASS_SENSOR_BINARY
2017-11-27 23:14:26.571 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_SENSOR_BINARY, endpoint 0 created
2017-11-27 23:14:26.572 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 15: Application update is adding command class COMMAND_CLASS_SENSOR_BINARY.
2017-11-27 23:14:26.573 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Adding command class COMMAND_CLASS_SENSOR_BINARY to the list of supported command classes.
2017-11-27 23:14:26.574 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Creating new instance of command class COMMAND_CLASS_MULTI_CHANNEL
2017-11-27 23:14:26.575 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Command class COMMAND_CLASS_MULTI_CHANNEL, endpoint 0 created
2017-11-27 23:14:26.575 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 15: Application update is adding command class COMMAND_CLASS_MULTI_CHANNEL.
2017-11-27 23:14:58.366 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2017-11-27 23:14:58.368 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Got a value event from Z-Wave network, endpoint = 2, command class = COMMAND_CLASS_BASIC, value = 255
2017-11-27 23:14:58.370 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Updating channel state zwave:device:zw:node15:sensor_binary2 to ON [OnOffType]
2017-11-27 23:14:58.380 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Commands processed 1.
I’ll +1 on the Kwikset problem. I can’t get any of them to successfully join the network. (It aborted my attempt to switch from Homeseer to OH2 over the weekend, unfortunately.)
None of my Dome DMDP1 sensors were working, either. They actually even call out OH as compatible, so not sure what was up with those.
As far as I can see they arent in the database - unless they have a different name. Please feel free to add the device.
If/when I give the Z-wave interface another shot, I’ll look at doing that. The door locks are total blockers because the keypads are used to disarm the security system, so until I’m pretty confident they’ll work, its back-burnered. (I, somewhat unwisely, left the Z-wave testing for last because I assumed if all of my non-standard home automation gear worked – including writing a few bindings – the Z-wave would just work.)
Unfortunately because its replacing an existing HA system that needs to stay running, I need to do a complete cut-over, or parts of the house will be left not working. I may order another Z-wave stick to be able to do some testing at some point.
If you have a windows box, try using the Zensys tool as described here.