[SOLVED] Aeon Labs Minimote help

DMize · January 4, 2016, 1:43am

I’ve had a functioning openhab installation for a little over 6 months and I’m loving it.

I’m starting to try to add some zwave items and wanted to start small so I have the Aeotec Z-Stick Gen 5 and the Aeotec Minimote v1 (DSA03202). The system found the z-stick and from there I have added the Minimote. It picks it up correctly as far as I can tell and when I push a button it shows in the zwave log (below). It also shows in the events.log that the button state was updated to ON. I also used OZWCP to do this with similar results. I’ve googled and tried so many things but I can’t figure out what is wrong.

The problem(s) are that the rules don’t trigger when the button is updated to ON. Investigating that I noticed that the node2.xml was never created for the minimote.

Does anyone have any suggestions to try or insight as to why this isn’t working? I’d like to add other zwave items (thermostat, door sensor, leak sensor…) but I have to have this proof of concept work first.

2016-01-03 19:52:47.079 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1595]- Watchdog: Checking Serial threads
2016-01-03 19:52:57.079 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1595]- Watchdog: Checking Serial threads
2016-01-03 19:53:07.079 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1595]- Watchdog: Checking Serial threads
2016-01-03 19:53:13.592 DEBUG o.o.b.z.i.ZWaveNetworkMonitor[:353]- Network Monitor: No nodes to ping!
2016-01-03 19:53:17.081 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1595]- Watchdog: Checking Serial threads
2016-01-03 19:53:27.082 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1595]- Watchdog: Checking Serial threads
2016-01-03 19:53:37.084 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1595]- Watchdog: Checking Serial threads
2016-01-03 19:53:47.084 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1595]- Watchdog: Checking Serial threads
2016-01-03 19:53:57.085 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1595]- Watchdog: Checking Serial threads
2016-01-03 19:54:07.086 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1595]- Watchdog: Checking Serial threads
2016-01-03 19:54:17.086 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1595]- Watchdog: Checking Serial threads
2016-01-03 19:54:18.569 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1528]- Receive Message = 01 0A 00 04 00 02 04 2B 01 01 00 DC 
2016-01-03 19:54:18.571 TRACE o.o.b.z.i.p.SerialMessage[:136]- NODE 255: Creating new SerialMessage from buffer = 01 0A 00 04 00 02 04 2B 01 01 00 DC 
2016-01-03 19:54:18.572 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0xDC
2016-01-03 19:54:18.573 TRACE o.o.b.z.i.p.SerialMessage[:141]- NODE 255: Checksum matched
2016-01-03 19:54:18.573 TRACE o.o.b.z.i.p.SerialMessage[:153]- NODE 255: Message payload = 00 02 04 2B 01 01 00 
2016-01-03 19:54:18.574 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1437]- Message is valid, sending ACK
2016-01-03 19:54:18.575 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1422]- Response SENT
2016-01-03 19:54:18.576 DEBUG o.o.b.z.i.p.ZWaveController[:1210]- Receive queue TAKE: Length=0
2016-01-03 19:54:18.576 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0xDC
2016-01-03 19:54:18.576 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1452]- Receive queue ADD: Length=0
2016-01-03 19:54:18.615 DEBUG o.o.b.z.i.p.SerialMessage[:233]- Assembled message buffer = 01 0A 00 04 00 02 04 2B 01 01 00 DC 
2016-01-03 19:54:18.621 DEBUG o.o.b.z.i.p.ZWaveController[:1211]- Process Message = 01 0A 00 04 00 02 04 2B 01 01 00 DC 
2016-01-03 19:54:18.621 DEBUG o.o.b.z.i.p.ZWaveController[:190]- Message: class = ApplicationCommandHandler (0x04), type = Request (0x00), payload = 00 02 04 2B 01 01 00 
2016-01-03 19:54:18.622 TRACE o.o.b.z.i.p.ZWaveController[:210]- Incoming Message type = REQUEST
2016-01-03 19:54:18.623 TRACE o.o.b.z.i.p.s.ApplicationCommandMessageClass[:30]- Handle Message Application Command Request
2016-01-03 19:54:18.624 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:38]- NODE 2: Application Command Request (ALIVE:STATIC_VALUES)
2016-01-03 19:54:18.624 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:56]- NODE 2: Incoming command class SCENE_ACTIVATION
2016-01-03 19:54:18.625 TRACE o.o.b.z.i.p.s.ApplicationCommandMessageClass[:79]- NODE 2: Found Command Class SCENE_ACTIVATION, passing to handleApplicationCommandRequest
2016-01-03 19:54:18.625 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:62]- Received Scene Activation for Node ID = 2
2016-01-03 19:54:18.626 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:66]- Scene Activation Set
2016-01-03 19:54:18.626 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:93]- Scene activation node from node 2: Scene 1, Time 0
2016-01-03 19:54:18.627 DEBUG o.o.b.z.i.p.ZWaveController[:682]- Notifying event listeners: ZWaveCommandClassValueEvent
2016-01-03 19:54:18.628 DEBUG o.o.b.z.i.ZWaveActiveBinding[:433]- ZwaveIncomingEvent
2016-01-03 19:54:18.629 DEBUG o.o.b.z.i.ZWaveActiveBinding[:450]- NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SCENE_ACTIVATION, value = 1
2016-01-03 19:54:18.632 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b2m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:18.633 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b1m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:18.635 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b3h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:18.638 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b4h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:18.640 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b3m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:18.640 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b2h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:18.640 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b4m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:18.645 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b1h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:18.647 TRACE o.o.b.z.i.p.s.ZWaveCommandProcessor[:59]- Message has Ack Pending
2016-01-03 19:54:20.145 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1528]- Receive Message = 01 0A 00 04 00 02 04 2B 01 03 00 DE 
2016-01-03 19:54:20.146 TRACE o.o.b.z.i.p.SerialMessage[:136]- NODE 255: Creating new SerialMessage from buffer = 01 0A 00 04 00 02 04 2B 01 03 00 DE 
2016-01-03 19:54:20.147 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0xDE
2016-01-03 19:54:20.147 TRACE o.o.b.z.i.p.SerialMessage[:141]- NODE 255: Checksum matched
2016-01-03 19:54:20.147 TRACE o.o.b.z.i.p.SerialMessage[:153]- NODE 255: Message payload = 00 02 04 2B 01 03 00 
2016-01-03 19:54:20.147 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1437]- Message is valid, sending ACK
2016-01-03 19:54:20.148 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1422]- Response SENT
2016-01-03 19:54:20.148 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1452]- Receive queue ADD: Length=1
2016-01-03 19:54:20.148 DEBUG o.o.b.z.i.p.ZWaveController[:1210]- Receive queue TAKE: Length=0
2016-01-03 19:54:20.148 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0xDE
2016-01-03 19:54:20.149 DEBUG o.o.b.z.i.p.SerialMessage[:233]- Assembled message buffer = 01 0A 00 04 00 02 04 2B 01 03 00 DE 
2016-01-03 19:54:20.149 DEBUG o.o.b.z.i.p.ZWaveController[:1211]- Process Message = 01 0A 00 04 00 02 04 2B 01 03 00 DE 
2016-01-03 19:54:20.149 DEBUG o.o.b.z.i.p.ZWaveController[:190]- Message: class = ApplicationCommandHandler (0x04), type = Request (0x00), payload = 00 02 04 2B 01 03 00 
2016-01-03 19:54:20.149 TRACE o.o.b.z.i.p.ZWaveController[:210]- Incoming Message type = REQUEST
2016-01-03 19:54:20.149 TRACE o.o.b.z.i.p.s.ApplicationCommandMessageClass[:30]- Handle Message Application Command Request
2016-01-03 19:54:20.149 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:38]- NODE 2: Application Command Request (ALIVE:STATIC_VALUES)
2016-01-03 19:54:20.150 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:56]- NODE 2: Incoming command class SCENE_ACTIVATION
2016-01-03 19:54:20.150 TRACE o.o.b.z.i.p.s.ApplicationCommandMessageClass[:79]- NODE 2: Found Command Class SCENE_ACTIVATION, passing to handleApplicationCommandRequest
2016-01-03 19:54:20.150 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:62]- Received Scene Activation for Node ID = 2
2016-01-03 19:54:20.150 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:66]- Scene Activation Set
2016-01-03 19:54:20.150 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:93]- Scene activation node from node 2: Scene 3, Time 0
2016-01-03 19:54:20.150 DEBUG o.o.b.z.i.p.ZWaveController[:682]- Notifying event listeners: ZWaveCommandClassValueEvent
2016-01-03 19:54:20.151 DEBUG o.o.b.z.i.ZWaveActiveBinding[:433]- ZwaveIncomingEvent
2016-01-03 19:54:20.151 DEBUG o.o.b.z.i.ZWaveActiveBinding[:450]- NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SCENE_ACTIVATION, value = 3
2016-01-03 19:54:20.152 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b2m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:20.152 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b1m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:20.153 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b3h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:20.153 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b4h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:20.153 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b3m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:20.153 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b2h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:20.153 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b4m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:20.153 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b1h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:20.153 TRACE o.o.b.z.i.p.s.ZWaveCommandProcessor[:59]- Message has Ack Pending
2016-01-03 19:54:21.321 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1528]- Receive Message = 01 0A 00 04 00 02 04 2B 01 05 00 D8 
2016-01-03 19:54:21.324 TRACE o.o.b.z.i.p.SerialMessage[:136]- NODE 255: Creating new SerialMessage from buffer = 01 0A 00 04 00 02 04 2B 01 05 00 D8 
2016-01-03 19:54:21.326 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0xD8
2016-01-03 19:54:21.326 TRACE o.o.b.z.i.p.SerialMessage[:141]- NODE 255: Checksum matched
2016-01-03 19:54:21.328 TRACE o.o.b.z.i.p.SerialMessage[:153]- NODE 255: Message payload = 00 02 04 2B 01 05 00 
2016-01-03 19:54:21.329 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1437]- Message is valid, sending ACK
2016-01-03 19:54:21.330 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1422]- Response SENT
2016-01-03 19:54:21.331 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1452]- Receive queue ADD: Length=1
2016-01-03 19:54:21.331 DEBUG o.o.b.z.i.p.ZWaveController[:1210]- Receive queue TAKE: Length=0
2016-01-03 19:54:21.332 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0xD8
2016-01-03 19:54:21.333 DEBUG o.o.b.z.i.p.SerialMessage[:233]- Assembled message buffer = 01 0A 00 04 00 02 04 2B 01 05 00 D8 
2016-01-03 19:54:21.333 DEBUG o.o.b.z.i.p.ZWaveController[:1211]- Process Message = 01 0A 00 04 00 02 04 2B 01 05 00 D8 
2016-01-03 19:54:21.333 DEBUG o.o.b.z.i.p.ZWaveController[:190]- Message: class = ApplicationCommandHandler (0x04), type = Request (0x00), payload = 00 02 04 2B 01 05 00 
2016-01-03 19:54:21.333 TRACE o.o.b.z.i.p.ZWaveController[:210]- Incoming Message type = REQUEST
2016-01-03 19:54:21.333 TRACE o.o.b.z.i.p.s.ApplicationCommandMessageClass[:30]- Handle Message Application Command Request
2016-01-03 19:54:21.333 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:38]- NODE 2: Application Command Request (ALIVE:STATIC_VALUES)
2016-01-03 19:54:21.334 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:56]- NODE 2: Incoming command class SCENE_ACTIVATION
2016-01-03 19:54:21.334 TRACE o.o.b.z.i.p.s.ApplicationCommandMessageClass[:79]- NODE 2: Found Command Class SCENE_ACTIVATION, passing to handleApplicationCommandRequest
2016-01-03 19:54:21.334 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:62]- Received Scene Activation for Node ID = 2
2016-01-03 19:54:21.334 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:66]- Scene Activation Set
2016-01-03 19:54:21.334 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:93]- Scene activation node from node 2: Scene 5, Time 0
2016-01-03 19:54:21.334 DEBUG o.o.b.z.i.p.ZWaveController[:682]- Notifying event listeners: ZWaveCommandClassValueEvent
2016-01-03 19:54:21.334 DEBUG o.o.b.z.i.ZWaveActiveBinding[:433]- ZwaveIncomingEvent
2016-01-03 19:54:21.335 DEBUG o.o.b.z.i.ZWaveActiveBinding[:450]- NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SCENE_ACTIVATION, value = 5
2016-01-03 19:54:21.335 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b2m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:21.335 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b1m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:21.335 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b3h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:21.335 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b4h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:21.335 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b3m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:21.336 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b2h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:21.336 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b4m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:21.336 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:340]- Getting converter for item = Rem_A_b1h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-03 19:54:21.336 TRACE o.o.b.z.i.p.s.ZWaveCommandProcessor[:59]- Message has Ack Pending

