Testing Z-Wave binding on openHAB-2

@feens I would suggest editing the master controller setting in the z-stick configuration and saving the configuration (you probably need to set if off, then back on again).

Is this the first time you’ve upgraded the binding for a few days?

@chris first of all thanks for implementing the popp scene controller so quickliy, small question. When I leave all the parameters default, should the scene number Item be changing when a button is pressed? (It does not at the moment)

Also, it looks like that after:

nothing is done with the zEvent?

2016-03-13 12:26:28.367 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 1D 05 5B 03 32 00 02 80 
2016-03-13 12:26:28.368 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-03-13 12:26:28.369 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 04 00 1D 05 5B 03 32 00 02 80 
2016-03-13 12:26:28.370 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0B 00 04 00 1D 05 5B 03 32 00 02 80 
2016-03-13 12:26:28.371 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, payload=00 1D 05 5B 03 32 00 02 
2016-03-13 12:26:28.371 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 29: Application Command Request (ALIVE:PING)
2016-03-13 12:26:28.372 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 29: Incoming command class CENTRAL_SCENE
2016-03-13 12:26:28.372 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 29: Received central scene command (v0)
2016-03-13 12:26:28.373 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 29: Received scene 50 at time 0
2016-03-13 12:26:28.373 [DEBUG] [ssage.ApplicationCommandMessageClass] - Transaction not completed: node address inconsistent.

I wouldn’t think so, but I guess that’s up to the device. However, from my understanding, each button has a different ID, and if you double, tripple, press-and-hold, then you also get a different ID (again, depending on what the device implements). If you do the same thing twice, then the number won’t change (as far as I know).

That’s a definite “ooops” mistake! I guess you’re compiling and testing this (??) - if so, please add the following line -:

this.getController().notifyEventListeners(zEvent);

I’ll also add it here, so no need for a PR (unless you find bigger problems), but if you are testing now, this should get you moving…

thanks, I am definitely testing this :slight_smile:

FYI the number 02 in the message correlates to the button pressed (second last value):

2016-03-13 12:26:28.367 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 1D 05 5B 03 32 00 02 80

this value becomes 01 when button 1 is pressen and so forth:

2016-03-13 12:58:06.956 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 1D 05 5B 03 BB 00 01 0A

The screne number 185 (?):

2016-03-13 12:56:16.962 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 29: Received scene 185 at time 0

185 in this case, keeps increasing (186, 187 etc) over time when a button is pressed.

You’re right - the scene ID should be offset+3

With both changes, when I press button 4 I get:

2016-03-13 13:09:35.694 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 1D 05 5B 03 C2 00 04 76 
2016-03-13 13:09:35.697 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-03-13 13:09:35.697 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 04 00 1D 05 5B 03 C2 00 04 76 
2016-03-13 13:09:35.698 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0B 00 04 00 1D 05 5B 03 C2 00 04 76 
2016-03-13 13:09:35.699 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, payload=00 1D 05 5B 03 C2 00 04 
2016-03-13 13:09:35.700 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 29: Application Command Request (ALIVE:DETAILS)
2016-03-13 13:09:35.700 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 29: Incoming command class CENTRAL_SCENE
2016-03-13 13:09:35.701 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 29: Received central scene command (v0)
2016-03-13 13:09:35.701 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 29: Received scene 4 at time 0
2016-03-13 13:09:35.702 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2016-03-13 13:09:35.702 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2016-03-13 13:09:35.703 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Got a value event from Z-Wave network, endpoint = 0, command class = CENTRAL_SCENE, value = 4
2016-03-13 13:09:35.703 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: No converter set for zwave:popp_009303_00_000:1532eca0da2:node29:scene_number
2016-03-13 13:09:35.704 [DEBUG] [ssage.ApplicationCommandMessageClass] - Transaction not completed: node address inconsistent.

I think I need to remove and add the Thing in order to get the converters re-initialized? (I’m guessing here)

It’s possibly a good guess - depending on when you added the device, and when I added central_scene, it may not be set in the thing…

hmmm, after removing and adding (via zwave discovery) still:

2016-03-13 13:14:48.221 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: No converter set for zwave:popp_009303_00_000:1532eca0da2:node29:scene_number

and (thus) no change in the scene number item.

complete log when button 3 was pressed:

