Testing Z-Wave binding on openHAB-2

[chris (Chris Jackson)]

@vespaman

but I figure I should report it anyways.

Yes - thanks. I’ll remove this error - or handle it better at least…

[vespaman (Micael)]

@chris

Regarding the ST812, please try tomorrows binding and let’s see if it helps. I have a suspicion that due to startup sequencing, the database might not be 100% complete in all cases and that might be the cause of this issue. If it’s not working tomorrow, then let me know and I’ll take another look.

Chris, not sure if I did the correct thing, but here it is:

1. I updated binding in PaperUI. (verified it is 150319)
2. Stopped OH.
3. Deleted the xml for the node.
4. Restarted OH. The ST812 remained in inbox as unknown.
5. I waited for the ST812 to wake up.
6. After a couple of hours, a new xml arrived.

But still no ST812 reported in the inbox. (only the old report of unknown node)

[chris (Chris Jackson)]

@vespaman

not sure if I did the correct thing

Looks fine…

Ok - we need to find out why some devices don’t get detected. I will generate a new binding for you for testing with more debug. Unfortunately, my IDE updated itself this morning, and now doesn’t work so it might take some time to resolve that first…

[EricB (ericb2745)]

Thank you. I used /dev/ttyUSB1 and it started up.

[jamborta (Tamas Jambor)]

hi all,

I still have no luck starting the 2.0 binding in OH2. I have removed and reinstalled OH, removed other hardware that was attached to the raspberry pi. Still there is nothing in the logs after the line that paper ui installed the zwave binding (despite that it shows up as active if i list all bindings).

(it all works fine with zwwave 1.9)

thanks,

[chris (Chris Jackson)]

Have you followed all the steps to install the controller -:

• Install the binding (we know you’ve done this )
• Install the controller
• Select the COM port
• Hit the discovery button to add other nodes

[jamborta (Tamas Jambor)]

@chris

Have you followed all the steps to install the controller -:

thanks a lot. missed configuration step from there. it is working now.

[shorty707]

good morning

whats that error telling me?

07:46:16.207 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zwave:device:15348538564:node14' has been updated.
07:46:16.458 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zwave:device:15348538564:node14' has been updated.
07:46:16.506 [ERROR] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Size error 2<>1 from config_42_2
07:46:16.711 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zwave:device:15348538564:node14' has been updated.
07:46:16.968 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zwave:device:15348538564:node14' has been updated.
07:46:17.017 [ERROR] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Size error 2<>1 from config_44_2
07:46:17.442 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zwave:device:15348538564:node14' has been updated.
07:46:17.719 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zwave:device:15348538564:node14' has been updated.
07:46:17.969 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zwave:device:15348538564:node14' has been updated.

it its something with parameters… these 2 have not been touched by me and are on default (i think)

[chris (Chris Jackson)]

@shorty707

it its something with parameters… these 2 have not been touched by me and are on default (i think)

I think this means that the device reported it’s only 1 byte, but the database says it’s 2 bytes. It probably means the database needs updating - what device is this for?

[shorty707]

aeon MS6 http://www.cd-jackson.com/index.php/zwave/zwave-device-database/zwave-device-list/devicesummary/73
i have 2 of these … the other one looks good in the log

[shorty707]

the fibaro flood sensor: http://www.cd-jackson.com/index.php/zwave/zwave-device-database/zwave-device-list/devicesummary/127

still makes trouble for me.

So I just deleted the thing. and readded (no new inclusion) …

this throws:

10:59:08.565 [INFO ] [smarthome.event.InboxRemovedEvent   ] - Discovery Result with UID 'zwave:device:15348538564:node16' has been removed.
10:59:08.574 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'zwave:device:15348538564:node16' has been added.
10:59:08.590 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15348538564:node16' changed from UNINITIALIZED to INITIALIZING
10:59:08.614 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occured while initializing handler of thing 'zwave:device:15348538564:node16': java.lang.IllegalStateException: Could not update properties, because callback is missing
java.util.concurrent.ExecutionException: java.lang.IllegalStateException: Could not update properties, because callback is missing
	at java.util.concurrent.FutureTask.report(FutureTask.java:122)[:1.8.0]
	at java.util.concurrent.FutureTask.get(FutureTask.java:206)[:1.8.0]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.callAsynchronous(SafeMethodCaller.java:179)[89:org.eclipse.smarthome.core:0.8.0.201603141848]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:72)[89:org.eclipse.smarthome.core:0.8.0.201603141848]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:56)[89:org.eclipse.smarthome.core:0.8.0.201603141848]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$7.run(ThingManager.java:641)[95:org.eclipse.smarthome.core.thing:0.8.0.201603141848]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)[:1.8.0]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)[:1.8.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0]
	at java.lang.Thread.run(Thread.java:744)[:1.8.0]