This log is of me pressing each button [1-4] momentarily and pressing each button and holding. The only issue? I see is that it says ‘Message has Ack Pending’ but I never see where it says received/sent (and I’m not sure it should).

Thanks for any help and suggestions.

DMize · January 6, 2016, 2:29am

So I updated to the latest binding from cloud bees yesterday and updated the minimote firmware and it still doesn’t work but now I’m getting a lot of these messages in the log…

2016-01-05 21:27:42.555 TRACE o.o.b.z.i.protocol.ZWaveNode[:457]- NODE 3: App version requested but version is unknown

I’m about out of patience with this. It’s really frustrating to see other users that have this minimote working and I’ve spent so much time getting something so seemingly simple setup.

Any thoughts?

DMize · January 6, 2016, 2:34am

Does anyone see anything wrong with this?

DMize · January 15, 2016, 4:26am

Quick update: I put in a ticket with aeotec and they think the controller is bad so I’m sending it back to get another one. I’ll post what I find when I get the new one.

DMize · January 23, 2016, 6:20pm

Update: Still need help!

Got my new minimote. Openhab can see it and it shows that I’ve pushed a button in the zwave log but the rule doesn’t fire.
There is no node2.xml created and it looks like the initialization of the node is never finished.
I’ve “force” woken the device a few times now and nothing changes.

I really need some guidance as to what I should try next. ZWAVE may be the death of me…

Here is a log file where a pushed two buttons and then did a force wake on the device.

