OH2 Z-Wave refactoring and testing... and SECURITY

[scurrier03]

@scurrier03

I installed the binding from the link near the start of this thread. After multiple tries I was able to get my Schlage lock included and it appears to be secure as indicated by a green check in habmin’s “Using Security” field.

The one problem I have left is that the device does not appear to be fully discovered. Since this is a battery device, do I need to wait for some time for it to wake up and finish whatever exchanges it needs to do to populate these device properties and make the device usable?

@chris

Most locks aren’t considered battery devices as they use FLIRS and I’d be a bit surprised if this doesn’t use FLIRS? In this case, it shouldn’t need to be woken up.

Feel free to email me the debug log - chris -at- cd-jackson.com and I’ll take a look in the coming days.

I came back to the system today and found that the lock properties had been filled in and it’s working as expected. I can lock and unlock the door.

I wasn’t sure what happened at first, but I have a theory now. I had my Pine64 that is hosting OpenHAB connected to a super slow wireless bridge. We’re talking 12 KB/s with some minor packet loss, <<1%. Given that I do recall the firmware for the lock populating in it’s OpenHAB thing back when I still had the problem I described, I’m wondering if maybe the initialization had completed just fine, but the properties and parameters weren’t filling in because of the slowness of this wireless bridge?

In other news, OpenHAB appears to have crashed on me today. Not sure if that happened before or after the lock started working properly, but it definitely was before I observed it was working.

The lock is a Schlage BE469.

Do you still want to see the logs?

[scurrier03]

@shawnmix

my BE469 has functional communication, but it seems some of the EXTRA functions are not working properly. Specifically, I tried using this to add security codes to the lock, but it’s not taking them.

I could test this, too, if need be.

[scurrier03]

Sorry to spam here, but I’ve found something else that is suspect.

This gentleman here claims that his BE469 lock (same one I have) is reporting battery life and updating status when locked/unlocked by hand.

My lock, on the other hand, only has a channel for the door lock switch, and it doesn’t update automatically when the lock is driven by hand. I have to go into HABmin and click “Refresh Items” from the Thing>Description page to get it to reflect the hand-driven status change.

I did some digging and it appears that the lock supports some type of battery status, according to the zwave database.

What should I be expecting here?

On another note, I’m now seeing some worrisome lines in the openhab.log about a SECURITY_ERR. Node 25 is my lock in this snip from the log:

2017-02-22 00:22:28.058 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 25: SECURITY_ERR No valid NONCE! null
2017-02-22 00:22:28.059 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-02-22 00:22:28.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-02-22 00:22:28.062 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-02-22 00:22:28.063 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
2017-02-22 00:22:28.244 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 21 00 04 10 19 1B 98 81 C4 6D 77 66 D8 8C C9 DE E5 B8 2B 2A AD 84 28 88 05 9A 50 44 B6 1B 6E 9E BA 93 
2017-02-22 00:22:28.250 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-02-22 00:22:28.255 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=25, callback=16, payload=10 19 1B 98 81 C4 6D 77 66 D8 8C C9 DE E5 B8 2B 2A AD 84 28 88 05 9A 50 44 B6 1B 6E 9E BA 
2017-02-22 00:22:28.259 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=25, callback=16, payload=10 19 1B 98 81 C4 6D 77 66 D8 8C C9 DE E5 B8 2B 2A AD 84 28 88 05 9A 50 44 B6 1B 6E 9E BA 
2017-02-22 00:22:28.263 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=25, callback=16, payload=10 19 1B 98 81 C4 6D 77 66 D8 8C C9 DE E5 B8 2B 2A AD 84 28 88 05 9A 50 44 B6 1B 6E 9E BA 
2017-02-22 00:22:28.264 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2017-02-22 00:22:28.266 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 25: Application Command Request (ALIVE:DONE)
2017-02-22 00:22:28.268 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 25: resetResendCount initComplete=true isDead=false
2017-02-22 00:22:28.271 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 25: Decapsulating COMMAND_CLASS_SECURITY
2017-02-22 00:22:28.273 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 25: SECURITY_ERR No valid NONCE! null

So at this point, I have two sets of logs which may be of interest.

[chris (Chris Jackson)]

@shawnmix

Or should I get some debug logs going again?

Yes please. I think that the code command class should work - I’ve certainly used it in the past to set codes in my lock, but I’ve not tested it recently.

[chris (Chris Jackson)]

