Testing Z-Wave binding on openHAB-2

Yes, it is the database, but you suggested that I might be seeing an issue that someone else also had seen, where known devices where not recognized properly. I emailed you a log some days back.
I have tried to create this node manually now, to see if it works. Automatically it will not work. I guess I will know tomorrow.

I don’t expect you can create this manually since it won’t have the information it needs (eg the node number).

You’re right, I totally missed it. I even looked directly at the entry above it, as I have a slightly different model yale lock to try integrating soon.

In terms of usability, would it be possible to present just the serial controller first, since it has to be configured before any other device?

I found this tricky as well when getting mine setup. There’s a big list of items and it’s hard to find the one item, which is pretty much a required item. What would be even more useful is if that “thing” was automatically “discovered”.

I’m using Aeon MultiSensor 6 in the US so they report scale=1 with temperature in Fahrenheit. However, OpenHAB2 keeps converting back to Celcius (as mentioned in the logs). I have tried configuring the channel multiple times; select Fahrenheit click save which results in a log message stating the Thing has been updated (Thing ‘zwave:aeon_zw100_00_000:c6398348:node7’ has been updated.) but temperature continues to be updated in Celcius…

2016-03-10 19:11:19.962 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 7: Application Command Request (ALIVE:DONE)
2016-03-10 19:11:19.962 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 7: Incoming command class SENSOR_MULTILEVEL
2016-03-10 19:11:19.962 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 7: Received Sensor Multi Level Request
2016-03-10 19:11:19.962 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 7: Sensor Multi Level REPORT received
2016-03-10 19:11:19.962 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 7: Sensor Type = Temperature(1), Scale = 1
2016-03-10 19:11:19.963 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 7: Sensor Value = 73
2016-03-10 19:11:19.963 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2016-03-10 19:11:19.963 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_MULTILEVEL, value = 73
2016-03-10 19:11:19.963 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 7: Sensor is reporting scale 1, requiring conversion to 0. Value is now 73.
2016-03-10 19:11:19.963 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 7: Sensor is reporting scale 1, requiring conversion to 0. Value is now 73.

When I try to add a Battery Level Channel to a thing, I get the following error when trying to save: Error saving item Battery Level HTTP 404 Not Found.

Shortly all devices other than the controller will be removed from the list, so that should make it easier :wink:

1 Like

That’s not really possible unfortunately since it would require scanning serial ports and writing stuff to ports to see if it gets a response. In the meantime, depending on what’s connected, it might screw up another device connected to a COM port by writing some data that this device objects to!

This is a known issue as it’s currently not possible to set the channel properties. The binding supports the conversion, but until this is fixed, there’s not much I can do - sorry.

This is a bug in HABmin. Type removing the ‘-’ from battery-level and it should work. I’ll add some code to remove this automatically…

Good point. I’d forgotten about setting the serial port. As you noted though, when you remove the other items I think the issue will be pretty mell mitigated.

@chris … hope this is something you find essential?

Nodon return values

Button 1 (Filled Circle)
Single Click = 10
Double Click = 13
Long Click = 11

Button 2 (Plus)
Single Click = 20
Double Click = 23
Long Click = 21

Button 3 (Emtpy Circle)
Single Click = 30
Double Click = 33
Long Click = 31

Button 4 (Minus)
Single Click = 40
Double Click = 43
Long Click = 41

Example Log for Button1 Single Click = Scene activation node from node 13: Scene 10, Time 0