2016-01-23 13:08:12.053 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1548]- Watchdog: Checking Serial threads
2016-01-23 13:08:22.053 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1548]- Watchdog: Checking Serial threads
2016-01-23 13:08:32.058 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1548]- Watchdog: Checking Serial threads
2016-01-23 13:08:42.059 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1548]- Watchdog: Checking Serial threads
2016-01-23 13:08:52.060 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1548]- Watchdog: Checking Serial threads
2016-01-23 13:09:02.059 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1548]- Watchdog: Checking Serial threads
2016-01-23 13:09:12.060 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1548]- Watchdog: Checking Serial threads
2016-01-23 13:09:22.060 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1548]- Watchdog: Checking Serial threads
2016-01-23 13:09:26.824 DEBUG o.o.b.z.i.ZWaveNetworkMonitor[:353]- Network Monitor: No nodes to ping!
2016-01-23 13:09:32.060 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1548]- Watchdog: Checking Serial threads
2016-01-23 13:09:42.060 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1548]- Watchdog: Checking Serial threads
2016-01-23 13:09:43.071 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1481]- Receive Message = 01 0A 00 04 00 02 04 2B 01 01 00 DC 
2016-01-23 13:09:43.074 TRACE o.o.b.z.i.p.SerialMessage[:136]- NODE 255: Creating new SerialMessage from buffer = 01 0A 00 04 00 02 04 2B 01 01 00 DC 
2016-01-23 13:09:43.075 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0xDC
2016-01-23 13:09:43.076 TRACE o.o.b.z.i.p.SerialMessage[:141]- NODE 255: Checksum matched
2016-01-23 13:09:43.076 TRACE o.o.b.z.i.p.SerialMessage[:153]- NODE 255: Message payload = 00 02 04 2B 01 01 00 
2016-01-23 13:09:43.076 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1390]- Message is valid, sending ACK
2016-01-23 13:09:43.079 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1375]- Response SENT
2016-01-23 13:09:43.080 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1405]- Receive queue ADD: Length=1
2016-01-23 13:09:43.080 DEBUG o.o.b.z.i.p.ZWaveController[:1163]- Receive queue TAKE: Length=0
2016-01-23 13:09:43.081 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0xDC
2016-01-23 13:09:43.084 DEBUG o.o.b.z.i.p.SerialMessage[:233]- Assembled message buffer = 01 0A 00 04 00 02 04 2B 01 01 00 DC 
2016-01-23 13:09:43.087 DEBUG o.o.b.z.i.p.ZWaveController[:1164]- Process Message = 01 0A 00 04 00 02 04 2B 01 01 00 DC 
2016-01-23 13:09:43.089 DEBUG o.o.b.z.i.p.ZWaveController[:192]- Message: class = ApplicationCommandHandler (0x04), type = Request (0x00), payload = 00 02 04 2B 01 01 00 
2016-01-23 13:09:43.090 TRACE o.o.b.z.i.p.ZWaveController[:212]- Incoming Message type = REQUEST
2016-01-23 13:09:43.091 TRACE o.o.b.z.i.p.s.ApplicationCommandMessageClass[:30]- Handle Message Application Command Request
2016-01-23 13:09:43.092 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:38]- NODE 2: Application Command Request (ALIVE:STATIC_VALUES)
2016-01-23 13:09:43.093 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:56]- NODE 2: Incoming command class SCENE_ACTIVATION
2016-01-23 13:09:43.094 TRACE o.o.b.z.i.p.s.ApplicationCommandMessageClass[:79]- NODE 2: Found Command Class SCENE_ACTIVATION, passing to handleApplicationCommandRequest
2016-01-23 13:09:43.095 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:62]- Received Scene Activation for Node ID = 2
2016-01-23 13:09:43.096 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:66]- Scene Activation Set
2016-01-23 13:09:43.097 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:93]- Scene activation node from node 2: Scene 1, Time 0
2016-01-23 13:09:43.097 DEBUG o.o.b.z.i.p.ZWaveController[:635]- Notifying event listeners: ZWaveCommandClassValueEvent
2016-01-23 13:09:43.098 DEBUG o.o.b.z.i.ZWaveActiveBinding[:433]- ZwaveIncomingEvent
2016-01-23 13:09:43.100 DEBUG o.o.b.z.i.ZWaveActiveBinding[:450]- NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SCENE_ACTIVATION, value = 1
2016-01-23 13:09:43.100 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b1h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:43.100 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b3h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:43.100 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b2h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:43.101 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b4h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:43.101 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b2m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:43.101 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b1m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:43.101 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b4m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:43.102 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b3m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:43.102 TRACE o.o.b.z.i.p.s.ZWaveCommandProcessor[:59]- Message has Ack Pending
2016-01-23 13:09:45.635 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1481]- Receive Message = 01 0A 00 04 00 02 04 2B 01 02 00 DF 
2016-01-23 13:09:45.638 TRACE o.o.b.z.i.p.SerialMessage[:136]- NODE 255: Creating new SerialMessage from buffer = 01 0A 00 04 00 02 04 2B 01 02 00 DF 
2016-01-23 13:09:45.640 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0xDF
2016-01-23 13:09:45.641 TRACE o.o.b.z.i.p.SerialMessage[:141]- NODE 255: Checksum matched
2016-01-23 13:09:45.642 TRACE o.o.b.z.i.p.SerialMessage[:153]- NODE 255: Message payload = 00 02 04 2B 01 02 00 
2016-01-23 13:09:45.643 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1390]- Message is valid, sending ACK
2016-01-23 13:09:45.645 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1375]- Response SENT
2016-01-23 13:09:45.645 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1405]- Receive queue ADD: Length=1
2016-01-23 13:09:45.645 DEBUG o.o.b.z.i.p.ZWaveController[:1163]- Receive queue TAKE: Length=0
2016-01-23 13:09:45.646 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0xDF
2016-01-23 13:09:45.647 DEBUG o.o.b.z.i.p.SerialMessage[:233]- Assembled message buffer = 01 0A 00 04 00 02 04 2B 01 02 00 DF 
2016-01-23 13:09:45.647 DEBUG o.o.b.z.i.p.ZWaveController[:1164]- Process Message = 01 0A 00 04 00 02 04 2B 01 02 00 DF 
2016-01-23 13:09:45.650 DEBUG o.o.b.z.i.p.ZWaveController[:192]- Message: class = ApplicationCommandHandler (0x04), type = Request (0x00), payload = 00 02 04 2B 01 02 00 
2016-01-23 13:09:45.651 TRACE o.o.b.z.i.p.ZWaveController[:212]- Incoming Message type = REQUEST
2016-01-23 13:09:45.652 TRACE o.o.b.z.i.p.s.ApplicationCommandMessageClass[:30]- Handle Message Application Command Request
2016-01-23 13:09:45.653 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:38]- NODE 2: Application Command Request (ALIVE:STATIC_VALUES)
2016-01-23 13:09:45.655 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:56]- NODE 2: Incoming command class SCENE_ACTIVATION
2016-01-23 13:09:45.655 TRACE o.o.b.z.i.p.s.ApplicationCommandMessageClass[:79]- NODE 2: Found Command Class SCENE_ACTIVATION, passing to handleApplicationCommandRequest
2016-01-23 13:09:45.656 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:62]- Received Scene Activation for Node ID = 2
2016-01-23 13:09:45.656 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:66]- Scene Activation Set
2016-01-23 13:09:45.656 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:93]- Scene activation node from node 2: Scene 2, Time 0
2016-01-23 13:09:45.656 DEBUG o.o.b.z.i.p.ZWaveController[:635]- Notifying event listeners: ZWaveCommandClassValueEvent
2016-01-23 13:09:45.656 DEBUG o.o.b.z.i.ZWaveActiveBinding[:433]- ZwaveIncomingEvent
2016-01-23 13:09:45.656 DEBUG o.o.b.z.i.ZWaveActiveBinding[:450]- NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SCENE_ACTIVATION, value = 2
2016-01-23 13:09:45.656 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b1h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:45.657 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b3h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:45.657 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b2h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:45.657 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b4h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:45.658 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b2m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:45.658 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b1m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:45.658 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b4m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:45.658 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b3m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-23 13:09:45.658 TRACE o.o.b.z.i.p.s.ZWaveCommandProcessor[:59]- Message has Ack Pending
2016-01-23 13:09:50.479 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1481]- Receive Message = 01 11 00 49 84 02 0B 01 01 01 86 72 70 9B EF 85 2B 26 53 
2016-01-23 13:09:50.483 TRACE o.o.b.z.i.p.SerialMessage[:136]- NODE 255: Creating new SerialMessage from buffer = 01 11 00 49 84 02 0B 01 01 01 86 72 70 9B EF 85 2B 26 53 
2016-01-23 13:09:50.484 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0x53
2016-01-23 13:09:50.485 TRACE o.o.b.z.i.p.SerialMessage[:141]- NODE 255: Checksum matched
2016-01-23 13:09:50.486 TRACE o.o.b.z.i.p.SerialMessage[:153]- NODE 255: Message payload = 84 02 0B 01 01 01 86 72 70 9B EF 85 2B 26 
2016-01-23 13:09:50.486 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1390]- Message is valid, sending ACK
2016-01-23 13:09:50.489 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1375]- Response SENT
2016-01-23 13:09:50.490 DEBUG o.o.b.z.i.p.ZWaveController[:1163]- Receive queue TAKE: Length=0
2016-01-23 13:09:50.491 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0x53
2016-01-23 13:09:50.491 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1405]- Receive queue ADD: Length=0
2016-01-23 13:09:50.491 DEBUG o.o.b.z.i.p.SerialMessage[:233]- Assembled message buffer = 01 11 00 49 84 02 0B 01 01 01 86 72 70 9B EF 85 2B 26 53 
2016-01-23 13:09:50.492 DEBUG o.o.b.z.i.p.ZWaveController[:1164]- Process Message = 01 11 00 49 84 02 0B 01 01 01 86 72 70 9B EF 85 2B 26 53 
2016-01-23 13:09:50.493 DEBUG o.o.b.z.i.p.ZWaveController[:192]- Message: class = ApplicationUpdate (0x49), type = Request (0x00), payload = 84 02 0B 01 01 01 86 72 70 9B EF 85 2B 26 
2016-01-23 13:09:50.493 TRACE o.o.b.z.i.p.ZWaveController[:212]- Incoming Message type = REQUEST
2016-01-23 13:09:50.493 DEBUG o.o.b.z.i.p.s.ApplicationUpdateMessageClass[:45]- NODE 2: Application update request. Node information received.
2016-01-23 13:09:50.494 TRACE o.o.b.z.i.p.s.ApplicationUpdateMessageClass[:86]- NODE 2: Command class 0x86 is supported.
2016-01-23 13:09:50.494 DEBUG o.o.b.z.i.p.c.ZWaveCommandClass[:224]- NODE 2: Creating new instance of command class VERSION
2016-01-23 13:09:50.494 TRACE o.o.b.z.i.p.c.ZWaveCommandClass[:70]- Command class VERSION created
2016-01-23 13:09:50.494 TRACE o.o.b.z.i.p.s.ApplicationUpdateMessageClass[:86]- NODE 2: Command class 0x72 is supported.
2016-01-23 13:09:50.494 DEBUG o.o.b.z.i.p.c.ZWaveCommandClass[:224]- NODE 2: Creating new instance of command class MANUFACTURER_SPECIFIC
2016-01-23 13:09:50.495 TRACE o.o.b.z.i.p.c.ZWaveCommandClass[:70]- Command class MANUFACTURER_SPECIFIC created
2016-01-23 13:09:50.495 TRACE o.o.b.z.i.p.s.ApplicationUpdateMessageClass[:86]- NODE 2: Command class 0x70 is supported.
2016-01-23 13:09:50.495 DEBUG o.o.b.z.i.p.c.ZWaveCommandClass[:224]- NODE 2: Creating new instance of command class CONFIGURATION
2016-01-23 13:09:50.496 TRACE o.o.b.z.i.p.c.ZWaveCommandClass[:70]- Command class CONFIGURATION created
2016-01-23 13:09:50.496 TRACE o.o.b.z.i.p.s.ApplicationUpdateMessageClass[:86]- NODE 2: Command class 0x9B is supported.
2016-01-23 13:09:50.496 WARN  o.o.b.z.i.p.c.ZWaveCommandClass[:221]- NODE 2: Unsupported command class ASSOCIATION_COMMAND_CONFIGURATION
2016-01-23 13:09:50.496 DEBUG o.o.b.z.i.p.ZWaveController[:635]- Notifying event listeners: ZWaveNodeInfoEvent
2016-01-23 13:09:50.497 DEBUG o.o.b.z.i.ZWaveActiveBinding[:433]- ZwaveIncomingEvent
2016-01-23 13:09:50.498 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:1060]- NODE 2: 2 NIF event during initialisation stage STATIC_VALUES
2016-01-23 13:09:50.498 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:1069]- NODE 2: NIF event during initialisation stage STATIC_VALUES
2016-01-23 13:09:50.498 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:269]- NODE 2: Node advancer - STATIC_VALUES: queue length(0), free to send(true)
2016-01-23 13:09:50.499 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:335]- NODE 2: Node advancer: loop - STATIC_VALUES try 1: stageAdvanced(false)
2016-01-23 13:09:50.499 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:582]- NODE 2: Node advancer: STATIC_VALUES - checking CONFIGURATION
2016-01-23 13:09:50.500 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:582]- NODE 2: Node advancer: STATIC_VALUES - checking SCENE_ACTIVATION
2016-01-23 13:09:50.500 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:582]- NODE 2: Node advancer: STATIC_VALUES - checking VERSION
2016-01-23 13:09:50.500 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:582]- NODE 2: Node advancer: STATIC_VALUES - checking MANUFACTURER_SPECIFIC
2016-01-23 13:09:50.500 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:582]- NODE 2: Node advancer: STATIC_VALUES - checking WAKE_UP
2016-01-23 13:09:50.500 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:585]- NODE 2: Node advancer: STATIC_VALUES - found    WAKE_UP
2016-01-23 13:09:50.500 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:589]- NODE 2: Found 1 instances of WAKE_UP
2016-01-23 13:09:50.501 DEBUG o.o.b.z.i.p.c.ZWaveWakeUpCommandClass[:253]- NODE 2: Creating new message for application command WAKE_UP_INTERVAL_GET
2016-01-23 13:09:50.501 DEBUG o.o.b.z.i.p.SerialMessage[:109]- NODE 2: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-01-23 13:09:50.501 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:582]- NODE 2: Node advancer: STATIC_VALUES - checking NO_OPERATION
2016-01-23 13:09:50.502 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:582]- NODE 2: Node advancer: STATIC_VALUES - checking BASIC
2016-01-23 13:09:50.502 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:617]- NODE 2: Node advancer: STATIC_VALUES - queued 1 frames
2016-01-23 13:09:50.502 DEBUG o.o.b.z.i.p.ZWaveController[:938]- Callback ID = 21
2016-01-23 13:09:50.502 DEBUG o.o.b.z.i.p.c.ZWaveWakeUpCommandClass[:237]- NODE 2: Message already on the wake-up queue. Removing original.
2016-01-23 13:09:50.503 DEBUG o.o.b.z.i.p.c.ZWaveWakeUpCommandClass[:241]- NODE 2: Putting message SendData in wakeup queue.
2016-01-23 13:09:50.503 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:242]- NODE 2: Node advancer - queued packet. Queue length is 1
2016-01-23 13:09:50.503 DEBUG o.o.b.z.i.p.c.ZWaveWakeUpCommandClass[:411]- NODE 2: Is awake with 1 messages in the wake-up queue.
2016-01-23 13:09:50.503 DEBUG o.o.b.z.i.p.ZWaveController[:635]- Notifying event listeners: ZWaveWakeUpEvent
2016-01-23 13:09:50.504 DEBUG o.o.b.z.i.ZWaveActiveBinding[:433]- ZwaveIncomingEvent
2016-01-23 13:09:50.504 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:1036]- NODE 2: Wakeup during initialisation.
2016-01-23 13:09:50.504 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:269]- NODE 2: Node advancer - STATIC_VALUES: queue length(1), free to send(false)
2016-01-23 13:09:50.504 DEBUG o.o.b.z.i.p.ZWaveController[:938]- Callback ID = 22
2016-01-23 13:09:50.505 DEBUG o.o.b.z.i.p.ZWaveController[:620]- Enqueueing message. Queue length = 1
2016-01-23 13:09:50.505 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1211]- Took message from queue for sending. Queue length = 0
2016-01-23 13:09:50.505 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:242]- NODE 2: Node advancer - queued packet. Queue length is 1
2016-01-23 13:09:50.506 DEBUG o.o.b.z.i.p.ZWaveController[:938]- Callback ID = 23
2016-01-23 13:09:50.506 DEBUG o.o.b.z.i.p.ZWaveController[:620]- Enqueueing message. Queue length = 1
2016-01-23 13:09:50.506 TRACE o.o.b.z.i.p.s.ZWaveCommandProcessor[:59]- Message has Ack Pending
2016-01-23 13:09:50.505 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0x57
2016-01-23 13:09:50.508 DEBUG o.o.b.z.i.p.SerialMessage[:233]- Assembled message buffer = 01 09 00 13 02 02 84 05 25 16 57 
2016-01-23 13:09:50.509 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1268]- NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 84 05 25 16 57 
2016-01-23 13:09:50.507 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1481]- Receive Message = 01 08 00 04 04 02 02 84 07 74 
2016-01-23 13:09:50.512 TRACE o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1274]- Message SENT
2016-01-23 13:09:50.513 TRACE o.o.b.z.i.p.SerialMessage[:136]- NODE 255: Creating new SerialMessage from buffer = 01 08 00 04 04 02 02 84 07 74 
2016-01-23 13:09:50.513 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0x74
2016-01-23 13:09:50.514 TRACE o.o.b.z.i.p.SerialMessage[:141]- NODE 255: Checksum matched
2016-01-23 13:09:50.514 TRACE o.o.b.z.i.p.SerialMessage[:153]- NODE 255: Message payload = 04 02 02 84 07 
2016-01-23 13:09:50.514 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1390]- Message is valid, sending ACK
2016-01-23 13:09:50.516 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1375]- Response SENT
2016-01-23 13:09:50.517 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1405]- Receive queue ADD: Length=1
2016-01-23 13:09:50.517 ERROR o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1496]- Protocol error (CAN), resending
2016-01-23 13:09:50.517 DEBUG o.o.b.z.i.p.ZWaveController[:1163]- Receive queue TAKE: Length=0
2016-01-23 13:09:50.518 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0x74
2016-01-23 13:09:50.519 DEBUG o.o.b.z.i.p.SerialMessage[:233]- Assembled message buffer = 01 08 00 04 04 02 02 84 07 74 
2016-01-23 13:09:50.519 DEBUG o.o.b.z.i.p.ZWaveController[:1164]- Process Message = 01 08 00 04 04 02 02 84 07 74 
2016-01-23 13:09:50.520 DEBUG o.o.b.z.i.p.ZWaveController[:192]- Message: class = ApplicationCommandHandler (0x04), type = Request (0x00), payload = 04 02 02 84 07 
2016-01-23 13:09:50.520 TRACE o.o.b.z.i.p.ZWaveController[:212]- Incoming Message type = REQUEST
2016-01-23 13:09:50.520 TRACE o.o.b.z.i.p.s.ApplicationCommandMessageClass[:30]- Handle Message Application Command Request
2016-01-23 13:09:50.520 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:38]- NODE 2: Application Command Request (ALIVE:STATIC_VALUES)
2016-01-23 13:09:50.520 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:56]- NODE 2: Incoming command class WAKE_UP
2016-01-23 13:09:50.521 TRACE o.o.b.z.i.p.s.ApplicationCommandMessageClass[:79]- NODE 2: Found Command Class WAKE_UP, passing to handleApplicationCommandRequest
2016-01-23 13:09:50.521 DEBUG o.o.b.z.i.p.c.ZWaveWakeUpCommandClass[:136]- NODE 2: Received Wake Up Request
2016-01-23 13:09:50.521 DEBUG o.o.b.z.i.p.c.ZWaveWakeUpCommandClass[:182]- NODE 2: Received WAKE_UP_NOTIFICATION
2016-01-23 13:09:50.521 DEBUG o.o.b.z.i.p.c.ZWaveWakeUpCommandClass[:411]- NODE 2: Is awake with 0 messages in the wake-up queue.
2016-01-23 13:09:50.521 DEBUG o.o.b.z.i.p.ZWaveController[:635]- Notifying event listeners: ZWaveWakeUpEvent
2016-01-23 13:09:50.521 DEBUG o.o.b.z.i.ZWaveActiveBinding[:433]- ZwaveIncomingEvent
2016-01-23 13:09:50.522 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:1036]- NODE 2: Wakeup during initialisation.
2016-01-23 13:09:50.522 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:269]- NODE 2: Node advancer - STATIC_VALUES: queue length(1), free to send(false)
2016-01-23 13:09:50.522 DEBUG o.o.b.z.i.p.ZWaveController[:938]- Callback ID = 24
2016-01-23 13:09:50.522 DEBUG o.o.b.z.i.p.ZWaveController[:620]- Enqueueing message. Queue length = 2
2016-01-23 13:09:50.522 DEBUG o.o.b.z.i.p.i.ZWaveNodeStageAdvancer[:242]- NODE 2: Node advancer - queued packet. Queue length is 1
2016-01-23 13:09:50.523 TRACE o.o.b.z.i.p.s.ZWaveCommandProcessor[:59]- Message has Ack Pending
2016-01-23 13:09:50.618 DEBUG o.o.b.z.i.p.ZWaveController[:620]- Enqueueing message. Queue length = 3
2016-01-23 13:09:50.620 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1327]- NODE 2: Response processed after 110ms/293ms.
2016-01-23 13:09:50.621 TRACE o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1328]- Acquired. Transaction completed permit count -> 0
2016-01-23 13:09:50.622 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1211]- Took message from queue for sending. Queue length = 2
2016-01-23 13:09:50.623 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0x59
2016-01-23 13:09:50.623 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1504]- Released. Transaction completed permit count -> 0
2016-01-23 13:09:50.624 DEBUG o.o.b.z.i.p.SerialMessage[:233]- Assembled message buffer = 01 09 00 13 02 02 84 05 25 18 59 
2016-01-23 13:09:50.626 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1268]- NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 84 05 25 18 59 
2016-01-23 13:09:50.649 TRACE o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1274]- Message SENT
2016-01-23 13:09:50.651 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1486]- Received ACK
2016-01-23 13:09:50.660 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1481]- Receive Message = 01 04 01 13 01 E8 
2016-01-23 13:09:50.662 TRACE o.o.b.z.i.p.SerialMessage[:136]- NODE 255: Creating new SerialMessage from buffer = 01 04 01 13 01 E8 
2016-01-23 13:09:50.663 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0xE8
2016-01-23 13:09:50.664 TRACE o.o.b.z.i.p.SerialMessage[:141]- NODE 255: Checksum matched
2016-01-23 13:09:50.665 TRACE o.o.b.z.i.p.SerialMessage[:153]- NODE 255: Message payload = 01 
2016-01-23 13:09:50.665 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1390]- Message is valid, sending ACK
2016-01-23 13:09:50.669 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1375]- Response SENT
2016-01-23 13:09:50.670 DEBUG o.o.b.z.i.p.ZWaveController[:1163]- Receive queue TAKE: Length=0
2016-01-23 13:09:50.671 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1405]- Receive queue ADD: Length=0
2016-01-23 13:09:50.671 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0xE8
2016-01-23 13:09:50.672 DEBUG o.o.b.z.i.p.SerialMessage[:233]- Assembled message buffer = 01 04 01 13 01 E8 
2016-01-23 13:09:50.673 DEBUG o.o.b.z.i.p.ZWaveController[:1164]- Process Message = 01 04 01 13 01 E8 
2016-01-23 13:09:50.674 DEBUG o.o.b.z.i.p.ZWaveController[:192]- Message: class = SendData (0x13), type = Response (0x01), payload = 01 
2016-01-23 13:09:50.674 TRACE o.o.b.z.i.p.ZWaveController[:246]- Incoming Message type = RESPONSE
2016-01-23 13:09:50.675 TRACE o.o.b.z.i.p.s.SendDataMessageClass[:36]- Handle Message Send Data Response
2016-01-23 13:09:50.675 DEBUG o.o.b.z.i.p.s.SendDataMessageClass[:38]- NODE 2: Sent Data successfully placed on stack.
2016-01-23 13:09:50.677 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1481]- Receive Message = 01 07 00 13 18 00 00 02 F1 
2016-01-23 13:09:50.678 TRACE o.o.b.z.i.p.SerialMessage[:136]- NODE 255: Creating new SerialMessage from buffer = 01 07 00 13 18 00 00 02 F1 
2016-01-23 13:09:50.679 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0xF1
2016-01-23 13:09:50.680 TRACE o.o.b.z.i.p.SerialMessage[:141]- NODE 255: Checksum matched
2016-01-23 13:09:50.681 TRACE o.o.b.z.i.p.SerialMessage[:153]- NODE 255: Message payload = 18 00 00 02 
2016-01-23 13:09:50.682 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1390]- Message is valid, sending ACK
2016-01-23 13:09:50.685 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1375]- Response SENT
2016-01-23 13:09:50.687 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1405]- Receive queue ADD: Length=1
2016-01-23 13:09:50.687 DEBUG o.o.b.z.i.p.ZWaveController[:1163]- Receive queue TAKE: Length=0
2016-01-23 13:09:50.689 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0xFF
2016-01-23 13:09:50.689 DEBUG o.o.b.z.i.p.SerialMessage[:233]- Assembled message buffer = 01 09 00 13 18 00 00 02 00 00 FF 
2016-01-23 13:09:50.690 DEBUG o.o.b.z.i.p.ZWaveController[:1164]- Process Message = 01 09 00 13 18 00 00 02 00 00 FF 
2016-01-23 13:09:50.691 DEBUG o.o.b.z.i.p.ZWaveController[:192]- Message: class = SendData (0x13), type = Request (0x00), payload = 18 00 00 02 
2016-01-23 13:09:50.691 TRACE o.o.b.z.i.p.ZWaveController[:212]- Incoming Message type = REQUEST
2016-01-23 13:09:50.692 TRACE o.o.b.z.i.p.s.SendDataMessageClass[:58]- Handle Message Send Data Request
2016-01-23 13:09:50.692 DEBUG o.o.b.z.i.p.s.SendDataMessageClass[:74]- NODE 2: SendData Request. CallBack ID = 24, Status = Transmission complete and ACK received(0)
2016-01-23 13:09:50.692 TRACE o.o.b.z.i.p.SerialMessage[:399]- Ack Pending cleared
2016-01-23 13:09:50.693 DEBUG o.o.b.z.i.p.s.ZWaveCommandProcessor[:63]- Sent message Message: class = SendData (0x13), type = Request (0x00), payload = 02 02 84 05 
2016-01-23 13:09:50.694 DEBUG o.o.b.z.i.p.s.ZWaveCommandProcessor[:64]- Recv message Message: class = SendData (0x13), type = Request (0x00), payload = 18 00 00 02 
2016-01-23 13:09:50.694 DEBUG o.o.b.z.i.p.s.ZWaveCommandProcessor[:65]- Checking transaction complete: class=SendData, expected=ApplicationCommandHandler, cancelled=false
2016-01-23 13:09:51.829 DEBUG o.o.b.z.i.ZWaveNetworkMonitor[:315]- Network Monitor: Queue length is 2 - deferring network monitor functions.
2016-01-23 13:09:52.061 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1548]- Watchdog: Checking Serial threads
2016-01-23 13:09:55.651 ERROR o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1309]- NODE 2: Timeout while sending message. Requeueing - 2 attempts left!
2016-01-23 13:09:55.655 TRACE o.o.b.z.i.p.s.SendDataMessageClass[:133]- NODE 2: Handling failed message.
2016-01-23 13:09:55.656 DEBUG o.o.b.z.i.p.c.ZWaveWakeUpCommandClass[:435]- NODE 2: Is sleeping
2016-01-23 13:09:55.657 DEBUG o.o.b.z.i.p.c.ZWaveWakeUpCommandClass[:241]- NODE 2: Putting message SendData in wakeup queue.
2016-01-23 13:09:55.658 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1211]- Took message from queue for sending. Queue length = 1
2016-01-23 13:09:55.659 DEBUG o.o.b.z.i.p.c.ZWaveWakeUpCommandClass[:237]- NODE 2: Message already on the wake-up queue. Removing original.
2016-01-23 13:09:55.660 DEBUG o.o.b.z.i.p.c.ZWaveWakeUpCommandClass[:241]- NODE 2: Putting message SendData in wakeup queue.
2016-01-23 13:09:55.661 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveSendThread[:1211]- Took message from queue for sending. Queue length = 0
2016-01-23 13:09:55.662 DEBUG o.o.b.z.i.p.c.ZWaveWakeUpCommandClass[:237]- NODE 2: Message already on the wake-up queue. Removing original.
2016-01-23 13:09:55.662 DEBUG o.o.b.z.i.p.c.ZWaveWakeUpCommandClass[:241]- NODE 2: Putting message SendData in wakeup queue.
2016-01-23 13:10:02.061 TRACE o.o.b.z.i.p.ZWaveController$WatchDogTimerTask[:1548]- Watchdog: Checking Serial threads