@scurrier03

My lock, on the other hand, only has a channel for the door lock switch, and it doesn’t update automatically when the lock is driven by hand.

At least for my Yale, it doesn’t send updates when the door is unlocked/opened (this is annoying). I think this is also true of other locks. Instead, they send an alarm message - we can of course decode this, and display it, and this is something on my hitlist, but it won’t allow the lock status to be directly updated (probably) - you could use a rule to link it to the lock though (probably).

Kwikset Lock Alarms

@scurrier03

I’m now seeing some worrisome lines in the openhab.log about a SECURITY_ERR.

It’s hard to say if this is really an error. This might just be due to retries or something - again, a log would be good, but I need more than just the error - I always need to see the information before the error happened.

Please consider emailing me the log - security keys aren’t logged here, but door codes could be, and in general as we’re talking about security I would just suggest not to publish too much on a public forum (that way you only have to worry about me breaking into you house ).

[shawnmix]

@scurrier03

Sorry to spam here, but I’ve found something else that is suspect.

No spamming, you’re in the same boat as I. Same lock (BE469). I will say some of the configuration settings have gone through, as the original code was 4-digits, when I changed the setting to 6 digits, I did notice it no longer was accepting the old code (expected behavior) and now would let you enter 6 digits before giving you the Red X for a non-existent code.

I’ve set to DEBUG level and made the update. I don’t see anything alarming in the logs myself, it looks as though the transaction went through successfully. Validated the code is not working in the door lock. I notice in HABmin as well that the code transaction has little orange pending bubble still. Log output is below.

I’m also wondering if I’ll be able to get the quicker status updates from manual operation. Looking at the product page with ZWaveAlliance - this lock doesn’t have associations like others for instant status updates. I know obviously the mapping piece outlined would be helpful, but in my debug logs I don’t even see anything relative to actions when putting in the wrong code, unlocking the door, anything. All I can do is use the item to lock/unlock - but no way to really read the status it seems. I think unfortunately though, this is due to the lock capabilities. A new Yale lock with ZWave Plus is on it’s way … I think this lock will be getting replaced.

NODE26 = Lock