19:51:13.459 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0A 00 04 00 0D 04 2B 01 0A 00 D8 
19:51:13.462 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
19:51:13.464 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 04 00 0D 04 2B 01 0A 00 D8 
19:51:13.465 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 0A 00 04 00 0D 04 2B 01 0A 00 D8 
19:51:13.466 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, payload=00 0D 04 2B 01 0A 00 
19:51:13.467 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 13: Application Command Request (ALIVE:DONE)
19:51:13.467 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 13: Incoming command class SCENE_ACTIVATION
19:51:13.468 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - Received Scene Activation for Node ID = 13
19:51:13.470 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - Scene Activation Set
19:51:13.471 [DEBUG] [.commandclass.ZWaveBasicCommandClass] - Scene activation node from node 13: Scene 10, Time 0
19:51:13.481 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
19:51:13.482 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Sent message Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=13, payload=0D 02 84 08 
19:51:13.483 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Recv message Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, payload=00 0D 04 2B 01 0A 00 
19:51:13.484 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, expected=SendData, cancelled=false
19:51:13.781 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 0D 02 84 07 7F 
19:51:13.784 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
19:51:13.785 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 04 00 0D 02 84 07 7F 
19:51:13.786 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 08 00 04 00 0D 02 84 07 7F 
19:51:13.787 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, payload=00 0D 02 84 07 
19:51:13.788 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 13: Application Command Request (ALIVE:DONE)
19:51:13.788 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 13: Incoming command class WAKE_UP
19:51:13.789 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 13: Received Wake Up Request
19:51:13.789 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 13: Received WAKE_UP_NOTIFICATION
19:51:13.789 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 13: Is awake with 0 messages in the wake-up queue.
19:51:13.790 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveWakeUpEvent
19:51:13.791 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Sent message Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=13, payload=0D 02 84 08 
19:51:13.792 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Recv message Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, payload=00 0D 02 84 07 
19:51:13.792 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, expected=SendData, cancelled=true
19:51:14.790 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 13: No more messages, go back to sleep
19:51:14.791 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 13: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
19:51:14.792 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue=[Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=13, payload=0D 02 84 08 ]
19:51:14.792 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
19:51:14.793 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 0D 02 84 08 25 60 23 
19:51:14.795 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 13: Sending REQUEST Message = 01 09 00 13 0D 02 84 08 25 60 23 
19:51:14.811 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
19:51:14.814 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
19:51:14.817 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8 
19:51:14.820 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8 
19:51:14.821 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 60 00 00 02 89 
19:51:14.823 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, payload=01 
19:51:14.825 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 13: Sent Data successfully placed on stack.
19:51:14.827 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
19:51:14.828 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 60 00 00 02 00 00 87 
19:51:14.830 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 60 00 00 02 00 00 87 
19:51:14.831 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, payload=60 00 00 02 
19:51:14.833 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 13: SendData Request. CallBack ID = 96, Status = Transmission complete and ACK received(0)
19:51:14.834 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Sent message Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=13, payload=0D 02 84 08 
19:51:14.836 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Recv message Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, payload=60 00 00 02 
19:51:14.837 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, expected=SendData, cancelled=false
19:51:14.838 [DEBUG] [.serialmessage.ZWaveCommandProcessor] -          transaction complete!
19:51:14.839 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
19:51:14.840 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 13: Went to sleep
19:51:14.841 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 13: Is sleeping
19:51:14.842 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 13: Response processed after 46ms/4892ms.

Does this mean that your item is being set to these values? Or not?

"
well if understand correct what you mean and check via items command on oh2 shell

zwave_nodon_crc3100_00_000_15348538564_node13 (Type=GroupItem, Members=2, State=NULL, Label=Node 13:     CRC-3100 Octon Remote Control, Category=null, Tags=[thing])
    zwave_nodon_crc3100_00_000_15348538564_node13_battery_level (Type=NumberItem, State=NULL, Label=Battery Level, Category=Battery, Groups=[zwave_nodon_crc3100_00_000_15348538564_node13])
    zwave_nodon_crc3100_00_000_15348538564_node13_scene_number (Type=NumberItem, State=NULL, Label=Scene Number, Category=, Groups=[zwave_nodon_crc3100_00_000_15348538564_node13])

i would say no … as state is always NULL

if you meant something else … let me know

Ok - thanks - that’s what I meant… I’ll take a look when I get a chance…

Hi @chris,

the binary sensor of my Fibaro works the whole day with the actual configuration, but now it stops working and i have the following entry in the log:

22:09:34.992 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: No converter set for zwave:fibaro_fgms001_00_000:f1ab5187:node10:sensor_binary

I’ll tried to delete the channel via HABmin and add it new, but it don’t fix the problem.

Do you have an idea how to fix ist?

Maybe i should think about why the first letter of the messages in the log is lost, but i see in the other logs people have the same problem:wink: @Kai - what is the best way to report this, forum or Issue at Github and which repository?

Regards
Heiko

What is “this” exactly?

Maybe i realized it for the 1st time after using OH for 3 years that the log is truncated :wink:

 [ding.zwave.handler.ZWaveThingHandler]
 [marthome.event.ItemStateChangedEvent]
 [ome.event.GroupItemStateChangedEvent]

After getting this setup correctly yesterday, I have a new problem: after restarting openhab this morning, my one z-wave device, which is configured and partially working, is showing up in my inbox again as an unknown device. That is, it’s still in Things as zwave:aeon_dsc06_00_000:e2e1b51e:node5, but it’s also in inbox as wave:unknown:e2e1b51e:node5 That’s in PaperUI. In HABmin, it’s not showing up under things, and the corresponding items are not showing up under items

It partially works - I can turn it on and off via a switch item, and a rule I have to turn it back off ten minutes after being turned on works, but the power meter I have tied to a number item is showing n/a, and a cron-based rule to turn it on at various times is not firing.

looking at the log, it looks like the binding tried to talk to the devices before opening the serial port, and got confused maybe?