Here is my zwave items

Switch Rem_A_b1m  "Remote A Button 1"      (button)  {zwave="2:0:command=SCENE_ACTIVATION,scene=1,state=1"}
Switch Rem_A_b1h  "Remote A Button 1 hold" (button)  {zwave="2:0:command=SCENE_ACTIVATION,scene=2,state=1"}
Switch Rem_A_b2m  "Remote A Button 2"      (button)  {zwave="2:0:command=SCENE_ACTIVATION,scene=3,state=1"}
Switch Rem_A_b2h  "Remote A Button 2 hold" (button)  {zwave="2:0:command=SCENE_ACTIVATION,scene=4,state=1"}
Switch Rem_A_b3m  "Remote A Button 3"      (button)  {zwave="2:0:command=SCENE_ACTIVATION,scene=5,state=1"}
Switch Rem_A_b3h  "Remote A Button 3 hold" (button)  {zwave="2:0:command=SCENE_ACTIVATION,scene=6,state=1"}
Switch Rem_A_b4m  "Remote A Button 4"      (button)  {zwave="2:0:command=SCENE_ACTIVATION,scene=7,state=1"}
Switch Rem_A_b4h  "Remote A Button 4 hold" (button)  {zwave="2:0:command=SCENE_ACTIVATION,scene=8,state=1"}