09:30:08.526 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 26: Configuration update received
09:30:08.538 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 26: Configuration update usercode_2 to 091686
09:30:08.538 [DEBUG] [mmandclass.ZWaveUserCodeCommandClass] - NODE 26: Setting user code for 2
09:30:08.539 [DEBUG] [ommandClassTransactionPayloadBuilder] - At build null
09:30:08.539 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 26: Adding to device queue
09:30:08.539 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 26: Added to queue - size 0
09:30:08.540 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
09:30:08.540 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 26: listening == false, frequentlyListening == true, awake == false
09:30:08.541 [DEBUG] [e.internal.protocol.ZWaveTransaction] - >>>>> transaction payload is the same [[99, 1, 2, 1, 48, 57, 49, 54, 56, 54]] == [[99, 1, 2, 1, 48, 57, 49, 54, 56, 54]]
09:30:08.541 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from sendQueue
09:30:08.541 [DEBUG] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
09:30:08.541 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 1A 0A 63 01 02 01 30 39 31 36 38 36 25 62 CB 
09:30:08.542 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 26: Sending REQUEST Message = 01 11 00 13 1A 0A 63 01 02 01 30 39 31 36 38 36 25 62 CB 
09:30:08.542 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
09:30:08.542 [DEBUG] [e.internal.protocol.ZWaveTransaction] - transactionStart type SendData 
09:30:08.543 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID:556 [WAIT_RESPONSE] callback: 98
09:30:08.543 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
09:30:08.543 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: 0
09:30:08.543 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
09:30:08.544 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Feb 22 09:30:10 EST 2017 - 2000ms
09:30:08.544 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID:556 [WAIT_RESPONSE] callback: 98
09:30:08.544 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
09:30:08.544 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Feb 22 09:30:10 EST 2017 - 2000ms
09:30:08.544 [DEBUG] [mmandclass.ZWaveUserCodeCommandClass] - NODE 26: Creating new message for application command USER_CODE_GET(2)
09:30:08.545 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
09:30:08.547 [DEBUG] [ommandClassTransactionPayloadBuilder] - At build COMMAND_CLASS_USER_CODE
09:30:08.547 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
09:30:08.547 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
09:30:08.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 26: Adding to device queue
09:30:08.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 26: Added to queue - size 0
09:30:08.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
09:30:08.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
09:30:08.548 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
09:30:08.549 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID:556 [WAIT_RESPONSE] callback: 98
09:30:08.549 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
09:30:08.549 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
09:30:08.549 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
09:30:08.550 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
09:30:08.550 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Feb 22 09:30:10 EST 2017 - 1995ms
09:30:08.550 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
09:30:08.550 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
09:30:08.550 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Feb 22 09:30:10 EST 2017 - 1994ms
09:30:08.554 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zwave:device:15a1b48bdc7:node26' has been updated.
09:30:08.557 [INFO ] [marthome.event.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[ConfigStatusMessage [parameterName=usercode_2, type=PENDING, messageKey=null, arguments=null, message=null, statusCode=null]]]
09:30:08.562 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
09:30:08.565 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
09:30:08.565 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01 
09:30:08.565 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01 
09:30:08.565 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01 
09:30:08.565 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID:556 [WAIT_RESPONSE] callback: 98
09:30:08.565 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
09:30:08.566 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID:556 [WAIT_RESPONSE] callback: 98
09:30:08.566 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01 
09:30:08.567 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 26: Sent Data successfully placed on stack.
09:30:08.567 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance ST: WAIT_RESPONSE
09:30:08.567 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance TX: null
09:30:08.568 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance WT: null
09:30:08.568 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance RX: Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01 
09:30:08.568 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance TO: WAIT_REQUEST
09:30:08.569 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction 98 advanced to WAIT_REQUEST
09:30:08.569 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 26: **** Transaction not completed
09:30:08.569 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
09:30:08.569 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
09:30:08.569 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
09:30:08.569 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
09:30:08.570 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Feb 22 09:30:13 EST 2017 - 5000ms
09:30:09.797 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 62 00 00 85 0C 
09:30:09.799 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
09:30:09.799 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=SendData[0x13], type=Request[0x00], dest=0, callback=98, payload=62 00 00 85 
09:30:09.800 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=SendData[0x13], type=Request[0x00], dest=0, callback=98, payload=62 00 00 85 
09:30:09.800 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=98, payload=62 00 00 85 
09:30:09.800 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID:556 [WAIT_REQUEST] callback: 98
09:30:09.800 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
09:30:09.800 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID:556 [WAIT_REQUEST] callback: 98
09:30:09.800 [DEBUG] [nal.protocol.ZWaveTransactionManager] - checking transaction 98 (Callback 98) ......
09:30:09.800 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
09:30:09.800 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to transaction 98......
09:30:09.800 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=98, payload=62 00 00 85 
09:30:09.800 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 26: SendData Request. CallBack ID = 98, Status = Transmission complete and ACK received(0)
09:30:09.801 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 26: resetResendCount initComplete=true isDead=false
09:30:09.801 [DEBUG] [e.internal.protocol.ZWaveTransaction] - Transaction 556 COMPLETED
09:30:09.801 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance ST: DONE
09:30:09.801 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance TX: null
09:30:09.801 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance WT: null
09:30:09.801 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance RX: Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=98, payload=62 00 00 85 
09:30:09.801 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance TO: DONE
09:30:09.801 [DEBUG] [e.internal.protocol.ZWaveTransaction] - >>>>> transaction payload is the same [[99, 1, 2, 1, 48, 57, 49, 54, 56, 54]] == [[99, 1, 2, 1, 48, 57, 49, 54, 56, 54]]
09:30:09.801 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 26: Response processed after 1259ms
09:30:09.802 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 26: **** Transaction completed
09:30:09.802 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 26: notifyTransactionResponse 556
09:30:09.804 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
09:30:09.804 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 26: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
09:30:09.804 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
09:30:09.804 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
09:30:09.804 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 26: listening == false, frequentlyListening == true, awake == false
09:30:09.804 [DEBUG] [e.internal.protocol.ZWaveTransaction] - >>>>> transaction payload is the same [[99, 2, 2]] == [[99, 2, 2]]
09:30:09.804 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from sendQueue
09:30:09.804 [DEBUG] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
09:30:09.805 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 1A 03 63 02 02 25 63 DA 
09:30:09.805 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 26: Sending REQUEST Message = 01 0A 00 13 1A 03 63 02 02 25 63 DA 
09:30:09.806 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
09:30:09.806 [DEBUG] [e.internal.protocol.ZWaveTransaction] - transactionStart type SendData 
09:30:09.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID:557 [WAIT_RESPONSE] callback: 99
09:30:09.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: COMMAND_CLASS_USER_CODE
09:30:09.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: 3
09:30:09.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
09:30:09.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
09:30:09.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Feb 22 09:30:11 EST 2017 - 2000ms
09:30:09.807 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID:557 [WAIT_RESPONSE] callback: 99
09:30:09.807 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
09:30:09.807 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Feb 22 09:30:11 EST 2017 - 1999ms
09:30:09.807 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
09:30:09.807 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
09:30:09.807 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
09:30:09.808 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
09:30:09.808 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID:557 [WAIT_RESPONSE] callback: 99
09:30:09.808 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
09:30:09.808 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
09:30:09.808 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
09:30:09.808 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
09:30:09.808 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
09:30:09.808 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Feb 22 09:30:11 EST 2017 - 1998ms
09:30:09.817 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
09:30:09.820 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
09:30:09.821 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01 
09:30:09.821 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01 
09:30:09.821 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01 
09:30:09.821 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID:557 [WAIT_RESPONSE] callback: 99
09:30:09.821 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
09:30:09.821 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID:557 [WAIT_RESPONSE] callback: 99
09:30:09.822 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01 
09:30:09.822 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 26: Sent Data successfully placed on stack.
09:30:09.823 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance ST: WAIT_RESPONSE
09:30:09.823 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance TX: null
09:30:09.823 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance WT: ApplicationCommandHandler
09:30:09.823 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance RX: Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01 
09:30:09.823 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance TO: WAIT_REQUEST
09:30:09.824 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction 99 advanced to WAIT_REQUEST
09:30:09.824 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 26: **** Transaction not completed
09:30:09.824 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
09:30:09.825 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
09:30:09.825 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
09:30:09.825 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
09:30:09.825 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Feb 22 09:30:14 EST 2017 - 4999ms
09:30:09.834 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 63 00 00 02 8A 
09:30:09.834 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
09:30:09.834 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=SendData[0x13], type=Request[0x00], dest=0, callback=99, payload=63 00 00 02 
09:30:09.834 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=SendData[0x13], type=Request[0x00], dest=0, callback=99, payload=63 00 00 02 
09:30:09.834 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=99, payload=63 00 00 02 
09:30:09.834 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID:557 [WAIT_REQUEST] callback: 99
09:30:09.834 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
09:30:09.834 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID:557 [WAIT_REQUEST] callback: 99
09:30:09.834 [DEBUG] [nal.protocol.ZWaveTransactionManager] - checking transaction 99 (Callback 99) ......
09:30:09.835 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
09:30:09.835 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to transaction 99......
09:30:09.835 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=99, payload=63 00 00 02 
09:30:09.835 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 26: SendData Request. CallBack ID = 99, Status = Transmission complete and ACK received(0)
09:30:09.835 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 26: resetResendCount initComplete=true isDead=false
09:30:09.835 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance ST: WAIT_REQUEST
09:30:09.835 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance TX: null
09:30:09.835 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance WT: ApplicationCommandHandler
09:30:09.835 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance RX: Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=99, payload=63 00 00 02 
09:30:09.835 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TransactionAdvance TO: DONE
09:30:09.835 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction 99 advanced to DONE
09:30:09.835 [DEBUG] [e.internal.protocol.ZWaveTransaction] - >>>>> transaction payload is the same [[99, 2, 2]] == [[99, 2, 2]]
09:30:09.835 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 26: Response processed after 29ms
09:30:09.835 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 26: **** Transaction completed
09:30:09.835 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 26: notifyTransactionResponse 557
09:30:09.835 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
09:30:09.835 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 26: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
09:30:09.835 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
09:30:09.835 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
09:30:09.835 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
09:30:09.836 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
09:30:09.836 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

