[SOLVED] My first zwave devices. Binding seems to work but can't connect Fibaro sensor

plysdyret · March 5, 2019, 10:41pm

Platform information:
- Hardware: KVM VM, Linear HUSBZB-1 USB stick
- OS: Ubuntu 16.04.6 LTS
- Java Runtime Environment: openjdk version “1.8.0_202”
- openHAB version: 2.4.0 Release Build

I bought a Linear HUSBZB-1 USB stick and a Fibaro Motion Sensor FGMS-001. The binding seems to work but I can’t seem to add the sensor. It seems like this should just work, putting the controller into inclusion mode and then pushing the button on the fibaro device three times to discover it. The fibaro flashes blue when I do the thing, and it’s placed right next to the USB stick, but I’m unsure if it’s seen at all in the debug log:

23:15:00.803 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:bc646f19
23:15:00.805 [DEBUG] [ave.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 0
23:15:00.813 [DEBUG] [ave.internal.protocol.ZWaveController] - Event listener added.
23:15:00.814 [DEBUG] [nal.protocol.ZWaveInclusionController] - ZWave controller start inclusion
23:15:00.816 [DEBUG] [col.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:false networkWide:false.
23:15:00.817 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Added 11 to queue - size 1
23:15:00.818 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
23:15:00.820 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 01 04 B5
23:15:00.827 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 01 04 B5
23:15:00.833 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
23:15:00.834 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
23:15:00.835 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
23:15:00.837 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
23:15:00.843 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
23:15:00.846 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
23:15:00.833 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
23:15:00.842 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 04 01 00 00 B7
23:15:00.853 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 11: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4
23:15:00.860 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=4, payload=04 01 00 00
23:15:00.865 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
23:15:00.869 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=4, payload=04 01 00 00
23:15:00.875 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 11: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4
23:15:00.884 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
23:15:00.887 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 11: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4
23:15:00.890 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 11: (Callback 4)
23:15:00.892 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match!
23:15:00.901 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 11: callback 4
23:15:00.903 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=4, payload=04 01 00 00
23:15:00.906 [DEBUG] [col.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
23:15:00.917 [INFO ] [smarthome.event.BindingEvent         ] - org.openhab.binding.zwave.event.BindingEvent@5b537b93
23:15:00.919 [DEBUG] [nal.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart
23:15:00.920 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 11: Transaction COMPLETED
23:15:00.922 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 70ms
23:15:00.924 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: TID 11: Transaction completed
23:15:00.926 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:11 DONE
23:15:00.929 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
23:15:00.931 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
23:16:30.816 [DEBUG] [nal.protocol.ZWaveInclusionController] - Inclusion timer at IncludeStart
23:16:30.821 [DEBUG] [col.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
23:16:30.822 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Added 12 to queue - size 1
23:16:30.826 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
23:16:30.827 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 05 B0
23:16:30.830 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 05 B0
23:16:30.834 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
23:16:30.838 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 12: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 5
23:16:30.839 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
23:16:30.844 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
23:16:30.846 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
23:16:30.848 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 5
23:16:30.850 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
23:16:30.853 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
23:16:30.856 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
23:16:30.889 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 05 06 00 00 B1
23:16:30.896 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=5, payload=05 06 00 00
23:16:30.900 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=5, payload=05 06 00 00
23:16:30.909 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 12: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 5
23:16:30.914 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
23:16:30.916 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 12: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 5
23:16:30.917 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 12: (Callback 5)
23:16:30.919 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match!
23:16:30.920 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 12: callback 5
23:16:30.922 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=5, payload=05 06 00 00
23:16:30.923 [DEBUG] [col.serialmessage.AddNodeMessageClass] - Add Node: Done.
23:16:30.924 [DEBUG] [nal.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeFail, new event IncludeDone
23:16:30.926 [DEBUG] [col.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
23:16:30.933 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Added 13 to queue - size 1
23:16:30.939 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
23:16:30.940 [DEBUG] [nal.protocol.ZWaveInclusionController] - ZWave controller end exclusion
23:16:30.941 [DEBUG] [ave.internal.protocol.ZWaveController] - ZWaveController include done
23:16:30.951 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 12: Advanced to DONE
23:16:30.954 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 116ms
23:16:30.957 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: TID 12: Transaction completed
23:16:30.959 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:12 DONE
23:16:30.963 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
23:16:30.965 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
23:16:30.969 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5
23:16:30.972 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5
23:16:30.990 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
23:16:30.992 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
23:16:30.990 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
23:16:31.002 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 13: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
23:16:31.011 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
23:16:31.014 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 13: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
23:16:31.019 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
23:16:31.022 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
23:16:31.025 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
23:16:36.012 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 255: TID 13: Timeout at state WAIT_REQUEST. 3 retries remaining.
23:16:36.016 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - TID 13: Transaction is current transaction, so clearing!!!!!
23:16:36.021 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 13: Transaction CANCELLED
23:16:36.024 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:13 CANCELLED
23:16:36.028 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
23:17:31.389 [DEBUG] [nal.protocol.ZWaveInclusionController] - ZWave inclusion controller finalised
23:17:44.721 [WARN ] [su.litvak.chromecast.api.v2.Channel  ] - Error while reading
java.net.SocketException: Connection reset
        at java.net.SocketInputStream.read(SocketInputStream.java:210) ~[?:?]
        at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[?:?]
        at sun.security.ssl.InputRecord.readFully(InputRecord.java:465) ~[?:?]
        at sun.security.ssl.InputRecord.read(InputRecord.java:503) ~[?:?]
        at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:975) ~[?:?]
        at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:933) ~[?:?]
        at sun.security.ssl.AppInputStream.read(AppInputStream.java:105) ~[?:?]
        at sun.security.ssl.AppInputStream.read(AppInputStream.java:71) ~[?:?]
        at su.litvak.chromecast.api.v2.Channel.read(Channel.java:423) ~[265:org.openhab.binding.chromecast:2.4.0]
        at su.litvak.chromecast.api.v2.Channel.access$200(Channel.java:51) ~[265:org.openhab.binding.chromecast:2.4.0]
        at su.litvak.chromecast.api.v2.Channel$ReadThread.run(Channel.java:137) [265:org.openhab.binding.chromecast:2.4.0]
23:17:44.723 [WARN ] [su.litvak.chromecast.api.v2.Channel  ] -  <--  null payload in message
23:17:44.741 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'chromecast:chromecast:d71ac814ca90668c19ad214bf91bcfb0' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Interrupted while waiting for response
23:17:44.746 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'chromecast:chromecast:d71ac814ca90668c19ad214bf91bcfb0' changed from OFFLINE (COMMUNICATION_ERROR): Interrupted while waiting for response to OFFLINE
23:18:01.858 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'chromecast:chromecast:d71ac814ca90668c19ad214bf91bcfb0' changed from OFFLINE to ONLINE
23:20:00.801 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:bc646f19
23:20:00.803 [DEBUG] [ave.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do

Any advice on how to proceed would be appreciated.

Thanks,

Torkil

dastrix80 · March 5, 2019, 10:51pm

What model of the FGMS-0001 is this? You can check the ZWave Database for your device to determine if its supported (There were some changes in the last week to add support for newer firmwares)

If you open HabMin, locate your device it and check in attributes it should give you the firwmare/make/model. You can use that info against Chris Jacksons Zwave binding database to confirm support

https://www.cd-jackson.com/index.php/zwave/zwave-device-database

Chances are youll need the latest Snapshot binding for Zwave. Delete the FGMS0001 thing and away you go.

Grab the snapshot binding 2.5 here : https://ci.openhab.org/job/openHAB2-Bundles/lastSuccessfulBuild/org.openhab.binding%24org.openhab.binding.zwave/ which will work fine with your 2.4 OH release.

Cheers
Kris

chris · March 5, 2019, 11:25pm

Where are you located?

Where did you buy these devices? Are they both American devices?

plysdyret · March 6, 2019, 6:51am

It never shows up as a thing, so I don’t know how to determine firmware/make/model.

Thanks, I’ll try newer version of the binding.

Mvh.

Torkil

dastrix80 · March 6, 2019, 6:52am

Try the new version first and see how that goes. It should show up as a thing if the inclusion has worked correctly (at least to my knowledge) but may be unknown if the database isnt awarre of it (unlikely)

plysdyret · March 6, 2019, 6:55am

Denmark

I bought the Fibaro from a Danish dealer and the stick from/via Amazon.de. IIRC the stick took something like three weeks to arrive, so I presume it was shipped from China or some such, but could have been USA.

Mvh.

Torkil

plysdyret · March 6, 2019, 7:03am

It’s not entirely clear to me how to do this. I uninstall the stock binding from the UI and drop the snapshot jar in the appropriate folder?

Mvh.

Torkil

dastrix80 · March 6, 2019, 7:39am

Open the karaf console

issue command


bundle:list | grep ZW

Grab the number, should be two or three digits that identifies the bundle. Then issue

bundle:uninstall <number>

Once youe downloaded the snapshot binding , place it into

 /usr/share/openhab2/addons

if you’ve used the apt-get installation method for OH2.

plysdyret · March 6, 2019, 7:46am

Ah, thanks. It looks like I managed to get the snapshot version installed:

openhab> bundle:list | grep ZW
290 x Active   x  80 x 2.5.0.201903042328     x ZWave Binding
openhab>

Didn’t seem to make much of a difference though:


2019-03-06 08:39:01.481 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2019-03-06 08:39:01.484 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:492bd5ec
2019-03-06 08:39:01.486 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
2019-03-06 08:39:01.492 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2019-03-06 08:39:01.493 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2019-03-06 08:39:01.494 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true.
2019-03-06 08:39:01.495 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 19 to queue - size 1
2019-03-06 08:39:01.496 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:39:01.498 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 04 75
2019-03-06 08:39:01.499 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 04 75
2019-03-06 08:39:01.502 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:39:01.502 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:39:01.503 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:39:01.504 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 19: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4
2019-03-06 08:39:01.504 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:39:01.505 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-06 08:39:01.505 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:39:01.505 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:39:01.508 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:39:01.508 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 04 01 00 00 B7
2019-03-06 08:39:01.512 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=4, payload=04 01 00 00
2019-03-06 08:39:01.514 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=4, payload=04 01 00 00
2019-03-06 08:39:01.515 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 19: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4
2019-03-06 08:39:01.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-06 08:39:01.518 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 19: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 4
2019-03-06 08:39:01.519 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 19: (Callback 4)
2019-03-06 08:39:01.520 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-03-06 08:39:01.522 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 19: callback 4
2019-03-06 08:39:01.523 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=4, payload=04 01 00 00
2019-03-06 08:39:01.524 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
2019-03-06 08:39:01.526 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart
2019-03-06 08:39:01.527 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 19: Transaction COMPLETED
2019-03-06 08:39:01.528 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 24ms
2019-03-06 08:39:01.529 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 19: Transaction completed
2019-03-06 08:39:01.530 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:19 DONE
2019-03-06 08:39:01.532 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:39:01.532 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:39:31.484 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:492bd5ec
2019-03-06 08:39:31.485 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeStart
2019-03-06 08:39:31.486 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2019-03-06 08:39:31.488 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 20 to queue - size 1
2019-03-06 08:39:31.489 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:39:31.494 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 05 B0
2019-03-06 08:39:31.495 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 05 B0
2019-03-06 08:39:31.498 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:39:31.499 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 20: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 5
2019-03-06 08:39:31.499 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:39:31.500 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:39:31.502 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:39:31.503 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 20: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 5
2019-03-06 08:39:31.503 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:39:31.509 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:39:31.510 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:39:31.550 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 05 06 00 00 B1
2019-03-06 08:39:31.554 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=5, payload=05 06 00 00
2019-03-06 08:39:31.561 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=5, payload=05 06 00 00
2019-03-06 08:39:31.562 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 20: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 5
2019-03-06 08:39:31.565 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-06 08:39:31.566 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 20: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 5
2019-03-06 08:39:31.567 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 20: (Callback 5)
2019-03-06 08:39:31.568 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-03-06 08:39:31.569 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 20: callback 5
2019-03-06 08:39:31.570 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=5, payload=05 06 00 00
2019-03-06 08:39:31.571 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
2019-03-06 08:39:31.571 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeDone, new event IncludeDone
2019-03-06 08:39:31.573 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2019-03-06 08:39:31.573 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 21 to queue - size 1
2019-03-06 08:39:31.574 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:39:31.575 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2019-03-06 08:39:31.576 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2019-03-06 08:39:31.577 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 20: Advanced to DONE
2019-03-06 08:39:31.578 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 79ms
2019-03-06 08:39:31.579 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 20: Transaction completed
2019-03-06 08:39:31.580 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:20 DONE
2019-03-06 08:39:31.581 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:39:31.582 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:39:31.583 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5
2019-03-06 08:39:31.583 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5
2019-03-06 08:39:31.586 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:39:31.587 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 21: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:39:31.587 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:39:31.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:39:31.590 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:39:31.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 21: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:39:31.592 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:39:31.592 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:39:31.593 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:39:36.588 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 21: Timeout at state WAIT_REQUEST. 3 retries remaining.
2019-03-06 08:39:36.589 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 21: Transaction is current transaction, so clearing!!!!!
2019-03-06 08:39:36.591 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 21: Transaction CANCELLED
2019-03-06 08:39:36.592 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:21 CANCELLED
2019-03-06 08:39:36.596 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:40:12.708 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave inclusion controller finalised

Mvh.

Torkil

dastrix80 · March 6, 2019, 7:49am

Looks like its not including. Factory reset the Sensor. I assume you dont have a thing visible now after the inclusion?

chris · March 6, 2019, 7:55am

As far as I’m aware, the HUSBZB-1 is only available in the USA, so it will not work with devices that are purchased in the EU.

RolfV · March 6, 2019, 7:58am

I have been checking the available resources on this stick as well, and as @chris already mentions, it seems to be only available in the 908 to 916 MHz range, which is a range that is not free to use in Europe, and all other z-wave devices in Europe work at 866 MHz.

plysdyret · March 6, 2019, 8:01am

No thing, no. Did a factory reset and tried again. Still no thing, but seems something happened?

2019-03-06 08:52:45.745 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:492bd5ec
2019-03-06 08:52:45.747 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2019-03-06 08:52:45.749 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:492bd5ec
2019-03-06 08:52:45.750 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
2019-03-06 08:52:45.752 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2019-03-06 08:52:45.753 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2019-03-06 08:52:45.755 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true.
2019-03-06 08:52:45.756 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 22 to queue - size 1
2019-03-06 08:52:45.758 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:52:45.759 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 07 76
2019-03-06 08:52:45.761 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 07 76
2019-03-06 08:52:45.768 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:52:45.768 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:52:45.769 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 22: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 7
2019-03-06 08:52:45.770 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:52:45.772 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 07 01 00 00 B4
2019-03-06 08:52:45.773 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:52:45.774 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 22: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 7
2019-03-06 08:52:45.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:52:45.776 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:52:45.777 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:52:45.780 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=7, payload=07 01 00 00
2019-03-06 08:52:45.781 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=7, payload=07 01 00 00
2019-03-06 08:52:45.782 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 22: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 7
2019-03-06 08:52:45.782 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-06 08:52:45.788 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 22: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 7
2019-03-06 08:52:45.789 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 22: (Callback 7)
2019-03-06 08:52:45.791 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-03-06 08:52:45.791 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 22: callback 7
2019-03-06 08:52:45.792 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=7, payload=07 01 00 00
2019-03-06 08:52:45.793 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
2019-03-06 08:52:45.802 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart
2019-03-06 08:52:45.802 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 22: Transaction COMPLETED
2019-03-06 08:52:45.806 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 37ms
2019-03-06 08:52:45.808 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 22: Transaction completed
2019-03-06 08:52:45.808 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:22 DONE
2019-03-06 08:52:45.810 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:52:45.810 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:53:15.749 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:492bd5ec
2019-03-06 08:53:15.750 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeStart
2019-03-06 08:53:15.751 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2019-03-06 08:53:15.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 23 to queue - size 1
2019-03-06 08:53:15.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:53:15.753 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 08 BD
2019-03-06 08:53:15.753 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 08 BD
2019-03-06 08:53:15.757 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:53:15.758 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:53:15.758 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:53:15.759 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:53:15.760 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 23: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 8
2019-03-06 08:53:15.760 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-06 08:53:15.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:53:15.762 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:53:15.763 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:53:15.809 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 08 06 00 00 BC
2019-03-06 08:53:15.812 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=8, payload=08 06 00 00
2019-03-06 08:53:15.814 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=8, payload=08 06 00 00
2019-03-06 08:53:15.815 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 23: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 8
2019-03-06 08:53:15.817 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-06 08:53:15.818 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 23: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 8
2019-03-06 08:53:15.819 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 23: (Callback 8)
2019-03-06 08:53:15.821 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-03-06 08:53:15.822 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 23: callback 8
2019-03-06 08:53:15.823 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=8, payload=08 06 00 00
2019-03-06 08:53:15.824 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
2019-03-06 08:53:15.825 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeDone, new event IncludeDone
2019-03-06 08:53:15.827 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2019-03-06 08:53:15.827 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 24 to queue - size 1
2019-03-06 08:53:15.829 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:53:15.829 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2019-03-06 08:53:15.830 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2019-03-06 08:53:15.831 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 23: Advanced to DONE
2019-03-06 08:53:15.832 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 73ms
2019-03-06 08:53:15.833 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 23: Transaction completed
2019-03-06 08:53:15.834 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:23 DONE
2019-03-06 08:53:15.835 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:53:15.836 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:53:15.838 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5
2019-03-06 08:53:15.839 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5
2019-03-06 08:53:15.841 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:53:15.843 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:53:15.843 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:53:15.844 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 24: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:53:15.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:53:15.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 24: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:53:15.846 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:53:15.847 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:53:15.847 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:53:20.845 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 24: Timeout at state WAIT_REQUEST. 3 retries remaining.
2019-03-06 08:53:20.847 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 24: Transaction is current transaction, so clearing!!!!!
2019-03-06 08:53:20.848 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 24: Transaction CANCELLED
2019-03-06 08:53:20.849 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:24 CANCELLED
2019-03-06 08:53:20.852 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:53:52.101 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:492bd5ec
2019-03-06 08:54:04.413 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:492bd5ec
2019-03-06 08:54:04.419 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update received
2019-03-06 08:54:04.434 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_softreset to false
2019-03-06 08:54:04.436 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update security_networkkey to B0 3D 46 74 50 4E E6 17 57 E7 89 99 95 5B 2E 91
2019-03-06 08:54:04.438 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update security_inclusionmode to 0
2019-03-06 08:54:04.440 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_sisnode to 1
2019-03-06 08:54:04.441 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_sync to false
2019-03-06 08:54:04.443 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update port to /dev/ttyUSB0
2019-03-06 08:54:04.445 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_master to true
2019-03-06 08:54:04.447 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update inclusion_mode to 2
2019-03-06 08:54:04.448 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_wakeupperiod to 3600
2019-03-06 08:54:04.449 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update heal_time to 2
2019-03-06 08:54:04.450 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 18 hours time.
2019-03-06 08:54:04.451 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_exclude to false
2019-03-06 08:54:04.452 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_inclusiontimeout to 180
2019-03-06 08:54:04.454 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_hardreset to false
2019-03-06 08:54:04.671 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Stopped ZWave thread: Receive
2019-03-06 08:54:07.683 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler
2019-03-06 08:54:07.684 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Deactivate zwave:serial_zstick:492bd5ec
2019-03-06 08:54:07.686 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=415, service.bundleid=290, service.scope=singleton} - org.openhab.binding.zwave
2019-03-06 08:54:07.689 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Interrupted taking message from recvQueue
java.lang.InterruptedException: null
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) ~[?:?]
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2048) ~[?:?]
        at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:403) ~[?:?]
        at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$ZWaveReceiveThread.run(ZWaveTransactionManager.java:427) [290:org.openhab.binding.zwave:2.5.0.201903042328]
2019-03-06 08:54:07.690 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:07.691 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:54:07.688 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.
2019-03-06 08:54:07.693 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:492bd5ec.
2019-03-06 08:54:07.696 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 18 hours time.
2019-03-06 08:54:07.711 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyUSB0'
2019-03-06 08:54:07.735 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Starting receive thread
2019-03-06 08:54:07.736 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2019-03-06 08:54:07.736 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive
2019-03-06 08:54:07.737 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller
2019-03-06 08:54:07.740 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2019-03-06 08:54:07.740 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2019-03-06 08:54:07.741 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:07.743 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:54:07.743 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2019-03-06 08:54:07.744 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - Creating ZWave discovery service for zwave:serial_zstick:492bd5ec with scan time of 180
2019-03-06 08:54:07.745 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Active zwave:serial_zstick:492bd5ec
2019-03-06 08:54:07.748 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.discovery.DiscoveryService}={service.id=416, service.bundleid=290, service.scope=singleton} - org.openhab.binding.zwave
2019-03-06 08:54:10.743 [DEBUG] [.ZWaveController$InitializeDelayTask] - Initialising network
2019-03-06 08:54:10.745 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 25 to queue - size 1
2019-03-06 08:54:10.745 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:54:10.746 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9
2019-03-06 08:54:10.746 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9
2019-03-06 08:54:10.751 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:54:10.751 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:54:10.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 25: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:10.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:10.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-06 08:54:10.753 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:54:10.753 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:10.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:54:10.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 26 to queue - size 1
2019-03-06 08:54:10.755 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:54:10.755 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 27 to queue - size 2
2019-03-06 08:54:10.756 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:54:10.756 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 28 to queue - size 3
2019-03-06 08:54:10.756 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:54:10.756 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID
2019-03-06 08:54:10.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 29 to queue - size 4
2019-03-06 08:54:10.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:54:10.760 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 01 15 5A 2D 57 61 76 65 20 34 2E 30 35 00 01 97
2019-03-06 08:54:10.764 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 34 2E 30 35 00 01
2019-03-06 08:54:10.765 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 34 2E 30 35 00 01
2019-03-06 08:54:10.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 25: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.767 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-06 08:54:10.768 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 25: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.769 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetVersion[21], type=Response[1], dest=255, callback=0, payload=5A 2D 57 61 76 65 20 34 2E 30 35 00 01
2019-03-06 08:54:10.770 [DEBUG] [serialmessage.GetVersionMessageClass] - Got MessageGetVersion response. Version=Z-Wave 4.05, Library Type=1
2019-03-06 08:54:10.771 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 25: Transaction COMPLETED
2019-03-06 08:54:10.772 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 21ms
2019-03-06 08:54:10.773 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 25: Transaction completed
2019-03-06 08:54:10.773 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:25 DONE
2019-03-06 08:54:10.774 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:10.780 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:54:10.784 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC
2019-03-06 08:54:10.786 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC
2019-03-06 08:54:10.790 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:54:10.791 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:10.794 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 01 20 DC E3 CE F7 01 D1
2019-03-06 08:54:10.796 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:54:10.797 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 26: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.799 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:10.805 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=DC E3 CE F7 01
2019-03-06 08:54:10.800 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 26: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.807 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:54:10.809 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=DC E3 CE F7 01
2019-03-06 08:54:10.810 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 26: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.811 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-06 08:54:10.812 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 26: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.814 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=MemoryGetId[32], type=Response[1], dest=255, callback=0, payload=DC E3 CE F7 01
2019-03-06 08:54:10.815 [DEBUG] [erialmessage.MemoryGetIdMessageClass] - Got MessageMemoryGetId response. Home id = 0xdce3cef7, Controller Node id = 1
2019-03-06 08:54:10.816 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 26: Transaction COMPLETED
2019-03-06 08:54:10.817 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 21ms
2019-03-06 08:54:10.819 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 26: Transaction completed
2019-03-06 08:54:10.819 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:26 DONE
2019-03-06 08:54:10.821 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:10.822 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:54:10.823 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB
2019-03-06 08:54:10.823 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB
2019-03-06 08:54:10.826 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:54:10.827 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:10.828 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:54:10.829 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 27: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.832 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 2B 01 07 04 20 00 00 00 01 00 01 FE 81 FF 88 CF 1F 00 00 FB 9F 7D A0 67 00 80 80 00 80 86 00 00 00 E8 73 00 00 0E 00 00 60 00 00 03
2019-03-06 08:54:10.833 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:10.836 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=04 20 00 00 00 01 00 01 FE 81 FF 88 CF 1F 00 00 FB 9F 7D A0 67 00 80 80 00 80 86 00 00 00 E8 73 00 00 0E 00 00 60 00 00
...

Mvh.

Torkil

plysdyret · March 6, 2019, 8:02am

...
2019-03-06 08:54:10.835 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 27: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.837 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:54:10.838 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=04 20 00 00 00 01 00 01 FE 81 FF 88 CF 1F 00 00 FB 9F 7D A0 67 00 80 80 00 80 86 00 00 00 E8 73 00 00 0E 00 00 60 00 00
2019-03-06 08:54:10.839 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 27: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.840 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-06 08:54:10.846 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 27: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.847 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiGetCapabilities[7], type=Response[1], dest=255, callback=0, payload=04 20 00 00 00 01 00 01 FE 81 FF 88 CF 1F 00 00 FB 9F 7D A0 67 00 80 80 00 80 86 00 00 00 E8 73 00 00 0E 00 00 60 00 00
2019-03-06 08:54:10.848 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - API Version    = 4.32
2019-03-06 08:54:10.849 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Manufacture ID = 0x0
2019-03-06 08:54:10.850 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Device Type    = 0x1
2019-03-06 08:54:10.850 [DEBUG] [SerialApiGetCapabilitiesMessageClass] - Device ID      = 0x1
2019-03-06 08:54:10.852 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 27: Transaction COMPLETED
2019-03-06 08:54:10.860 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 30 to queue - size 3
2019-03-06 08:54:10.867 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:54:10.868 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 39ms
2019-03-06 08:54:10.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 27: Transaction completed
2019-03-06 08:54:10.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:27 DONE
2019-03-06 08:54:10.875 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:10.876 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:54:10.877 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65
2019-03-06 08:54:10.878 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65
2019-03-06 08:54:10.881 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:54:10.883 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:10.885 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 01 06 96 0F 64
2019-03-06 08:54:10.886 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:54:10.886 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 28: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.888 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:10.889 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F
2019-03-06 08:54:10.888 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 28: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.891 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:54:10.894 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F
2019-03-06 08:54:10.895 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 28: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.897 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-06 08:54:10.897 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 28: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.899 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiSetTimeouts[6], type=Response[1], dest=255, callback=0, payload=96 0F
2019-03-06 08:54:10.899 [DEBUG] [age.SerialApiSetTimeoutsMessageClass] - Got SerialApiSetTimeouts response. ACK=150, BYTE=15
2019-03-06 08:54:10.901 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 28: Transaction COMPLETED
2019-03-06 08:54:10.901 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 15ms
2019-03-06 08:54:10.902 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 28: Transaction completed
2019-03-06 08:54:10.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:28 DONE
2019-03-06 08:54:10.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:10.905 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:54:10.906 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA
2019-03-06 08:54:10.907 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA
2019-03-06 08:54:10.915 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:54:10.917 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:10.918 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 56 01 AD
2019-03-06 08:54:10.920 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:54:10.921 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 29: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.922 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:10.923 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 29: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:54:10.925 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01
2019-03-06 08:54:10.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:10.926 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:54:10.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01
2019-03-06 08:54:10.928 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 29: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.930 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-06 08:54:10.930 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 29: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.932 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetSucNodeId[86], type=Response[1], dest=255, callback=0, payload=01
2019-03-06 08:54:10.932 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Got SUC NodeID response.
2019-03-06 08:54:10.934 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - NODE 1: Node is SUC.
2019-03-06 08:54:10.934 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 29: Transaction COMPLETED
2019-03-06 08:54:10.935 [DEBUG] [etControllerCapabilitiesMessageClass] - Creating GET_CONTROLLER_CAPABILITIES message
2019-03-06 08:54:10.936 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 31 to queue - size 2
2019-03-06 08:54:10.937 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:54:10.937 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 16ms
2019-03-06 08:54:10.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 29: Transaction completed
2019-03-06 08:54:10.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:29 DONE
2019-03-06 08:54:10.940 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:10.941 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:54:10.942 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 02 FE
2019-03-06 08:54:10.942 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 02 FE
2019-03-06 08:54:10.946 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:54:10.947 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:10.947 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:54:10.949 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 30: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.950 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:10.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 30: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:10.952 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:54:10.953 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:10.954 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:54:11.001 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 25 01 02 05 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00 CD
2019-03-06 08:54:11.004 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=05 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00
2019-03-06 08:54:11.006 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=05 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00
2019-03-06 08:54:11.007 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 30: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:11.008 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-06 08:54:11.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 30: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:11.011 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SerialApiGetInitData[2], type=Response[1], dest=255, callback=0, payload=05 08 1D 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 05 00
2019-03-06 08:54:11.011 [DEBUG] [age.SerialApiGetInitDataMessageClass] - Got MessageSerialApiGetInitData response.
2019-03-06 08:54:11.012 [DEBUG] [age.SerialApiGetInitDataMessageClass] - NODE 1: Node found
2019-03-06 08:54:11.013 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API
2019-03-06 08:54:11.014 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
2019-03-06 08:54:11.015 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------
2019-03-06 08:54:11.016 [DEBUG] [age.SerialApiGetInitDataMessageClass] - # Nodes = 1
2019-03-06 08:54:11.017 [DEBUG] [age.SerialApiGetInitDataMessageClass] - ----------------------------------------------------------------------------
2019-03-06 08:54:11.018 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 30: Transaction COMPLETED
2019-03-06 08:54:11.019 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 70ms
2019-03-06 08:54:11.019 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Init node thread start
2019-03-06 08:54:11.020 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 30: Transaction completed
2019-03-06 08:54:11.021 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:30 DONE
2019-03-06 08:54:11.022 [DEBUG] [ve.internal.protocol.ZWaveController] - Starting waiting for init threads
2019-03-06 08:54:11.024 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_1_init
2019-03-06 08:54:11.034 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:11.035 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:54:11.036 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 05 F9
2019-03-06 08:54:11.037 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 05 F9
2019-03-06 08:54:11.045 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:54:11.045 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:54:11.046 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:11.046 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 31: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:11.047 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 05 3C C3
2019-03-06 08:54:11.048 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:11.050 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:11.050 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=3C
2019-03-06 08:54:11.052 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:54:11.053 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=3C
2019-03-06 08:54:11.054 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 31: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:11.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-06 08:54:11.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 31: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:11.057 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=GetControllerCapabilities[5], type=Response[1], dest=255, callback=0, payload=3C
2019-03-06 08:54:11.058 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is secondary = false
2019-03-06 08:54:11.060 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is on other network = false
2019-03-06 08:54:11.061 [DEBUG] [etControllerCapabilitiesMessageClass] - Node ID Server is present = false
2019-03-06 08:54:11.062 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is real primary = true
2019-03-06 08:54:11.063 [DEBUG] [etControllerCapabilitiesMessageClass] - Controller is SUC = true
2019-03-06 08:54:11.064 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 31: Transaction COMPLETED
2019-03-06 08:54:11.065 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 19ms
2019-03-06 08:54:11.066 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 31: Transaction completed
2019-03-06 08:54:11.067 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:31 DONE
2019-03-06 08:54:11.071 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:11.072 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:54:11.106 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 1: Serializing from file /var/lib/openhab2/zwave/network_dce3cef7__node_1.xml
2019-03-06 08:54:11.111 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave inclusion controller finalised
2019-03-06 08:54:11.127 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Restore from config: Ok.
2019-03-06 08:54:11.128 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2019-03-06 08:54:11.130 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2019-03-06 08:54:11.131 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Starting initialisation from EMPTYNODE
2019-03-06 08:54:11.134 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Init node thread finished
2019-03-06 08:54:11.135 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_1_init complete
2019-03-06 08:54:11.137 [DEBUG] [ve.internal.protocol.ZWaveController] - All init threads complete
2019-03-06 08:54:11.138 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller: Incoming Network State Event true
2019-03-06 08:54:11.155 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to IDENTIFY_NODE
2019-03-06 08:54:11.157 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: Initialisation starting
2019-03-06 08:54:11.158 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@6d89f2b9
2019-03-06 08:54:11.160 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 32 to queue - size 1
2019-03-06 08:54:11.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:54:11.162 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 01 BB
2019-03-06 08:54:11.163 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 01 BB
2019-03-06 08:54:11.165 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:54:11.165 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:54:11.167 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:11.172 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 16 01 02 02 01 73
2019-03-06 08:54:11.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:11.173 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-06 08:54:11.173 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:54:11.173 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:11.166 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 32: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:11.174 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:54:11.176 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01
2019-03-06 08:54:11.177 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01
2019-03-06 08:54:11.178 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 32: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:11.178 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-06 08:54:11.179 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 32: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:54:11.181 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IdentifyNode[65], type=Response[1], dest=255, callback=0, payload=D3 16 01 02 02 01
2019-03-06 08:54:11.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: ProtocolInfo
2019-03-06 08:54:11.182 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Listening = true
2019-03-06 08:54:11.183 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Routing   = true
2019-03-06 08:54:11.183 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Beaming   = true
2019-03-06 08:54:11.184 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Version   = 4
2019-03-06 08:54:11.184 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: FLIRS     = false
2019-03-06 08:54:11.184 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Security  = false
2019-03-06 08:54:11.184 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Max Baud  = 40000
2019-03-06 08:54:11.185 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Basic    = BASIC_TYPE_STATIC_CONTROLLER
2019-03-06 08:54:11.186 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Generic  = GENERIC_TYPE_STATIC_CONTROLLER
2019-03-06 08:54:11.190 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 1: Specific = SPECIFIC_TYPE_PC_CONTROLLER
2019-03-06 08:54:11.191 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_NO_OPERATION
2019-03-06 08:54:11.192 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_NO_OPERATION, endpoint 0 created
2019-03-06 08:54:11.193 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Version = 1, version set. Enabling extra functionality.
2019-03-06 08:54:11.193 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 1: Adding command class COMMAND_CLASS_NO_OPERATION to the list of supported command classes.
2019-03-06 08:54:11.194 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Creating new instance of command class COMMAND_CLASS_BASIC
2019-03-06 08:54:11.196 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 1: Command class COMMAND_CLASS_BASIC, endpoint 0 created
2019-03-06 08:54:11.196 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 1: Adding command class COMMAND_CLASS_BASIC to the list of supported command classes.
2019-03-06 08:54:11.197 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 32: Transaction COMPLETED
2019-03-06 08:54:11.198 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 32ms
2019-03-06 08:54:11.198 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 32: Transaction completed
2019-03-06 08:54:11.199 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:32 DONE
2019-03-06 08:54:11.200 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:11.201 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:54:11.202 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 32: Transaction event listener: DONE: DONE ->
2019-03-06 08:54:11.203 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@677199c9
2019-03-06 08:54:11.203 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node Init transaction completed with response COMPLETE
2019-03-06 08:54:11.204 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer: FAILED_CHECK - Controller - terminating initialisation
2019-03-06 08:54:11.205 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 1: Node advancer - advancing to DONE
2019-03-06 08:54:11.206 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 1: Serializing to file /var/lib/openhab2/zwave/network_dce3cef7__node_1.xml
2019-03-06 08:54:16.726 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:492bd5ec
2019-03-06 08:54:16.727 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2019-03-06 08:54:16.729 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:492bd5ec
2019-03-06 08:54:16.731 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
2019-03-06 08:54:16.741 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2019-03-06 08:54:16.743 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion
2019-03-06 08:54:16.744 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true.
2019-03-06 08:54:16.745 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 33 to queue - size 1
2019-03-06 08:54:16.746 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:54:16.747 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 0A 7B
2019-03-06 08:54:16.748 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 0A 7B
2019-03-06 08:54:16.751 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:54:16.751 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:54:16.753 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:16.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:54:16.754 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 0A 01 00 00 B9
2019-03-06 08:54:16.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-03-06 08:54:16.763 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:54:16.764 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:16.753 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 33: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 10
2019-03-06 08:54:16.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:54:16.767 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=10, payload=0A 01 00 00
2019-03-06 08:54:16.768 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=10, payload=0A 01 00 00
2019-03-06 08:54:16.768 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 33: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 10
2019-03-06 08:54:16.770 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-06 08:54:16.770 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 33: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 10
2019-03-06 08:54:16.771 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 33: (Callback 10)
2019-03-06 08:54:16.772 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-03-06 08:54:16.779 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 33: callback 10
2019-03-06 08:54:16.781 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=10, payload=0A 01 00 00
2019-03-06 08:54:16.781 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
2019-03-06 08:54:16.784 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeSent, new event IncludeStart
2019-03-06 08:54:16.785 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 33: Transaction COMPLETED
2019-03-06 08:54:16.788 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 36ms
2019-03-06 08:54:16.789 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 33: Transaction completed
2019-03-06 08:54:16.790 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:33 DONE
2019-03-06 08:54:16.791 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:54:16.791 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:55:46.745 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion timer at IncludeStart
2019-03-06 08:55:46.747 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2019-03-06 08:55:46.748 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 34 to queue - size 1
2019-03-06 08:55:46.749 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:55:46.749 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 0B BE
2019-03-06 08:55:46.750 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 0B BE
2019-03-06 08:55:46.752 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:55:46.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 34: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 11
2019-03-06 08:55:46.757 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:55:46.758 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:55:46.759 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:55:46.760 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 34: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 11
2019-03-06 08:55:46.760 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:55:46.760 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:55:46.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:55:46.809 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 0B 06 00 00 BF
2019-03-06 08:55:46.811 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=11, payload=0B 06 00 00
2019-03-06 08:55:46.813 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=11, payload=0B 06 00 00
2019-03-06 08:55:46.814 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 34: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 11
2019-03-06 08:55:46.815 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-03-06 08:55:46.817 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 34: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 11
2019-03-06 08:55:46.818 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 34: (Callback 11)
2019-03-06 08:55:46.819 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-03-06 08:55:46.820 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 34: callback 11
2019-03-06 08:55:46.822 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=11, payload=0B 06 00 00
2019-03-06 08:55:46.823 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
2019-03-06 08:55:46.824 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion event: Current state IncludeFail, new event IncludeDone
2019-03-06 08:55:46.825 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2019-03-06 08:55:46.826 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 35 to queue - size 1
2019-03-06 08:55:46.827 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:55:46.828 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller end exclusion
2019-03-06 08:55:46.829 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWaveController include done
2019-03-06 08:55:46.830 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 34: Advanced to DONE
2019-03-06 08:55:46.832 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 78ms
2019-03-06 08:55:46.833 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 34: Transaction completed
2019-03-06 08:55:46.834 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:34 DONE
2019-03-06 08:55:46.835 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:55:46.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:55:46.842 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 00 B5
2019-03-06 08:55:46.843 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 00 B5
2019-03-06 08:55:46.845 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-03-06 08:55:46.845 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-03-06 08:55:46.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:55:46.852 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 35: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:55:46.853 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-03-06 08:55:46.855 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 35: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 0
2019-03-06 08:55:46.856 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-03-06 08:55:46.857 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-03-06 08:55:46.858 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-03-06 08:55:51.854 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 35: Timeout at state WAIT_REQUEST. 3 retries remaining.
2019-03-06 08:55:51.854 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 35: Transaction is current transaction, so clearing!!!!!
2019-03-06 08:55:51.856 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 35: Transaction CANCELLED
2019-03-06 08:55:51.857 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:35 CANCELLED
2019-03-06 08:55:51.858 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-03-06 08:57:16.729 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:492bd5ec
2019-03-06 08:57:16.730 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2019-03-06 08:57:29.215 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave inclusion controller finalised

chris · March 6, 2019, 8:05am

No - there is nothing happening. No devices are detected by the device, and as stated above, this is likely due to the regions/frequencies that the different devices are designed for.

plysdyret · March 6, 2019, 8:13am

Thanks. I’ve contacted the seller on Amazon to verify and will try to get a refund.

Would you guys happen to have a recommendation on what I should buy instead?

Mvh.

Torkil

dastrix80 · March 6, 2019, 8:13am

I was looking at the Device! not the stick
Buy an Aeotec ZStick

chris · March 6, 2019, 8:38am

Most sticks are the same - they use the same chipset. The Aeotec is a popular one, but really, there’s limited difference between them.

Just be sure to get a European one