And here is the rule I am trying to trigger

rule "zwave test button 1"
when 
	Rem_A_b1m received update
then 
	sendCommand(Toggle_3, ON)

end

Can anyone please offer some suggestions?

TIA

kyle · January 24, 2016, 4:20pm

Were you able to set the “Secondary Controller Mode” configuration to “Scene Mode”? (This config is only in openhab 1.8)

DMize · January 24, 2016, 4:30pm

I have the zwave binding snapshot from Jan 4, 2016. But I am still running OH 1.7.
I’ve attempted to set it but it keeps showing ‘update pending’. I’ve left it overnight and force woken the minimote with no change. Late yesterday I put habmin2 on the server (which is a really nice interface) and here is a screenshot.

I am getting the key presses in the zwave log but I don’t have a node.xml created for it. I’ve checked the permissions on the directory to make sure the openhab user can write and it can (it did create the node1.xml for the zwave dongle).

The minimote has version 1.19 firmware which is the latest (not sure when it was released though).

Any ideas would be great, I’ve wasted at least 3 days on this and I’m about burnt out on the idea of adding anything zwave.

kyle · January 24, 2016, 4:43pm

So I would recommend updating to 1.8.

It is a pain in the butt getting the configuration changes to take. I
simply had to keep messing with it (waking it over and over etc). The
config will eventually take though.