[TordYevl (Tommy)]

Did one more try with my Danalock V3, excluded it from my controler and habmin.
Stopped openhab and cleared the log file.
Started openhab and set the logging level to debug.
Multiple tries to set openhab and the lock in inclusion mode.
After a couple of times the lock is found by openhab but not identified.
The lock is woken up by putting it in inclusion mode (good or bad?) no change.
I delete the item in habmin and scan again now the lock is found and identified, Using security still shows a question mark in habmin.
The lock is multiple times woken up by inclusion mode. Here I get an exception in the logs.
After a number of waking up the lock plays a melody and Using security in habmin show a green check.
I now try to control my lock but without luck
Could the exception be the reason for why I can’t control the lock (NODE 23)?

2017-02-22 20:04:21.265 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:15a52609621:node23.
2017-02-22 20:04:21.267 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: MANUFACTURER not set
2017-02-22 20:04:21.267 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Controller status changed to ONLINE.
2017-02-22 20:04:21.267 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Controller is ONLINE. Starting device initialisation.
2017-02-22 20:04:21.267 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Updating node properties.
2017-02-22 20:04:21.267 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Updating node properties. MAN=270
2017-02-22 20:04:21.267 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 23: Updating node properties. MAN=270. SET. Was null
2017-02-22 20:04:21.271 [ERROR] [ome.core.thing.internal.ThingManager] - Exception occured while initializing handler of thing 'zwave:device:15a52609621:node23': java.lang.NullPointerException
java.util.concurrent.ExecutionException: java.lang.NullPointerException
	at java.util.concurrent.FutureTask.report(FutureTask.java:122)[:1.8.0_121]
	at java.util.concurrent.FutureTask.get(FutureTask.java:206)[:1.8.0_121]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.callAsynchronous(SafeMethodCaller.java:194)[99:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:83)[99:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.core.common.SafeMethodCaller.call(SafeMethodCaller.java:67)[99:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$9.run(ThingManager.java:698)[106:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_121]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)[:1.8.0_121]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)[:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_121]
	at java.lang.Thread.run(Thread.java:745)[:1.8.0_121]