2016-03-11 17:50:06.035 [INFO ] [ap.impl.jmdns.JmdnsHomekitAdvertiser] - Stopping advertising in response to shutdown.
2016-03-11 17:51:47.890 [ERROR] [org.eclipse.smarthome.core.transform] - [org.eclipse.smarthome.action.transformation.action(56)] Circular reference detected, getService returning null
2016-03-11 17:52:44.360 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'zwave:aeon_dsc06_00_000:e2e1b51e:node5' has been added.
2016-03-11 17:52:44.449 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'zwave:serial_zstick:e2e1b51e' has been added.
2016-03-11 17:52:44.860 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'CatFeeder5-zwave:aeon_dsc06_00_000:e2e1b51e:node5:switch_binary' has been added.
2016-03-11 17:52:44.898 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'CatFeeder5_Power-zwave:aeon_dsc06_00_000:e2e1b51e:node5:meter_watts' has been added.
2016-03-11 17:52:45.134 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'zwave_aeon_dsc06_00_000_e2e1b51e_node5-zwave:aeon_dsc06_00_000:e2e1b51e:node5' has been added.
2016-03-11 17:52:45.163 [INFO ] [rthome.event.ItemThingLinkAddedEvent] - Link 'zwave_serial_zstick_e2e1b51e-zwave:serial_zstick:e2e1b51e' has been added.
2016-03-11 17:52:45.806 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'home_group_1d2ba494' has been added.
2016-03-11 17:52:45.853 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'zwave_aeon_dsc06_00_000_e2e1b51e_node5' has been added.
2016-03-11 17:52:45.865 [INFO ] [smarthome.event.ItemAddedEvent      ] - Item 'zwave_serial_zstick_e2e1b51e' has been added.
2016-03-11 17:53:17.585 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:aeon_dsc06_00_000:e2e1b51e:node5' changed from UNINITIALIZED to INITIALIZING
2016-03-11 17:53:17.976 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:e2e1b51e' changed from UNINITIALIZED to INITIALIZING
2016-03-11 17:53:18.067 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:e2e1b51e' changed from INITIALIZING to ONLINE
2016-03-11 17:53:18.166 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:aeon_dsc06_00_000:e2e1b51e:node5' changed from INITIALIZING to OFFLINE
2016-03-11 17:53:18.311 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Controller failed to register event handler.
2016-03-11 17:53:18.314 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'
2016-03-11 17:53:18.313 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Controller failed to register event handler.
2016-03-11 17:53:18.682 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Controller failed to register event handler.
2016-03-11 17:53:21.048 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2016-03-11 17:53:21.857 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2016-03-11 17:53:21.901 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2016-03-11 17:53:32.340 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 1: Node found
2016-03-11 17:53:32.381 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 5: Node found
2016-03-11 17:53:32.419 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API
2016-03-11 17:53:32.448 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
2016-03-11 17:53:32.501 [INFO ] [age.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------
2016-03-11 17:53:32.524 [INFO ] [age.SerialApiGetInitDataMessageClass] - # Nodes = 2
2016-03-11 17:53:32.559 [INFO ] [age.SerialApiGetInitDataMessageClass] - ----------------------------------------------------------------------------
2016-03-11 17:53:44.332 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device could not be resolved to a thingType! 0086:0003:0006::1.43
2016-03-11 17:53:45.828 [WARN ] [zwave.handler.ZWaveControllerHandler] - 
2016-03-11 17:53:46.714 [INFO ] [smarthome.event.InboxUpdatedEvent   ] - Discovery Result with UID 'zwave:unknown:e2e1b51e:node5' has been updated.
2016-03-11 17:53:46.853 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:aeon_dsc06_00_000:e2e1b51e:node5' changed from OFFLINE to ONLINE: PROTOINFO
2016-03-11 17:53:48.078 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:aeon_dsc06_00_000:e2e1b51e:node5' changed from ONLINE: PROTOINFO to ONLINE: NEIGHBORS
2016-03-11 17:53:49.073 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:aeon_dsc06_00_000:e2e1b51e:node5' changed from ONLINE: NEIGHBORS to ONLINE: FAILED_CHECK
2016-03-11 17:53:51.873 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:aeon_dsc06_00_000:e2e1b51e:node5' changed from ONLINE: FAILED_CHECK to ONLINE: WAIT
2016-03-11 17:53:51.983 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:aeon_dsc06_00_000:e2e1b51e:node5' changed from ONLINE: WAIT to ONLINE: PING
2016-03-11 17:53:52.703 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:aeon_dsc06_00_000:e2e1b51e:node5' changed from ONLINE: PING to ONLINE
2016-03-11 17:53:57.309 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 5: Timeout while sending message. Requeueing - 0 attempts left!
2016-03-11 17:53:57.323 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 5: Got an error while sending data. Resending message.
2016-03-11 17:53:57.643 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:aeon_dsc06_00_000:e2e1b51e:node5' changed from ONLINE to ONLINE: DETAILS
2016-03-11 17:53:57.729 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:aeon_dsc06_00_000:e2e1b51e:node5' changed from ONLINE: DETAILS to ONLINE: DYNAMIC_VALUES
2016-03-11 17:54:01.282 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:aeon_dsc06_00_000:e2e1b51e:node5' changed from ONLINE: DYNAMIC_VALUES to ONLINE

It’s hard to say what’s up. It looks like you created two things for the same node though?

Anyway, the log doesn’t really help as it has no debug information…