Caused by: java.lang.IllegalStateException: Could not update properties, because callback is missing
	at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.updateProperty(BaseThingHandler.java:477)[95:org.eclipse.smarthome.core.thing:0.8.0.201603141848]
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.updateNeighbours(ZWaveThingHandler.java:1086)[181:org.openhab.binding.zwave:2.0.0.201603190202]
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.bridgeHandlerInitialized(ZWaveThingHandler.java:393)[181:org.openhab.binding.zwave:2.0.0.201603190202]
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialize(ZWaveThingHandler.java:226)[181:org.openhab.binding.zwave:2.0.0.201603190202]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$7$1.call(ThingManager.java:644)[95:org.eclipse.smarthome.core.thing:0.8.0.201603141848]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$7$1.call(ThingManager.java:1)[95:org.eclipse.smarthome.core.thing:0.8.0.201603141848]
	at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:170)[89:org.eclipse.smarthome.core:0.8.0.201603141848]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0]
	... 3 more
10:59:08.609 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15348538564:node16' changed from INITIALIZING to ONLINE
10:59:08.612 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15348538564:node16' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
10:59:08.657 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15348538564:node16' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (HANDLER_INITIALIZING_ERROR): Could not update properties, because callback is missing
10:59:08.616 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occured during notification of thing 'zwave:device:15348538564:node16' about bridge initialization at 'null': null
java.lang.NullPointerException
	at org.eclipse.smarthome.core.thing.internal.ThingManager$8.run(ThingManager.java:691)[95:org.eclipse.smarthome.core.thing:0.8.0.201603141848]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)[:1.8.0]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)[:1.8.0]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0]
	at java.lang.Thread.run(Thread.java:744)[:1.8.0]

[chris (Chris Jackson)]

@shorty707

i have 2 of these

Are they the same version? I have a feeling that some of the parameters might have changed lengths at some stage (I seem to recall a discusion about this in the past, but I might be mistaken)…

[shorty707]

@chris

Are they the same version?

no clue how to find out the technical revision or version of that.

from the information printed on the device and packing they are the same. the second one was besides problems in oh also so inaccurate that I now exlcuded it and will return to amazon … so can’t do any further checks with it

[chris (Chris Jackson)]

@shorty707

no clue how to find out the technical revision or version of that.

Have a look in the XML file for now. Do a search for VERSION and you should find the application version… I’ll look at adding this to HABmin.

I guess the other thing is to get a log so I can see exactly what the data looks like for these responses…

[shorty707]

when I “water test” the fibaro flood sensor
the alarm:

11:18:39.436 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Updating zwave:device:15348538564:node16:alarm_general to ON
11:18:39.440 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Updating zwave:device:15348538564:node16:sensor_flood to ON

it only updates:

11:18:39.570 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_device_15348538564_node16_alarm_general changed from OFF to ON

I would expect to also get the device_sensor_flood updated?

full log