Caused by: java.lang.NullPointerException
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.updateNodeProperties(ZWaveThingHandler.java:1396)[9:org.openhab.binding.zwave:2.1.0.201702192058]
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.bridgeStatusChanged(ZWaveThingHandler.java:488)[9:org.openhab.binding.zwave:2.1.0.201702192058]
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.initialize(ZWaveThingHandler.java:158)[9:org.openhab.binding.zwave:2.1.0.201702192058]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$9$1.call(ThingManager.java:701)[106:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$9$1.call(ThingManager.java:1)[106:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:181)[99:org.eclipse.smarthome.core:0.9.0.201702100936]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
	... 3 more
2017-02-22 20:04:21.562 [DEBUG] [ve.internal.protocol.ZWaveController] - Stopping inclusion timer.
2017-02-22 20:04:21.562 [DEBUG] [ve.internal.protocol.ZWaveController] - Neither inclusion nor exclusion was active!
2017-02-22 20:04:23.918 [DEBUG] [sactionManager$ZWaveTransactionTimer] - XXXXXXXXX Timeout.......... 1 outstanding transactions
2017-02-22 20:04:23.918 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 23: XXXXXXX Timeout at state WAIT_DATA. 3 retries remaining.
2017-02-22 20:04:23.918 [DEBUG] [e.internal.protocol.ZWaveTransaction] - Transaction 158 CANCELLED
2017-02-22 20:04:23.918 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-02-22 20:04:23.918 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: notifyTransactionResponse 158
2017-02-22 20:04:23.919 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: processing secure transaction -- 156

[shawnmix]

@whwkins

I had the same issue with a Linear GD00Z garage door opener showing up as an Unknown Device.

@whwkins Have you been able to get the Linear GD00Z-4 working with this Security binding for OH2? I’m in the same boat. I just keep hitting brick walls as I get my system expanded, failing to fully get the details I need apparently until things don’t work.

This time I knew it wasn’t going to directly work with my garage door as I have a LiftMaster MyQ Security+2.0 opener which has problems working. But I’ve seen 2 workarounds involving simple soldering jobs. I was going to attempt testing the wire connections first before soldering, but it seems I’m only getting a Barrier Position channel as well. If I look at the node attributes, I can see that it does say it’s using Security, but alas no barrier operator channel.

@chris is it that there is just still something missing at this point? I’m contemplating jumping back onto the 1.x binding for now if I can get the lock working and the garage opener working until the 2.0 is ready for prime time. Just sucks having to re-assign all the items. I’d rather not if I don’t have to or if it’s something I can help get working with you, but I have to weight the options.

[whwkins (William Hawkins)]

@shawnmix

@whwkins

I had the same issue with a Linear GD00Z garage door opener showing up as an Unknown Device.

@whwkins Have you been able to get the Linear GD00Z-4 working with this Security binding for OH2? I’m in the same boat. I just keep hitting brick walls as I get my system expanded, failing to fully get the details I need apparently until things don’t work.

I have got my GD00Z-4 working. I had to include/exclude a few times to get Security working as expected, though I think a lot of that was because I was impatient and tried to re-include it too quickly when it showed up as an Unknown device. As for my last problem of control of the Barrier Position command class, I figured that out and have control of my garage door now.

[scurrier03]

@scurrier03

The one problem I have left is that the device does not appear to be fully discovered.

@scurrier03

On another note, I’m now seeing some worrisome lines in the openhab.log about a SECURITY_ERR.

@chris

Please consider emailing me the log

Log files have been emailed.

[shawnmix]

@whwkins

I have got my GD00Z-4 working. I had to include/exclude a few times to get Security working as expected, though I think a lot of that was because I was impatient and tried to re-include it too quickly when it showed up as an Unknown device. As for my last problem of control of the Barrier Position command class, I figured that out and have control of my garage door now

So are you saying perhaps I need to exclude the device and try to include it again? Let it sit and transfer the appropriate details?

When you say control of the Barrier Position class, I assume you meant operator class? As I believe that is the one that allows functional open/close of the door. What needs to be figured out there? That’s the main issue I’m trying to overcome.

[chris (Chris Jackson)]

@shawnmix

@chris is it that there is just still something missing at this point?

Not that I know of - I believe it should include ok (other than the speed issue which I know the problem, but haven’t looked into in detail at the moment to find a solution), but if it’s not working for you then maybe there’s a bug, or maybe it’s something else. It’s really difficult to say without looking at logs - I know that’s always my statement, and it may sound like an excuse, but really without seeing what’s happening, I can only guess.

I would suggest to email any logs though rather than post them publicly ;).