Once you get that set to Scene Mode, you’re all set.

DMize · January 24, 2016, 5:29pm

Thanks Kyle, I’ve update to 1.8 and restarted the service.

So should I just push the learn button for 3 secs over and over or should I just do it occasionally?

Everything else looks fine to you?

Thanks

DMize · January 24, 2016, 5:40pm

Another question - should it say that it’s power by MAINS… it is a battery device so I wondered if that may have anything to do with it having a hard time finishing initialization.

DMize · January 29, 2016, 11:35am

I’ve been working with an engineer from Aeotec for the past 17 days on this and he tells me that parameter 250 is set. On my minimote.

In the logs I see that the button press is being recognized.
2016-01-29 06:13:31.414 TRACE o.o.b.z.i.p.SerialMessage[:141]- NODE 255: Checksum matched
2016-01-29 06:13:31.415 TRACE o.o.b.z.i.p.SerialMessage[:153]- NODE 255: Message payload = 00 02 04 2B 01 01 00 
2016-01-29 06:13:31.415 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1390]- Message is valid, sending ACK
2016-01-29 06:13:31.417 TRACE o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1375]- Response SENT
2016-01-29 06:13:31.424 DEBUG o.o.b.z.i.p.ZWaveController[:1163]- Receive queue TAKE: Length=0
2016-01-29 06:13:31.425 TRACE o.o.b.z.i.p.SerialMessage[:179]- Calculated checksum = 0xDC
2016-01-29 06:13:31.426 DEBUG o.o.b.z.i.p.SerialMessage[:233]- Assembled message buffer = 01 0A 00 04 00 02 04 2B 01 01 00 DC 
2016-01-29 06:13:31.427 DEBUG o.o.b.z.i.p.ZWaveController[:1164]- Process Message = 01 0A 00 04 00 02 04 2B 01 01 00 DC 
2016-01-29 06:13:31.427 DEBUG o.o.b.z.i.p.ZWaveController[:192]- Message: class = ApplicationCommandHandler (0x04), type = Request (0x00), payload = 00 02 04 2B 01 01 00 
2016-01-29 06:13:31.428 TRACE o.o.b.z.i.p.ZWaveController[:212]- Incoming Message type = REQUEST
2016-01-29 06:13:31.428 TRACE o.o.b.z.i.p.s.ApplicationCommandMessageClass[:30]- Handle Message Application Command Request
2016-01-29 06:13:31.428 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:38]- NODE 2: Application Command Request (ALIVE:STATIC_VALUES)
2016-01-29 06:13:31.429 DEBUG o.o.b.z.i.p.s.ApplicationCommandMessageClass[:56]- NODE 2: Incoming command class SCENE_ACTIVATION
2016-01-29 06:13:31.429 TRACE o.o.b.z.i.p.s.ApplicationCommandMessageClass[:79]- NODE 2: Found Command Class SCENE_ACTIVATION, passing to handleApplicationCommandRequest
2016-01-29 06:13:31.429 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:62]- Received Scene Activation for Node ID = 2
2016-01-29 06:13:31.430 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:66]- Scene Activation Set
2016-01-29 06:13:31.430 DEBUG o.o.b.z.i.p.c.ZWaveBasicCommandClass[:93]- Scene activation node from node 2: Scene 1, Time 0
2016-01-29 06:13:31.430 DEBUG o.o.b.z.i.p.ZWaveController[:635]- Notifying event listeners: ZWaveCommandClassValueEvent
2016-01-29 06:13:31.431 DEBUG o.o.b.z.i.ZWaveActiveBinding[:433]- ZwaveIncomingEvent
2016-01-29 06:13:31.431 DEBUG o.o.b.z.i.ZWaveActiveBinding[:450]- NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = SCENE_ACTIVATION, value = 1
2016-01-29 06:13:31.431 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b1h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-29 06:13:31.431 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b3h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-29 06:13:31.432 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b2h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-29 06:13:31.432 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b4h, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-29 06:13:31.432 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b2m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-29 06:13:31.432 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b1m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-29 06:13:31.433 DEBUG o.o.b.z.i.p.ZWaveController$ZWaveReceiveThread[:1405]- Receive queue ADD: Length=0
2016-01-29 06:13:31.437 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b4m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-29 06:13:31.439 TRACE o.o.b.z.i.c.ZWaveConverterHandler[:346]- Getting converter for item = Rem_A_b3m, command class = SCENE_ACTIVATION, item command class = scene_activation
2016-01-29 06:13:31.439 TRACE o.o.b.z.i.p.s.ZWaveCommandProcessor[:59]- Message has Ack Pending

