Hello,
after a hard reset of my zwave controller (to clear old data) the existing things are not found by the controller. In the logfile I see that there is a trial to search existing things, but they are not found.
2018-02-27 18:09:34.069 [DEBUG] [age.SerialApiGetInitDataMessageClass] - Got MessageSerialApiGetInitData response.
2018-02-27 18:09:34.071 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 1: Node found
2018-02-27 18:09:34.073 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API
2018-02-27 18:09:34.074 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
2018-02-27 18:09:34.076 [INFO ] [age.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------
2018-02-27 18:09:34.077 [INFO ] [age.SerialApiGetInitDataMessageClass] - # Nodes = 1
2018-02-27 18:09:34.079 [INFO ] [age.SerialApiGetInitDataMessageClass] - ----------------------------------------------------------------------------
2018-02-27 18:09:34.081 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=GetRoutingInfo[0x80], type=Request[0x00], priority=High, dest=255, callback=0, payload=01 00 00 03
2018-02-27 18:09:34.084 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SerialApiGetInitData[0x02], type=Response[0x01], priority=High, dest=255, callback=0, payload=05 00 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
2018-02-27 18:09:34.086 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SerialApiGetInitData, callback id=0, expected=GetRoutingInfo, cancelled=false MISMATCH
2018-02-27 18:09:34.087 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInitializationStateEvent
2018-02-27 18:09:34.090 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 1: Init node thread start
2018-02-27 18:09:34.090 [DEBUG] [ve.internal.protocol.ZWaveController] - Waiting for init thread Node_1_init
2018-02-27 18:09:34.092 [WARN ] [ve.internal.protocol.ZWaveController] - NODE 1: Attempting to add node that already exists
2018-02-27 18:09:34.100 [DEBUG] [ve.internal.protocol.ZWaveController] - Init thread Node_1_init complete
2018-02-27 18:09:34.101 [DEBUG] [ve.internal.protocol.ZWaveController] - All init threads complete
2018-02-27 18:09:34.102 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNetworkStateEvent
2018-02-27 18:09:34.104 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller: Incoming Network State Event true
2018-02-27 18:09:38.952 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Timeout while sending message. Requeueing - 0 attempts left!
2018-02-27 18:09:38.953 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 2. Queue={}
2018-02-27 18:09:38.954 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 1
2018-02-27 18:09:38.956 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 02 FE
2018-02-27 18:09:38.957 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 02 FE
2018-02-27 18:09:39.060 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 25 01 02 05 00 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 C5
2018-02-27 18:09:39.066 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-02-27 18:09:39.069 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 25 01 02 05 00 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 C5
The existing things are listed with
2018-02-27 18:09:24.282 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Controller is ONLINE. Starting device initialisation.
2018-02-27 18:09:24.282 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Controller status changed to ONLINE.
2018-02-27 18:09:24.278 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Controller status changed to ONLINE.
2018-02-27 18:09:24.283 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Controller is ONLINE. Starting device initialisation.
2018-02-27 18:09:24.284 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Controller status changed to ONLINE.
2018-02-27 18:09:24.285 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Controller is ONLINE. Starting device initialisation.
2018-02-27 18:09:24.285 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Controller is ONLINE. Starting device initialisation.
==> /var/log/openhab2/events.log <==
2018-02-27 18:09:24.292 [hingStatusInfoChangedEvent] - 'zwave:device:72a0a799:node12' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2018-02-27 18:09:24.297 [hingStatusInfoChangedEvent] - 'zwave:device:72a0a799:node13' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2018-02-27 18:09:24.305 [hingStatusInfoChangedEvent] - 'zwave:device:72a0a799:node14' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2018-02-27 18:09:24.312 [hingStatusInfoChangedEvent] - 'zwave:device:72a0a799:node8' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
2018-02-27 18:09:24.321 [hingStatusInfoChangedEvent] - 'zwave:device:72a0a799:node3' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE: Node not found in Z-Wave network
I already did:
-
Hard Reset zwave controller
-
Soft Reset zwave controller
-
Deleted Thing ‘zwave controller’ and added again and USB device re-assigned (sometimes ACM0 or ACM1)
-
Restarted openhab2
-
Excluded a Motion Sensor (one of my things), reset it to factory defaults and tried to include it again … it is not appearing in the inbox
I would like to get some hints what I can do to get the existing things again found by the serial controller … From my understanding a hard or soft reset of the zwave controller shall not kill the zwave system …
Many thanks! Siggi
-
Platform information:
- openhab2 2.3.0-SNAPSHOT Build #1220 (things are added via PaperUI, items are added via items file)
- Raspbian GNU/Linux 9 (stretch), 1 GB memory, 29 GB root
events.180227.pdf (422.6 KB)
openhab1.180227.pdf (857.7 KB)
openhab2.180227.pdf (810.4 KB)
-
usb info from RasPi:
[17:35:29] openhabian@openhabianpi:~$ lsusb
Bus 001 Device 029: ID 0658:0200 Sigma Designs, Inc.
Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp. SMSC9512/9514 Fast Ethernet Adapter
Bus 001 Device 002: ID 0424:9514 Standard Microsystems Corp. SMC9514 Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
[18:22:32] openhabian@openhabianpi:~$ dmesg |grep acm
[ 4.246178] cdc_acm 1-1.5:1.0: ttyACM0: USB ACM device
[ 4.247124] usbcore: registered new interface driver cdc_acm
[ 4.247131] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[521528.857143] cdc_acm 1-1.5:1.0: ttyACM0: USB ACM device
[521691.619160] cdc_acm 1-1.5:1.0: ttyACM0: USB ACM device
[522955.286004] cdc_acm 1-1.5:1.0: ttyACM0: USB ACM device
[523385.882082] cdc_acm 1-1.5:1.0: ttyACM0: USB ACM device
[523483.613901] cdc_acm 1-1.5:1.0: ttyACM1: USB ACM device
[524485.853908] cdc_acm 1-1.5:1.0: ttyACM0: USB ACM device
[526557.927269] cdc_acm 1-1.5:1.0: ttyACM1: USB ACM device
[533305.383636] cdc_acm 1-1.5:1.0: ttyACM0: USB ACM device
[536861.981963] cdc_acm 1-1.5:1.0: ttyACM0: USB ACM device
[536867.091827] cdc_acm 1-1.5:1.0: ttyACM1: USB ACM device
[18:22:59] openhabian@openhabianpi:~$