@shawnmix

So are you saying perhaps I need to exclude the device and try to include it again?

Note that secure inclusion can ONLY occur within the first 20 seconds or so following the inclusion. If it doesn’t work during this time, then it will never work and you need to exclude and re-include the device from the controller.

[whwkins (William Hawkins)]

@shawnmix

So are you saying perhaps I need to exclude the device and try to include it again? Let it sit and transfer the appropriate details?

That is what I would try. I watched the logs on my last attempt and made sure inclusion was complete before trying to do anything else.

@shawnmix

When you say control of the Barrier Position class, I assume you meant operator class? As I believe that is the one that allows functional open/close of the door. What needs to be figured out there? That’s the main issue I’m trying to overcome.

Yes, the Barrier Operator class. It’s handled a little bit different from a Lock. It shows up as a number between 0 and 255. For me, the only useful numbers are 0 for CLOSED and 255 for OPEN. I think 254 is OPENING, 253 is STOPPED and 252 is CLOSING, but I don’t see those with my device. For control I have a Switch with a mapping in my sitemap to open/close the garage door:

Switch item=GarageDoorPosition mappings=[0="CLOSED", 255="OPEN"]

[shawnmix]

@chris

I would suggest to email any logs though rather than post them publicly .

It’s no problem, and I work in the IT world, so trust me logs are my life. It’s nothing crazy for me. Though I do have you in my mind as Mr please send me logs! j/k I thought it was securely included pretty quickly when I first did it, and I had included it right while it was plugged into my OH install as it was easier to bring it and plug right in next to the server. I’ll have a go at removing and re-including. I’ll run DEBUG level logs as well and kick those out for you to see in case it still fails.

@whwkins

Yes, the Barrier Operator class. It’s handled a little bit different from a Lock. It shows up as a number between 0 and 255. For me, the only useful numbers are 0 for CLOSED and 255 for OPEN. I think 254 is OPENING, 253 is STOPPED and 252 is CLOSING, but I don’t see those with my device. For control I have a Switch with a mapping in my sitemap to open/close the garage door:

Ya I did notice that it was reporting those weird numbers back. I was expecting a 0/1, but then saw the 255 and had a moment of thinking before trying to close and open again to see the change. Nice to know it has multiple mappings though, I’ll have to watch for those on the bus next time I test it out. I’m going to try and exclude then re-include the device to see if I can’t get the Operator function to work properly again.

On a side note (aka little off topic) - is there a way to create static mappings like what you listed for items that have been added through PaperUI/HABmin? So far I’ve prided myself on trying to keep almost ALL items adding through the GUI vs manual items files.