But not much before that in the log I’m still getting this…

2016-01-29 06:08:47.040 TRACE o.o.b.z.i.ZWaveGenericBindingProvider[:48]- validateItemType(Rem_A_b1m, 2:0:command=SCENE_ACTIVATION,scene=1,state=1)
2016-01-29 06:08:47.040 TRACE o.o.b.z.i.ZWaveGenericBindingProvider[:57]- processBindingConfiguration(Rem_A_b1m, 2:0:command=SCENE_ACTIVATION,scene=1,state=1)
2016-01-29 06:08:47.040 TRACE o.o.b.z.i.ZWaveActiveBinding[:135]- bindingChanged Rem_A_b1m
2016-01-29 06:08:47.041 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b1m is not completed initialisation
2016-01-29 06:08:47.041 TRACE o.o.b.z.i.ZWaveGenericBindingProvider[:48]- validateItemType(Rem_A_b1h, 2:0:command=SCENE_ACTIVATION,scene=2,state=1)
2016-01-29 06:08:47.042 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b1m is not completed initialisation
2016-01-29 06:08:47.043 TRACE o.o.b.z.i.ZWaveGenericBindingProvider[:48]- validateItemType(Rem_A_b2m, 2:0:command=SCENE_ACTIVATION,scene=3,state=1)
2016-01-29 06:08:47.043 TRACE o.o.b.z.i.ZWaveGenericBindingProvider[:57]- processBindingConfiguration(Rem_A_b2m, 2:0:command=SCENE_ACTIVATION,scene=3,state=1)
2016-01-29 06:08:47.043 TRACE o.o.b.z.i.ZWaveActiveBinding[:135]- bindingChanged Rem_A_b2m
2016-01-29 06:08:47.043 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b1h is not completed initialisation
2016-01-29 06:08:47.043 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b2m is not completed initialisation
2016-01-29 06:08:47.043 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b1m is not completed initialisation
2016-01-29 06:08:47.044 TRACE o.o.b.z.i.ZWaveGenericBindingProvider[:48]- validateItemType(Rem_A_b2h, 2:0:command=SCENE_ACTIVATION,scene=4,state=1)
2016-01-29 06:08:47.044 TRACE o.o.b.z.i.ZWaveGenericBindingProvider[:57]- processBindingConfiguration(Rem_A_b2h, 2:0:command=SCENE_ACTIVATION,scene=4,state=1)
2016-01-29 06:08:47.044 TRACE o.o.b.z.i.ZWaveActiveBinding[:135]- bindingChanged Rem_A_b2h
2016-01-29 06:08:47.045 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b1h is not completed initialisation
2016-01-29 06:08:47.045 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b2h is not completed initialisation
2016-01-29 06:08:47.045 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b2m is not completed initialisation
2016-01-29 06:08:47.045 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b1m is not completed initialisation
2016-01-29 06:08:47.045 TRACE o.o.b.z.i.ZWaveGenericBindingProvider[:48]- validateItemType(Rem_A_b3m, 2:0:command=SCENE_ACTIVATION,scene=5,state=1)
2016-01-29 06:08:47.045 TRACE o.o.b.z.i.ZWaveGenericBindingProvider[:57]- processBindingConfiguration(Rem_A_b3m, 2:0:command=SCENE_ACTIVATION,scene=5,state=1)
2016-01-29 06:08:47.046 TRACE o.o.b.z.i.ZWaveActiveBinding[:135]- bindingChanged Rem_A_b3m
2016-01-29 06:08:47.046 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b1h is not completed initialisation
2016-01-29 06:08:47.046 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b2h is not completed initialisation
2016-01-29 06:08:47.047 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b2m is not completed initialisation
2016-01-29 06:08:47.047 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b1m is not completed initialisation
2016-01-29 06:08:47.047 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b3m is not completed initialisation
2016-01-29 06:08:47.047 TRACE o.o.b.z.i.ZWaveGenericBindingProvider[:48]- validateItemType(Rem_A_b3h, 2:0:command=SCENE_ACTIVATION,scene=6,state=1)
2016-01-29 06:08:47.047 TRACE o.o.b.z.i.ZWaveGenericBindingProvider[:57]- processBindingConfiguration(Rem_A_b3h, 2:0:command=SCENE_ACTIVATION,scene=6,state=1)
2016-01-29 06:08:47.048 TRACE o.o.b.z.i.ZWaveActiveBinding[:135]- bindingChanged Rem_A_b3h
2016-01-29 06:08:47.048 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b1h is not completed initialisation
2016-01-29 06:08:47.048 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b3h is not completed initialisation
2016-01-29 06:08:47.048 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b2h is not completed initialisation
2016-01-29 06:08:47.048 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b2m is not completed initialisation
2016-01-29 06:08:47.049 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b1m is not completed initialisation
2016-01-29 06:08:47.049 DEBUG o.o.b.z.i.ZWaveActiveBinding[:192]- NODE 2: Polling list: item Rem_A_b3m is not completed initialisation