11:18:39.400 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 10 07 9C 02 10 00 FF 00 00 90 
11:18:39.408 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
11:18:39.415 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 04 00 10 07 9C 02 10 00 FF 00 00 90 
11:18:39.417 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0D 00 04 00 10 07 9C 02 10 00 FF 00 00 90 
11:18:39.419 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, payload=00 10 07 9C 02 10 00 FF 00 00 
11:18:39.421 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 16: Application Command Request (ALIVE:SECURITY_REPORT)
11:18:39.422 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 16: Incoming command class SENSOR_ALARM
11:18:39.424 [DEBUG] [ndclass.ZWaveAlarmSensorCommandClass] - NODE 16: Received Sensor Alarm Request
11:18:39.425 [DEBUG] [ndclass.ZWaveAlarmSensorCommandClass] - NODE 16: Alarm Report: Source=16, Type=General(0), Value=255
11:18:39.426 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveAlarmSensorValueEvent
11:18:39.427 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 16: Got an event from Z-Wave network: ZWaveAlarmSensorValueEvent
11:18:39.429 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 16: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_ALARM, value = 255
11:18:39.436 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Updating zwave:device:15348538564:node16:alarm_general to ON
11:18:39.440 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Updating zwave:device:15348538564:node16:sensor_flood to ON
11:18:39.442 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 10: Transaction not completed: node address inconsistent.  lastSent=10, incoming=255
11:18:39.570 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_device_15348538564_node16_alarm_general changed from OFF to ON
11:18:40.177 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 10 07 9C 02 10 05 FF 00 00 95 
11:18:40.181 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
11:18:40.185 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 04 00 10 07 9C 02 10 05 FF 00 00 95 
11:18:40.188 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0D 00 04 00 10 07 9C 02 10 05 FF 00 00 95 
11:18:40.192 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, payload=00 10 07 9C 02 10 05 FF 00 00 
11:18:40.194 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 16: Application Command Request (ALIVE:SECURITY_REPORT)
11:18:40.197 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 16: Incoming command class SENSOR_ALARM
11:18:40.199 [DEBUG] [ndclass.ZWaveAlarmSensorCommandClass] - NODE 16: Received Sensor Alarm Request
11:18:40.200 [DEBUG] [ndclass.ZWaveAlarmSensorCommandClass] - NODE 16: Alarm Report: Source=16, Type=Flood(5), Value=255
11:18:40.202 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveAlarmSensorValueEvent
11:18:40.205 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 16: Got an event from Z-Wave network: ZWaveAlarmSensorValueEvent
11:18:40.207 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 16: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_ALARM, value = 255
11:18:40.208 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Updating zwave:device:15348538564:node16:alarm_general to ON
11:18:40.213 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Updating zwave:device:15348538564:node16:sensor_flood to ON
11:18:40.215 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 10: Transaction not completed: node address inconsistent.  lastSent=10, incoming=255
11:18:41.437 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 10 07 9C 02 10 05 00 00 00 6A 
11:18:41.441 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
11:18:41.443 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 04 00 10 07 9C 02 10 05 00 00 00 6A 
11:18:41.445 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0D 00 04 00 10 07 9C 02 10 05 00 00 00 6A 
11:18:41.450 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, payload=00 10 07 9C 02 10 05 00 00 00 
11:18:41.452 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 16: Application Command Request (ALIVE:SECURITY_REPORT)
11:18:41.455 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 16: Incoming command class SENSOR_ALARM
11:18:41.457 [DEBUG] [ndclass.ZWaveAlarmSensorCommandClass] - NODE 16: Received Sensor Alarm Request
11:18:41.459 [DEBUG] [ndclass.ZWaveAlarmSensorCommandClass] - NODE 16: Alarm Report: Source=16, Type=Flood(5), Value=0
11:18:41.461 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveAlarmSensorValueEvent
11:18:41.464 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 16: Got an event from Z-Wave network: ZWaveAlarmSensorValueEvent
11:18:41.466 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 16: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_ALARM, value = 0
11:18:41.468 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Updating zwave:device:15348538564:node16:alarm_general to OFF
11:18:41.471 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Updating zwave:device:15348538564:node16:sensor_flood to OFF
11:18:41.473 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 10: Transaction not completed: node address inconsistent.  lastSent=10, incoming=255
11:18:41.521 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_device_15348538564_node16_alarm_general changed from ON to OFF

[shorty707]

ok additionally to above log. I see discovery of the flood sensor automatically creates the “sensor_flood” item as “number”

When I remeber correct changing that manually in habmin doesnt help …
and I do not know how what I must update in the database to alter that to be a switch?

[chris (Chris Jackson)]

This is likely a problem with the channel definition which is a Number at the moment - it probably should be a Switch. How did you define your item?

[chris (Chris Jackson)]

Ok - our mails crossed, but that answers my question

I’ll update this to Switch…

[shorty707]

@chris

I’ll update this to Switch…

is this something that is done in the DB? if yes if you tell me how I can help a little more in future

if that is done in the binding and how channel definition works there … never mind

[chris (Chris Jackson)]

@shorty707

is this something that is done in the DB?

No - it’s directly in the binding - there’s an XML file that defines it, and then some code that implements it…

It might be worth a quick look through the channels list page on the database website though to see if you (or anyone else) disagree with anything…