[g_g_rich]

Hi @chris.

Again, thanks for continually updating and improving the zwave binding! I’m testing the new binding, and noticed a few issues.

Node4 never finishes initializing endpoints.

2017-02-23 10:56:33.352 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 4: Initialising endpoints - version 1
2017-02-23 10:56:34.072 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 4: Initialising endpoints - version 1
2017-02-23 10:56:34.770 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 4: Initialising endpoints - version 1
2017-02-23 10:56:35.503 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 4: Initialising endpoints - version 1
2017-02-23 10:56:36.372 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 4: Initialising endpoints - version 1
2017-02-23 10:56:37.123 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 4: Initialising endpoints - version 1
2017-02-23 10:56:37.818 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 4: Initialising endpoints - version 1
2017-02-23 10:56:38.541 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 4: Initialising endpoints - version 1
2017-02-23 10:56:39.259 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 4: Initialising endpoints - version 1

and the zwave Start Frames and Frames Acknowledged are large and continually running up

2017-02-23 10:40:19.404 [ItemStateChangedEvent     ] - zStickSof changed from 1479901 to 1479902
2017-02-23 10:40:19.444 [ItemStateChangedEvent     ] - zStickSof changed from 1479902 to 1479903
2017-02-23 10:40:19.467 [ItemStateChangedEvent     ] - zStickSof changed from 1479903 to 1479904
2017-02-23 10:40:19.507 [ItemStateChangedEvent     ] - zStickAck changed from 493294 to 493295
2017-02-23 10:40:19.516 [ItemStateChangedEvent     ] - zStickSof changed from 1479904 to 1479905
2017-02-23 10:40:19.555 [ItemStateChangedEvent     ] - zStickSof changed from 1479905 to 1479906
2017-02-23 10:40:19.579 [ItemStateChangedEvent     ] - zStickSof changed from 1479906 to 1479907
2017-02-23 10:40:19.612 [ItemStateChangedEvent     ] - zStickAck changed from 493295 to 493296
2017-02-23 10:40:19.618 [ItemStateChangedEvent     ] - zStickSof changed from 1479907 to 1479908
2017-02-23 10:40:19.658 [ItemStateChangedEvent     ] - zStickSof changed from 1479908 to 1479909
2017-02-23 10:40:19.682 [ItemStateChangedEvent     ] - zStickSof changed from 1479909 to 1479910
2017-02-23 10:40:19.712 [ItemStateChangedEvent     ] - zStickAck changed from 493296 to 493297
2017-02-23 10:40:19.719 [ItemStateChangedEvent     ] - zStickSof changed from 1479910 to 1479911
2017-02-23 10:40:19.759 [ItemStateChangedEvent     ] - zStickSof changed from 1479911 to 1479912
2017-02-23 10:40:19.783 [ItemStateChangedEvent     ] - zStickSof changed from 1479912 to 1479913
2017-02-23 10:40:19.817 [ItemStateChangedEvent     ] - zStickAck changed from 493297 to 493298

Many of the channels from my other node never get updated, or get updated erratically even though I set the association group to my zstick.

Anyways, I’ve emailed you both the startup log and a later log.

[chris (Chris Jackson)]

@g_g_rich

Node4 never finishes initializing endpoints.

What is node 4? It looks like it’s using a very old (and unfortunately undocumented / deprecated) command class.

[chris (Chris Jackson)]

@g_g_rich please download the latest test binding - I’ve fixed a bug that will definitely improve your issue (send more logs if it doesn’t get much further though ;)).

[g_g_rich]

It is an older device.
It’s this: http://www.cd-jackson.com/index.php/zwave/zwave-device-database/zwave-device-list/devicesummary/426

I’ll download the new jar and let you know if there is improvement.
Thanks.

[g_g_rich]

The new jar seems to have fixed those issues. The node finished initializing the endpoints and all of the frame starts etc have settled down. Thanks.

One thing though, I can’t do any channel configuration for items ie. change scale from C to F. PaperUI gives a 500 internal server error, and habmin allows it, does not show any error, but the configuration does not change, don’t see anything in the logs.

[chris (Chris Jackson)]

@g_g_rich

I can’t do any channel configuration for items ie. change scale from C to F.

I assume everything is configured using the GUI and not through text files? I’m not sure what else would prevent that saving - is there anything logged?