The node.xml has not been created yet and it looks like the initialization has not completed but it is recognizing that the minimote is in scene mode and the buttons are being pressed but openhab isn’t doing anything because the initialization hasn’t completed yet.

Over the past few days I’ve woken the device over 60 times with nothing to show for it.

I’m got one more day to send this all back to the store and forget zwave so if anyone has some advice that’d be great.

Thanks,
Dan

kyle · January 29, 2016, 12:45pm

I believe it’s OK that it isn’t completing initialization. Mine never does
but everything still works. Show me what your item line looks like for one
of these buttons.

DMize · January 30, 2016, 3:07pm

Here is the 1st button on the remote from my item file.

Switch Rem_A_b1m "Remote A Button 1" (button) {zwave="2:0:command=SCENE_ACTIVATION,scene=1,state=1"}

and here is the test rule I’ve been using

rule "zwave test button 1"
when 
	Rem_A_b1m received update
then 
	sendCommand(Toggle_3, ON)

end

Any thoughts?

kyle · January 31, 2016, 2:12am

Hmm. I compared my zwave logs to yours when I press a button on my remote and everything matches up until the lines that say “Getting converter for item…”. I don’t get any of those.

I am fairly certain that your remote is working correctly with openhab but for whatever reason your rules aren’t working.

Qris · January 31, 2016, 11:41am

I don’t want to hijack your topic, but we are using the same hardware, so maybe you can help me out, and perhaps I can help you at a later moment in time

My Minimote doesn’t seem to get recognized properly (Node 2). I tried resetting both the Z-Stick and the Minimote but nothing worked. Also, no zwave xml is created for this particular remote. My Fibaro dimmer and motion sensor work fine before I resetted everything.

I’m using Openhab 1.7.1 (?)

Thanks for any help!

DMize · January 31, 2016, 3:15pm

@Qris, to get mine to pick up the details of the minimote I had to hold the Join/Learn button for 3-4 seconds. Then it displayed that it was a minimote and showed a lot more details. I’ve yet to get mine to create a node xml file for the minimote but I’m not positive that it will because I was just told that it will never complete initialization.
Let me know if you get your minimote firing rules because I’ve been working on this for a month now.

@kyle, thanks. Do you think it’s a binding issue? Do you think I should create a bug? I’m not finding much about ‘Getting converter for item’. And I’ve noticed that in log before and searched on it in the past.

Qris · February 6, 2016, 10:44am

Thnx DMize,

First off, sorry for replying this late. I’m in building a new home, hence the use of domotics

Pressing the Learn button for a couple of seconds did the job on identifying the Minimote, at least to some extend. It shows up in my Devices tab but I can only see a couple of parameters (no parameter 250). I cannot change the settings.

In my terminal it says this when I press the learn button:

2016-02-06 11:35:19.309 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 3: Unsupported command class ASSOCIATION_COMMAND_CONFIGURATION
2016-02-06 11:35:19.346 [WARN ] [b.z.i.p.s.SendDataMessageClass] - NODE 3: Already processed another send data request for this callback Id, ignoring.
2016-02-06 11:35:24.313 [ERROR] [WaveController$ZWaveSendThread] - NODE 3: Timeout while sending message. Requeueing - 1 attempts left!

DMize · February 6, 2016, 2:59pm

No problem, I’m still working on my issue too so I’m hoping that if we get yours working something will click with mine. I’ve now tried this zwave stick and minimote on three machines (1 Linux bare metal, 1 Linux vm, and 1 windows bare metal) and it has yet to work. I keep getting logs that have “Getting converter for item…” in them which I’m not seeing much info about.

For you to get the parameter 250 you need to update your zwave binding. You might as well grab the latest from the stable release or even the latest nightly build. https://openhab.ci.cloudbees.com/job/openHAB1-Addons/

Once that is loaded you should be able to see the parameter 250. Let me know how it goes.

Qris · February 6, 2016, 3:47pm

Hi Dan,

So I updated the Z-Wave binding to 1.8.0. Still no luck getting all the parameters to show up. Only 241 till 248 are visible. The Minimote also doesn’t show any neighbours. Strange…

I’ll try to remove and re-add the Minimote once more… If I could only get the thing to work, then I can hopefully help you with the rules. I’m also planning on using those, so I’ll do my very best

DMize · February 6, 2016, 5:48pm

In habmin on the left where it shows the binding names does it show you what version of the binding you have? I don’t see a spot where it shows the version number for habmin2. Maybe you have to copies of the binding and it’s using the wrong one? Updating my binding to 1.8.0 is what gave me the parameter 250. I don’t think the minimote will have neighbors because it’s not always listening so nothing will get routed through it other than the button presses from the remote itself.

Thanks for any help you can provide.