2016-03-13 13:14:48.209 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0B 00 04 00 1D 05 5B 03 C7 00 03 74 
2016-03-13 13:14:48.211 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-03-13 13:14:48.212 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0B 00 04 00 1D 05 5B 03 C7 00 03 74 
2016-03-13 13:14:48.213 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0B 00 04 00 1D 05 5B 03 C7 00 03 74 
2016-03-13 13:14:48.214 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, payload=00 1D 05 5B 03 C7 00 03 
2016-03-13 13:14:48.214 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 29: Application Command Request (ALIVE:DONE)
2016-03-13 13:14:48.215 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 29: Incoming command class CENTRAL_SCENE
2016-03-13 13:14:48.216 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 29: Received central scene command (v0)
2016-03-13 13:14:48.217 [DEBUG] [dclass.ZWaveCentralSceneCommandClass] - NODE 29: Received scene 3 at time 0
2016-03-13 13:14:48.218 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2016-03-13 13:14:48.219 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2016-03-13 13:14:48.220 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Got a value event from Z-Wave network, endpoint = 0, command class = CENTRAL_SCENE, value = 3
2016-03-13 13:14:48.221 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: No converter set for zwave:popp_009303_00_000:1532eca0da2:node29:scene_number
2016-03-13 13:14:48.222 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Sent message Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=29, payload=1D 02 84 08 
2016-03-13 13:14:48.223 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Recv message Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, payload=00 1D 05 5B 03 C7 00 03 
2016-03-13 13:14:48.224 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, expected=SendData, cancelled=false

I would take a look at the startup of this thing and see if there’s a problem reading the properties and creating the converter links…

Do a search in ZWaveThingHandler for // Process the channel properties and configuration and debug from there… (Sorry - can’t give you a line number as I’ve rewritten this quite significantly).

Hmm, @chris, can you confirm that CommandClass converter CENTRAL_SCENE is implemented?

2016-03-13 13:36:54.234 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Initialising channel zwave:popp_009303_00_000:1532eca0da2:node29:scene_number
2016-03-13 13:36:54.236 [WARN ] [converter.ZWaveCommandClassConverter] - CommandClass converter CENTRAL_SCENE is not implemented!
2016-03-13 13:36:54.237 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: No converter found for zwave:popp_009303_00_000:1532eca0da2:node29:scene_number, class CENTRAL_SCENE
2016-03-13 13:36:54.586 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'zwave_popp_009303_00_000_1532eca0da2_node29_scene_number-zwave:popp_009303_00_000:1532eca0da2:node29:scene_number' has been added.

Yes…

But… It’s not in the list (which is strange, since I’m sure I added it!)… Take a look in the ZWaveCommandClassConvert.java file - you’ll see a list - add it there (it should be obvious what to do)…

I’ve added this now to the Smart Switch 6. Let’s see if this works before we add it to other devices. You’ll need to delete the thing and add it again, but you’ll need to do that anyway with the next version as there is a major change coming…

It may be a couple of days before the next release as I’ve come across a bug in the ESH core that will need to be resolved before I can proceed :frowning:.

Hi @chris. I’ve started getting initialization errors with my z-wave controller. Tried updating to the latest binding, rebooting etc but the problem is still there. I’ve also tried deleting the controller thing and re-adding, but this didn’t help either.

The controller itself seems ok and works without any issues on OH 1.8 (have tried shutting down OH2 and starting 1.8 on the same machine; even without a reboot the 1.8 works fine without any issues).

The logs show:

2016-03-13 14:34:49.625 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:153705bb323' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
    2016-03-13 14:34:49.630 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occured while initializing handler of thing 'zwave:serial_zstick:153705bb323': java.lang.ClassCastException: java.lang.String cannot be cast to java.lang.Boolean
    java.util.concurrent.ExecutionException: java.lang.ClassCastException: java.lang.String cannot be cast to java.lang.Boolean
    	at java.util.concurrent.FutureTask.report(FutureTask.java:122)[:1.8.0_45]
    	at java.util.concurrent.FutureTask.get(FutureTask.java:206)[:1.8.0_45]
    	at org.eclipse.smarthome.core.common.SafeMethodCaller.callAsynchronous(SafeMethodCaller.java:179)[92:org.eclipse.smarthome.core:0.8.0.201603021108]
    	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:72)[92:org.eclipse.smarthome.core:0.8.0.201603021108]
    	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:56)[92:org.eclipse.smarthome.core:0.8.0.201603021108]
    	at org.eclipse.smarthome.core.thing.internal.ThingManager$7.run(ThingManager.java:636)[98:org.eclipse.smarthome.core.thing:0.8.0.201603021108]
    	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_45]
    	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_45]
    	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)[:1.8.0_45]
    	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)[:1.8.0_45]
    	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_45]
    	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_45]
    	at java.lang.Thread.run(Thread.java:745)[:1.8.0_45]
    Caused by: java.lang.ClassCastException: java.lang.String cannot be cast to java.lang.Boolean
    	at org.openhab.binding.zwave.handler.ZWaveControllerHandler.initialize(ZWaveControllerHandler.java:72)[169:org.openhab.binding.zwave:2.0.0.201603120202]
    	at org.openhab.binding.zwave.handler.ZWaveSerialHandler.initialize(ZWaveSerialHandler.java:76)[169:org.openhab.binding.zwave:2.0.0.201603120202]
    	at org.eclipse.smarthome.core.thing.internal.ThingManager$7$1.call(ThingManager.java:639)[98:org.eclipse.smarthome.core.thing:0.8.0.201603021108]
    	at org.eclipse.smarthome.core.thing.internal.ThingManager$7$1.call(ThingManager.java:1)[98:org.eclipse.smarthome.core.thing:0.8.0.201603021108]
    	at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:170)[92:org.eclipse.smarthome.core:0.8.0.201603021108]
    	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_45]
    	... 3 more
    2016-03-13 14:34:49.640 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:153705bb323' changed from INITIALIZING to UNINITIALIZED (HANDLER_INITIALIZING_ERROR): java.lang.String cannot be cast to java.lang.Boolean

Thanks.

This isn’t anything to do with the controller - it’s to do with the configuration in OH. Is this the first time you’ve updated the binding for a few days, or have you changed each day?

To solve it, I expect you should be able to change the configuration of the “Master Controller” setting, save the config, then change it back and re-save…

Let me know if that works…

Hi all OH2 ZWave testers…

IMPORTANT NOTE: In the next day or two, the next update of the OH2 binding will have a change that will require you to delete all the ZWave things and add them back - along with their items. This will change the way the things are initialised and should solve the duplicate nodes in the inbox issue, and (hopefully!) also the problems with finding devices in the database (although let’s wait and see for this one).

It will also ensure that new devices are added to the inbox immediately (although they might have the wrong name - just saying “Z-Wave Node x” for starters). The idea is that devices get added immediately, then once you approve them, and the various discovery stages are complete, then it will update it’s type to be the correct one for the device.

This uses a reasonably new feature in ESH and unfortunately there is a bug that we need to solve before I can release this, but just take note that next time you upgrade the binding, you’ll likely need to perform a bit of maintenance…

Yes, last time I updated the binding was a few days ago. The problem does seem to be the “Master Controller” setting. Paper UI shows it as unset. Setting it and saving gives an Error 500. However, Habmin was initially showing it SET to Master. Forcing a page refresh, Habmin shows empty for the setting. Selecting the Master Controller from the drop down and saving appears to go through on Habmin. Log also shows that the thing has been updated. However, a page refresh again shows an empty combo on Habmin and Paper UI still shows unset…

There seems to be some issue in saving the change. Not sure where the problem is. Just as a quick test, I tried with another clean copy of OH2, and the controller seems to be picked up and working fine.

Fixed with:

thanks for you help :sunglasses:

Now my nice rule workx:

rule "wallcontrollerprint"
when
	Item zwave_popp_009303_00_000_1532eca0da2_node29_scene_number changed
then
	logInfo("wallc", "wallc={}", zwave_popp_009303_00_000_1532eca0da2_node29_scene_number.state)
end

Cool - glad it’s working :smile:

@chris - Can you tell me what the format is for defining zwave things in a things file. Thanks!

We use the standard ESH thing format, but please don’t do this - please use the online database. If you edit outside of the database, if I need to update something across all things, it will be a nightmare. It’s preferable to edit in the database, and if you want to create an XML file for local testing, then just press the export button.