OH upgrade, ZWave not working

bdm · August 10, 2020, 6:45am

I’ve recently upgraded my openhabian setup (updated background raspbian via openhabian-config first, then upgraded openhab also via the interface) from 2.54 to 2.57 to be able to access the iCalendar binding.
Unfortunately, my zwave controller went off line.
I tried deleting and installing the thing in paperui, no dice

changing the port back and forth in paperui
cleared the cache
reset the pi
going back into openhabian-config and re-applying the razzberry fixes
deleting and re-installing the z-wave binding
again toggling the zwave port (this used to fix issues for me, so I do it intermittently - not that it’s solved anything in years).

When I look at my logs, I can see zwave ‘chatter’, but the zwave controller shows up as “Offline - Bridge Offline”. Needless to say, there isn’t any control of any of the zwave devices.

Logs, filtered for ‘zwave’:

2020-08-09 23:35:06.721 [thome.event.ExtensionEvent] - Extension 'binding-zwave' has been uninstalled.

2020-08-09 23:35:10.779 [INFO ] [internal.service.FeaturesServiceImpl] - Adding features: openhab-binding-zwave/[2.5.7,2.5.7]

2020-08-09 23:35:15.742 [INFO ] [internal.service.FeaturesServiceImpl] -       mvn:org.openhab.addons.bundles/org.openhab.binding.zwave/[2.5.0,2.6)

2020-08-09 23:35:15.792 [INFO ] [internal.service.FeaturesServiceImpl] -   mvn:org.openhab.addons.bundles/org.openhab.binding.zwave/[2.5.0,2.6)

2020-08-09 23:35:16.329 [INFO ] [internal.service.FeaturesServiceImpl] -   org.openhab.binding.zwave/2.5.7

2020-08-09 23:35:16.602 [thome.event.ExtensionEvent] - Extension 'binding-zwave' has been installed.

2020-08-09 23:35:21.223 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node3' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.227 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node2' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.235 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node19' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.237 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node14' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.238 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node13' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.239 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node12' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.243 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node11' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.245 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node18' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.246 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node17' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.249 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node16' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.252 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node15' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.254 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node32' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.255 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node31' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.255 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null

2020-08-09 23:35:21.256 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node30' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.258 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node35' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.259 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node34' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.260 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node33' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.261 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node20' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.263 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node9' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.264 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node5' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.265 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node4' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.267 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node7' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.269 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node6' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.271 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node24' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.272 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node29' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.273 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node28' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.275 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node27' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-09 23:35:21.426 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:a204e4d4' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:35:21.439 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:a204e4d4' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.569 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node2' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.578 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node2' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.589 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node19' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.600 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node13' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.602 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node14' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.605 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node3' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.614 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node12' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.620 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node19' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.625 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node14' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.632 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node12' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.637 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node13' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.641 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node3' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.648 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node18' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.655 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node18' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.658 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node11' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.665 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node15' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.672 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node17' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.674 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node32' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.676 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node16' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.679 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node11' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.694 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node15' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.697 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node16' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.708 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node17' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.712 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node32' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.714 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node31' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.719 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node31' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.727 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node34' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.729 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node33' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.732 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node35' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.738 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node30' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.741 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node20' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.742 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node33' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.752 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node34' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.767 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node30' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.772 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node20' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.775 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node9' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.778 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node5' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.781 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node35' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.784 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node7' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.792 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node6' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.798 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node5' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.803 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node9' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.815 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node4' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.817 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node29' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.825 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node6' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.828 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node7' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.831 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node4' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.834 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node28' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.836 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node27' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.839 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node29' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.847 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node24' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-09 23:35:21.851 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node28' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.858 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node27' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:21.864 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node24' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:35:26.495 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 40 to 0

2020-08-09 23:35:26.499 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_ack changed from 10 to 0

2020-08-09 23:35:26.504 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from 14 to 0

2020-08-09 23:35:26.506 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 78 to 0

2020-08-09 23:35:26.509 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_cse changed from 2 to 0

2020-08-09 23:35:26.518 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

2020-08-09 23:35:26.519 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

2020-08-09 23:35:29.562 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 0 to 1

2020-08-09 23:35:31.060 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 0 to 1

2020-08-09 23:35:31.068 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 1 to 2

2020-08-09 23:35:31.070 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 2 to 3

2020-08-09 23:35:31.072 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 3 to 4

2020-08-09 23:35:31.073 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 4 to 5

2020-08-09 23:35:31.074 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 5 to 6

2020-08-09 23:35:31.080 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 1 to 2

2020-08-09 23:35:31.126 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_ack changed from 0 to 1

2020-08-09 23:35:33.144 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_ack changed from 1 to 2

2020-08-09 23:35:33.151 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 6 to 7

2020-08-09 23:35:33.156 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 7 to 8

2020-08-09 23:35:33.158 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 8 to 9

2020-08-09 23:35:33.167 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 9 to 10

2020-08-09 23:35:33.169 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 10 to 11

2020-08-09 23:35:33.170 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 11 to 12

2020-08-09 23:35:34.644 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 2 to 3

2020-08-09 23:35:34.656 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_cse changed from 0 to 1

2020-08-09 23:35:35.192 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_ack changed from 2 to 3

2020-08-09 23:35:37.004 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_ack changed from 3 to 4

2020-08-09 23:35:37.216 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_ack changed from 4 to 5

2020-08-09 23:35:37.218 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 12 to 13

2020-08-09 23:35:37.219 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 3 to 4

2020-08-09 23:35:38.714 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 13 to 14

2020-08-09 23:35:38.716 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 4 to 5

2020-08-09 23:36:07.018 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_ack changed from 5 to 6

2020-08-09 23:36:07.443 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from 0 to 1

2020-08-09 23:36:11.515 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 5 to 6

2020-08-09 23:36:43.029 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 6 to 7

2020-08-09 23:36:46.027 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 7 to 8

2020-08-09 23:36:49.026 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 8 to 9

2020-08-09 23:36:50.527 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 14 to 15

2020-08-09 23:36:50.531 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 15 to 16

2020-08-09 23:36:52.030 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 16 to 17

2020-08-09 23:36:52.034 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 17 to 18

2020-08-09 23:36:52.036 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 18 to 19

2020-08-09 23:36:52.037 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 19 to 20

2020-08-09 23:36:53.533 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 20 to 21

2020-08-09 23:36:53.536 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 21 to 22

2020-08-09 23:36:53.541 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 22 to 23

2020-08-09 23:36:53.543 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 23 to 24

2020-08-09 23:36:53.546 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 24 to 25

2020-08-09 23:36:53.548 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 25 to 26

2020-08-09 23:36:53.549 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 9 to 10

2020-08-09 23:36:53.580 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 27: Not initialized (ie node unknown), ignoring message.

2020-08-09 23:37:00.493 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 26 to 27

2020-08-09 23:37:03.486 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 10 to 11

2020-08-09 23:37:06.486 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 11 to 12

2020-08-09 23:37:07.261 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from 1 to 2

2020-08-09 23:37:07.987 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 27 to 28

2020-08-09 23:37:09.491 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 28 to 29

2020-08-09 23:37:09.498 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 29 to 30

2020-08-09 23:37:09.501 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 30 to 31

2020-08-09 23:37:09.504 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 31 to 32

2020-08-09 23:37:10.987 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 32 to 33

2020-08-09 23:37:10.994 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 33 to 34

2020-08-09 23:37:11.007 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 34 to 35

2020-08-09 23:37:11.010 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 35 to 36

2020-08-09 23:37:13.987 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 12 to 13

2020-08-09 23:37:16.986 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 13 to 14

2020-08-09 23:37:18.490 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 36 to 37

2020-08-09 23:37:18.496 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 37 to 38

2020-08-09 23:37:18.498 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 38 to 39

2020-08-09 23:37:18.501 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 39 to 40

2020-08-09 23:37:19.989 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 40 to 41

2020-08-09 23:37:19.992 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 41 to 42

2020-08-09 23:37:19.994 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 42 to 43

2020-08-09 23:37:21.492 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 43 to 44

2020-08-09 23:37:21.494 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 44 to 45

2020-08-09 23:37:25.992 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 45 to 46

2020-08-09 23:37:25.994 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 14 to 15

2020-08-09 23:37:28.997 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 46 to 47

2020-08-09 23:37:29.000 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 47 to 48

2020-08-09 23:37:29.002 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 48 to 49

2020-08-09 23:37:29.004 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 49 to 50

2020-08-09 23:37:30.490 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 50 to 51

2020-08-09 23:37:30.504 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 51 to 52

2020-08-09 23:37:30.507 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 52 to 53

2020-08-09 23:37:30.509 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 53 to 54

2020-08-09 23:37:31.988 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 54 to 55

2020-08-09 23:37:33.486 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 55 to 56

2020-08-09 23:37:36.487 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 15 to 16

2020-08-09 23:37:38.190 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from 2 to 3

2020-08-09 23:37:38.606 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from 3 to 4

2020-08-09 23:37:38.808 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from 4 to 5

2020-08-09 23:37:39.485 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from 5 to 6

2020-08-09 23:37:40.989 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 56 to 57

2020-08-09 23:37:40.998 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 57 to 58

2020-08-09 23:37:41.000 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 58 to 59

2020-08-09 23:37:42.492 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 59 to 60

2020-08-09 23:37:42.495 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 60 to 61

2020-08-09 23:37:43.990 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 61 to 62

2020-08-09 23:37:45.488 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 62 to 63

2020-08-09 23:37:45.493 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 63 to 64

2020-08-09 23:37:45.495 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 64 to 65

2020-08-09 23:37:45.497 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 65 to 66

2020-08-09 23:37:48.488 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 16 to 17

2020-08-09 23:37:51.496 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 66 to 67

2020-08-09 23:37:51.507 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 67 to 68

2020-08-09 23:37:51.509 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 68 to 69

2020-08-09 23:37:51.512 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 69 to 70

2020-08-09 23:37:51.514 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 17 to 18

2020-08-09 23:37:51.531 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 27: Not initialized (ie node unknown), ignoring message.

2020-08-09 23:38:07.070 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 18 to 19

2020-08-09 23:38:10.068 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 19 to 20

2020-08-09 23:38:27.239 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_ack changed from 6 to 7

2020-08-09 23:38:28.736 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 20 to 21

2020-08-09 23:38:31.738 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 21 to 22

2020-08-09 23:38:37.283 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from 6 to 7

2020-08-09 23:38:38.576 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 70 to 71

2020-08-09 23:38:40.066 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 22 to 23

2020-08-09 23:39:07.295 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from 7 to 8

2020-08-09 23:39:08.781 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from 8 to 9

2020-08-09 23:39:37.088 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_ack changed from 7 to 8

2020-08-09 23:39:49.503 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 23 to 24

2020-08-09 23:39:50.997 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 24 to 25

2020-08-09 23:39:53.999 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 25 to 26

2020-08-09 23:39:55.503 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 71 to 72

2020-08-09 23:39:55.505 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 26 to 27

2020-08-09 23:39:56.998 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 72 to 73

2020-08-09 23:39:58.495 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 73 to 74

2020-08-09 23:40:00.000 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 74 to 75

2020-08-09 23:40:01.506 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 75 to 76

2020-08-09 23:40:01.511 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 76 to 77

2020-08-09 23:40:01.514 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 77 to 78

2020-08-09 23:40:02.999 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 78 to 79

2020-08-09 23:40:04.497 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 79 to 80

2020-08-09 23:40:07.100 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 27 to 28

2020-08-09 23:40:10.096 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 28 to 29

2020-08-09 23:40:19.686 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 29 to 30

2020-08-09 23:40:22.681 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 30 to 31

2020-08-09 23:40:22.710 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 29: Not initialized (ie node unknown), ignoring message.

and a snip after removing and re-adding the z-wave controller thing:

2020-08-09 23:55:37.602 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null

==> /var/log/openhab2/events.log <==

2020-08-09 23:55:37.618 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:a204e4d4' changed from UNINITIALIZED to INITIALIZING

2020-08-09 23:55:37.633 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:a204e4d4' has been updated.

2020-08-09 23:55:37.636 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:a204e4d4' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.644 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node3' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.673 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node3' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.676 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node2' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.679 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node19' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.684 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node14' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.689 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node12' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.692 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node13' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.695 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node19' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.699 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node2' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.701 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from NULL to 34

2020-08-09 23:55:37.704 [.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_a204e4d4_serial_sof-zwave:serial_zstick:a204e4d4:serial_sof' has been added.

2020-08-09 23:55:37.707 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node18' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.711 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node13' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.715 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node17' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.717 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node11' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.720 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_ack changed from NULL to 1

2020-08-09 23:55:37.722 [.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_a204e4d4_serial_ack-zwave:serial_zstick:a204e4d4:serial_ack' has been added.

2020-08-09 23:55:37.732 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node18' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.744 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node14' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.762 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node12' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.769 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node11' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.828 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node15' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.832 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node16' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.835 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node17' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.838 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_nak changed from NULL to 0

2020-08-09 23:55:37.841 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node32' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.843 [.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_a204e4d4_serial_nak-zwave:serial_zstick:a204e4d4:serial_nak' has been added.

2020-08-09 23:55:37.846 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node31' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.849 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node30' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.853 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node16' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.856 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from NULL to 5

2020-08-09 23:55:37.859 [.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_a204e4d4_serial_can-zwave:serial_zstick:a204e4d4:serial_can' has been added.

2020-08-09 23:55:37.870 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node35' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.877 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node30' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.883 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node15' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.890 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node32' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.894 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node33' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.897 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node34' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.903 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node35' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.907 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from NULL to 95

2020-08-09 23:55:37.909 [.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_a204e4d4_serial_oof-zwave:serial_zstick:a204e4d4:serial_oof' has been added.

2020-08-09 23:55:37.911 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node20' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.914 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node9' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.926 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node33' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.935 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node31' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.937 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node4' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.960 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node5' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.961 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node34' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.970 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node9' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.973 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node20' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.977 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node4' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.978 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node24' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.980 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node7' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.989 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node5' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:37.991 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node6' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.992 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node29' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:37.997 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node28' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:38.001 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_cse changed from NULL to 3

2020-08-09 23:55:38.003 [.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_a204e4d4_serial_cse-zwave:serial_zstick:a204e4d4:serial_cse' has been added.

2020-08-09 23:55:38.035 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node24' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:38.044 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node6' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:38.050 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node29' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:38.053 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node7' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:38.055 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node28' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:38.057 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node27' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-09 23:55:38.061 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node27' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-09 23:55:38.675 [vent.ItemStateChangedEvent] - systeminfo_computer_openhab_memory_availablePercent changed from 82.5 to 82.4

==> /var/log/openhab2/openhab.log <==

2020-08-09 23:55:38.677 [DEBUG] [.internal.InfluxDBPersistenceService] - got DecimalType value 82.4

2020-08-09 23:55:42.663 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

==> /var/log/openhab2/events.log <==

2020-08-09 23:55:42.666 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 34 to 0

==> /var/log/openhab2/openhab.log <==

2020-08-09 23:55:42.666 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

==> /var/log/openhab2/events.log <==

2020-08-09 23:55:42.672 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_ack changed from 1 to 0

==> /var/log/openhab2/openhab.log <==

2020-08-09 23:55:42.672 [DEBUG] [.internal.InfluxDBPersistenceService] - got DecimalType value 0

2020-08-09 23:55:42.682 [DEBUG] [.internal.InfluxDBPersistenceService] - got DecimalType value 0

2020-08-09 23:55:42.688 [DEBUG] [.internal.InfluxDBPersistenceService] - got DecimalType value 0

==> /var/log/openhab2/events.log <==

2020-08-09 23:55:42.688 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from 5 to 0

==> /var/log/openhab2/openhab.log <==

2020-08-09 23:55:42.697 [DEBUG] [.internal.InfluxDBPersistenceService] - got DecimalType value 0

==> /var/log/openhab2/events.log <==

2020-08-09 23:55:42.702 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 95 to 0

==> /var/log/openhab2/openhab.log <==

2020-08-09 23:55:42.705 [DEBUG] [.internal.InfluxDBPersistenceService] - got DecimalType value 0

==> /var/log/openhab2/events.log <==

2020-08-09 23:55:42.708 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_cse changed from 3 to 0

==> /var/log/openhab2/openhab.log <==

2020-08-09 23:55:44.196 [DEBUG] [.internal.InfluxDBPersistenceService] - got DecimalType value 2

==> /var/log/openhab2/events.log <==

2020-08-09 23:55:44.200 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 0 to 1

Thanks for any further direction/ideas you may have.

Raspberry pi 4b rev 1.1, 4gb
openhabian 2.57
razzbery hat

chris · August 10, 2020, 7:51am

Can you put the binding into debug mode? This is described in the binding documentation and it will help you see what is happening, and hopefully why. Currently these logs are at too high a level to really see why the controller isn’t starting up.

bdm · August 10, 2020, 7:41pm

Thanks Chris,
I’ve set the logging to debug, then restarted the binding

(for the benefit of those following along, enter the console, then set the debug level)

sudo openhab-cli console
log:set DEBUG org.openhab.binding.zwave

and for my lazy eyes, I sent a log message immediately before resetting the binding:

log:log ResettingBinding

then reset the binding

bundle:restart org.openhab.binding.zwave

This message appeared in the logs at: 2020-08-10 11:54:26.272

I then captured the logs from the web interface that runs the tail command.

Using your filter from the new opensmarthouse website, the filtered logs are:

And the raw logs are heavily edited to make them fit the size limits:


==> /var/log/openhab2/events.log <==

2020-08-10 11:54:26.104 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 44 to 45

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:26.272 [INFO ] [org.apache.karaf.log.core           ] - ResettingBinding

[snip]

2020-08-10 11:54:28.530 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Handler disposed. Unregistering listener.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:28.542 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node15' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2020-08-10 11:54:28.544 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node9' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to UNINITIALIZED

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:28.556 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Handler disposed. Unregistering listener.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:28.567 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node9' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2020-08-10 11:54:28.569 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node3' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to UNINITIALIZED

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:28.580 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Handler disposed. Unregistering listener.

[snip - etc, same string of messages for unregistering the listeners for all the other nodes]

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:29.091 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node12' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2020-08-10 11:54:29.093 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:a204e4d4' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to UNINITIALIZED

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:29.102 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 45 to 46

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:29.103 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Disposing receive thread

2020-08-10 11:54:29.346 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Timeout - Sending NAK

2020-08-10 11:54:29.347 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Stopped ZWave thread: Receive

2020-08-10 11:54:29.348 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Receive thread dispose

2020-08-10 11:54:29.349 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Disposing serial connection

2020-08-10 11:54:29.398 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial connection disposed

2020-08-10 11:54:29.399 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler

2020-08-10 11:54:29.400 [DEBUG] [ve.internal.protocol.ZWaveController] - Shutting down ZWave controller

2020-08-10 11:54:29.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Shutting down transaction manager

2020-08-10 11:54:29.404 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Exiting ZWave Receive Thread

2020-08-10 11:54:29.405 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction manager shutdown

2020-08-10 11:54:29.407 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller shutdown

2020-08-10 11:54:29.411 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Deactivate zwave:serial_zstick:a204e4d4

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:29.416 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:a204e4d4' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2020-08-10 11:54:31.840 [vent.ItemStateChangedEvent] - systeminfo_computer_openhab_memory_availablePercent changed from 80.4 to 80.3

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:33.854 [vent.ItemStateChangedEvent] - systeminfo_computer_openhab_memory_availablePercent changed from 80.3 to 80.2

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.247 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node3' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-10 11:54:34.251 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node2' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-10 11:54:34.255 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node19' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.257 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - Creating ZWave discovery service for zwave:serial_zstick:a204e4d4 with scan time of 60

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.258 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node14' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-10 11:54:34.260 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node13' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-10 11:54:34.262 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node12' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.262 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Active zwave:serial_zstick:a204e4d4

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.264 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node11' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.267 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.267 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node18' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-10 11:54:34.272 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node17' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-10 11:54:34.276 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node16' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-10 11:54:34.278 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node15' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to UNINITIALIZED (BRIDGE_UNINITIALIZED)

2020-08-10 11:54:34.334 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:a204e4d4' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.343 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.

2020-08-10 11:54:34.344 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:a204e4d4.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.347 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:a204e4d4' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-10 11:54:34.412 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node14' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-10 11:54:34.414 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node2' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-10 11:54:34.421 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node13' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-10 11:54:34.423 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node32' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-10 11:54:34.431 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node19' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.437 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node14.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.441 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node14' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.443 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node13.

2020-08-10 11:54:34.446 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node32.

2020-08-10 11:54:34.455 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Channel zwave:device:a204e4d4:node14:lock_door linked - polling started.

2020-08-10 11:54:34.456 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node2.

2020-08-10 11:54:34.464 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node3.

2020-08-10 11:54:34.467 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Channel zwave:device:a204e4d4:node14:alarm_raw linked - polling started.

2020-08-10 11:54:34.468 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Channel zwave:device:a204e4d4:node14:battery-level linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.468 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node3' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-10 11:54:34.469 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node13' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.471 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Channel zwave:device:a204e4d4:node13:lock_door linked - polling started.

2020-08-10 11:54:34.471 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Channel zwave:device:a204e4d4:node13:alarm_raw linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.472 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node32' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.472 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Channel zwave:device:a204e4d4:node13:battery-level linked - polling started.

2020-08-10 11:54:34.474 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 32: Channel zwave:device:a204e4d4:node32:switch_binary linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.474 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node12' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-10 11:54:34.476 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node2' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.479 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:a204e4d4:node2:switch_binary linked - polling started.

2020-08-10 11:54:34.479 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:a204e4d4:node2:scene_number linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.479 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node3' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.480 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node19.

2020-08-10 11:54:34.492 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:meter_watts linked - polling started.

2020-08-10 11:54:34.492 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:switch_dimmer linked - polling started.

2020-08-10 11:54:34.493 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:meter_kwh linked - polling started.

2020-08-10 11:54:34.493 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:meter_reset linked - polling started.

2020-08-10 11:54:34.494 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:scene_number linked - polling started.

2020-08-10 11:54:34.495 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:config_decimal_param16 linked - polling started.

2020-08-10 11:54:34.495 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:config_decimal_param9 linked - polling started.

2020-08-10 11:54:34.496 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:config_decimal_param13 linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.498 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node19' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.508 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Channel zwave:device:a204e4d4:node19:switch_binary linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.508 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node11' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-10 11:54:34.509 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node18' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.513 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node12.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.518 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node12' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.520 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Channel zwave:device:a204e4d4:node12:lock_door linked - polling started.

2020-08-10 11:54:34.520 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Channel zwave:device:a204e4d4:node12:alarm_raw linked - polling started.

2020-08-10 11:54:34.520 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Channel zwave:device:a204e4d4:node12:battery-level linked - polling started.

2020-08-10 11:54:34.529 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node11.

2020-08-10 11:54:34.532 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node18.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.535 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node11' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.538 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Channel zwave:device:a204e4d4:node11:lock_door linked - polling started.

2020-08-10 11:54:34.539 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Channel zwave:device:a204e4d4:node11:alarm_raw linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.541 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node18' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.541 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Channel zwave:device:a204e4d4:node11:battery-level linked - polling started.

2020-08-10 11:54:34.545 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Channel zwave:device:a204e4d4:node18:switch_binary linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.555 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node16' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

2020-08-10 11:54:34.563 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node31' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-10 11:54:34.569 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node17' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.571 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node16.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.574 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node16' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.578 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 16: Channel zwave:device:a204e4d4:node16:lock_door linked - polling started.

2020-08-10 11:54:34.581 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 16: Channel zwave:device:a204e4d4:node16:alarm_raw linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.583 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node15' changed from UNINITIALIZED (BRIDGE_UNINITIALIZED) to INITIALIZING

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.583 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 16: Channel zwave:device:a204e4d4:node16:battery-level linked - polling started.

2020-08-10 11:54:34.589 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node31.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.591 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node30' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-10 11:54:34.593 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node35' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-10 11:54:34.596 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node31' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.598 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 31: Channel zwave:device:a204e4d4:node31:sensor_temperature linked - polling started.

2020-08-10 11:54:34.598 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node15.

2020-08-10 11:54:34.599 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 31: Channel zwave:device:a204e4d4:node31:sensor_relhumidity linked - polling started.

2020-08-10 11:54:34.604 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 31: Channel zwave:device:a204e4d4:node31:sensor_luminance linked - polling started.

2020-08-10 11:54:34.606 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 31: Channel zwave:device:a204e4d4:node31:alarm_burglar linked - polling started.

2020-08-10 11:54:34.604 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node17.

2020-08-10 11:54:34.610 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 31: Channel zwave:device:a204e4d4:node31:alarm_motion linked - polling started.

2020-08-10 11:54:34.614 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 31: Channel zwave:device:a204e4d4:node31:battery-level linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.614 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node15' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.621 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Channel zwave:device:a204e4d4:node15:switch_binary linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.621 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node17' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.630 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node35.

2020-08-10 11:54:34.633 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Channel zwave:device:a204e4d4:node17:switch_binary linked - polling started.

2020-08-10 11:54:34.635 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node33.

2020-08-10 11:54:34.636 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Channel zwave:device:a204e4d4:node17:scene_number linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.638 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node33' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-10 11:54:34.641 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node34' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-10 11:54:34.643 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node35' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.644 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node30.

2020-08-10 11:54:34.648 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 35: Channel zwave:device:a204e4d4:node35:switch_binary linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.651 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node33' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.659 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 33: Channel zwave:device:a204e4d4:node33:switch_binary linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.659 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node30' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.661 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Channel zwave:device:a204e4d4:node30:sensor_relhumidity linked - polling started.

2020-08-10 11:54:34.664 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Channel zwave:device:a204e4d4:node30:sensor_luminance linked - polling started.

2020-08-10 11:54:34.667 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node34.

2020-08-10 11:54:34.668 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Channel zwave:device:a204e4d4:node30:sensor_temperature linked - polling started.

2020-08-10 11:54:34.670 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Channel zwave:device:a204e4d4:node30:alarm_motion linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.670 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node20' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.671 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Channel zwave:device:a204e4d4:node30:battery-level linked - polling started.

2020-08-10 11:54:34.670 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Channel zwave:device:a204e4d4:node30:alarm_tamper linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.672 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node34' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.675 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 34: Channel zwave:device:a204e4d4:node34:switch_binary linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.679 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node4' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-10 11:54:34.684 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node9' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-10 11:54:34.686 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node7' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-10 11:54:34.688 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node5' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.698 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node20.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.700 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node20' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.702 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 20: Channel zwave:device:a204e4d4:node20:switch_dimmer linked - polling started.

2020-08-10 11:54:34.711 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node9.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.714 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node9' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.716 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Channel zwave:device:a204e4d4:node9:switch_binary linked - polling started.

2020-08-10 11:54:34.716 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Channel zwave:device:a204e4d4:node9:scene_number linked - polling started.

2020-08-10 11:54:34.717 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node7.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.719 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node6' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-10 11:54:34.721 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node7' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.721 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node5.

2020-08-10 11:54:34.723 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Channel zwave:device:a204e4d4:node7:switch_binary linked - polling started.

2020-08-10 11:54:34.727 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node4.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.793 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node5' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

2020-08-10 11:54:34.798 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node29' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.797 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Channel zwave:device:a204e4d4:node5:switch_binary linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.799 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node4' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.803 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Channel zwave:device:a204e4d4:node4:switch_binary linked - polling started.

2020-08-10 11:54:34.803 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node6.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.809 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node6' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.810 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node29.

2020-08-10 11:54:34.810 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Channel zwave:device:a204e4d4:node6:lock_door linked - polling started.

2020-08-10 11:54:34.814 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Channel zwave:device:a204e4d4:node6:alarm_raw linked - polling started.

2020-08-10 11:54:34.815 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Channel zwave:device:a204e4d4:node6:battery-level linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.817 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node28' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-10 11:54:34.820 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node24' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

2020-08-10 11:54:34.821 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node29' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.824 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Channel zwave:device:a204e4d4:node29:sensor_luminance linked - polling started.

2020-08-10 11:54:34.824 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Channel zwave:device:a204e4d4:node29:sensor_relhumidity linked - polling started.

2020-08-10 11:54:34.825 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Channel zwave:device:a204e4d4:node29:alarm_motion linked - polling started.

2020-08-10 11:54:34.825 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Channel zwave:device:a204e4d4:node29:sensor_temperature linked - polling started.

2020-08-10 11:54:34.827 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Channel zwave:device:a204e4d4:node29:alarm_tamper linked - polling started.

2020-08-10 11:54:34.830 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Channel zwave:device:a204e4d4:node29:battery-level linked - polling started.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.832 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node27' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.839 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node28.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.844 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node28' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.846 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 28: Channel zwave:device:a204e4d4:node28:switch_binary linked - polling started.

2020-08-10 11:54:34.844 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node27.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.852 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node27' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.853 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Channel zwave:device:a204e4d4:node27:sensor_relhumidity linked - polling started.

2020-08-10 11:54:34.854 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Channel zwave:device:a204e4d4:node27:sensor_luminance linked - polling started.

2020-08-10 11:54:34.856 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Channel zwave:device:a204e4d4:node27:alarm_tamper linked - polling started.

2020-08-10 11:54:34.856 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Channel zwave:device:a204e4d4:node27:alarm_motion linked - polling started.

2020-08-10 11:54:34.855 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Channel zwave:device:a204e4d4:node27:sensor_temperature linked - polling started.

2020-08-10 11:54:34.857 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Channel zwave:device:a204e4d4:node27:battery-level linked - polling started.

2020-08-10 11:54:34.865 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node24.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:34.873 [hingStatusInfoChangedEvent] - 'zwave:device:a204e4d4:node24' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:34.876 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Channel zwave:device:a204e4d4:node24:basic_sensor_binary linked - polling started.

2020-08-10 11:54:34.876 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Channel zwave:device:a204e4d4:node24:sensor_luminance linked - polling started.

2020-08-10 11:54:34.878 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Channel zwave:device:a204e4d4:node24:sensor_relhumidity linked - polling started.

2020-08-10 11:54:34.880 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Channel zwave:device:a204e4d4:node24:alarm_motion linked - polling started.

2020-08-10 11:54:34.880 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Channel zwave:device:a204e4d4:node24:battery-level linked - polling started.

2020-08-10 11:54:34.880 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Channel zwave:device:a204e4d4:node24:sensor_temperature linked - polling started.

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:39.354 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyAMA0'

2020-08-10 11:54:39.363 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Starting receive thread

2020-08-10 11:54:39.366 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive

2020-08-10 11:54:39.366 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized

2020-08-10 11:54:39.370 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:39.374 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 46 to 0

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:39.384 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

2020-08-10 11:54:39.384 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2020-08-10 11:54:39.386 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

2020-08-10 11:54:39.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:39.396 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_ack changed from 8 to 0

2020-08-10 11:54:39.398 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from 7 to 0

2020-08-10 11:54:39.400 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 32 to 0

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:39.401 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_cse changed from 2 to 0

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:39.406 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

2020-08-10 11:54:39.413 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

2020-08-10 11:54:39.415 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 15 hours time.

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:41.936 [vent.ItemStateChangedEvent] - systeminfo_computer_openhab_memory_availablePercent changed from 80.1 to 79.9

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:42.406 [DEBUG] [.ZWaveController$InitializeDelayTask] - Initialising network

2020-08-10 11:54:42.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 15 to queue - size 1

2020-08-10 11:54:42.411 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-08-10 11:54:42.412 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 

2020-08-10 11:54:42.414 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 

2020-08-10 11:54:42.418 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06

2020-08-10 11:54:42.419 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2020-08-10 11:54:42.420 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Frame length is out of limits (146)

2020-08-10 11:54:42.421 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2020-08-10 11:54:42.422 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2020-08-10 11:54:42.424 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

2020-08-10 11:54:42.425 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:42.426 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_ack changed from 0 to 1

2020-08-10 11:54:42.431 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 0 to 1

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:42.445 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-08-10 11:54:42.446 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 15: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-08-10 11:54:42.448 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-08-10 11:54:42.449 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 16 to queue - size 1

2020-08-10 11:54:42.450 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-08-10 11:54:42.451 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 17 to queue - size 2

2020-08-10 11:54:42.452 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-08-10 11:54:42.453 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 18 to queue - size 3

2020-08-10 11:54:42.454 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-08-10 11:54:42.455 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID

2020-08-10 11:54:42.456 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 19 to queue - size 4

2020-08-10 11:54:42.457 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-08-10 11:54:42.675 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Timeout - Sending NAK

2020-08-10 11:54:43.917 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Frame length is out of limits (146)

==> /var/log/openhab2/events.log <==

2020-08-10 11:54:43.921 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 1 to 2

==> /var/log/openhab2/openhab.log <==

2020-08-10 11:54:44.170 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Timeout - Sending NAK

2020-08-10 11:54:44.448 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 15: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-08-10 11:54:44.450 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 15: Transaction is current transaction, so clearing!!!!!

2020-08-10 11:54:44.452 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 15: Transaction CANCELLED

2020-08-10 11:54:44.455 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:15 CANCELLED

2020-08-10 11:54:44.456 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-08-10 11:54:44.464 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC 

2020-08-10 11:54:44.466 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC 

2020-08-10 11:54:44.495 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-08-10 11:54:44.496 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 16: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-08-10 11:54:45.417 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 15

2020-08-10 11:54:45.418 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=

2020-08-10 11:54:45.425 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=

2020-08-10 11:54:45.426 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 16: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-08-10 11:54:45.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Holdoff Timer started...

2020-08-10 11:54:45.431 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 16: Resetting transaction

I am particularly wondering if the below lines have some significance:

2020-08-10 11:47:26.220 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null

2020-08-10 11:47:26.221 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2020-08-10 11:47:26.222 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-08-10 11:47:26.399 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Protocol error (OOF). Got 0xA7.

2020-08-10 11:47:26.402 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Protocol error (OOF). Got 0xD1.

I’m sorry if this is too much of a dump, but I tried to filter down, yet keep apparently relevant information.

Thanks for your insight!

bdm · August 12, 2020, 9:43pm

One additional thought, did java dependencies change with the new zwave bundle? During the upgrade process from openabian-config, a pop-up box mentioned that the new version of java was not tested with openhab, and I opted to NOT update it (as I believed was the suggestion)

My current java version is: openjdk version 1.8.0_222

Will this be a problem? Is anyone running the newer version of openjdk on openhabian in an otherwise vanilla zwave/mqtt installation successfully?

Thanks

bdm · August 12, 2020, 10:45pm

Finally, after a reboot, the relevant section of openhab.log shows:

2020-08-12 14:49:35.123 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Active zwave:serial_zstick:a204e4d4
2020-08-12 14:49:35.125 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null
2020-08-12 14:49:35.278 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Initializing ZWave serial controller.
2020-08-12 14:49:35.283 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initializing ZWave Controller zwave:serial_zstick:a204e4d4.
2020-08-12 14:49:35.347 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node32.
2020-08-12 14:49:35.353 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 32: Channel zwave:device:a204e4d4:node32:switch_binary linked - polling started.
2020-08-12 14:49:35.404 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node31.
2020-08-12 14:49:35.408 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 31: Channel zwave:device:a204e4d4:node31:sensor_temperature linked - polling started.
2020-08-12 14:49:35.412 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 31: Channel zwave:device:a204e4d4:node31:sensor_luminance linked - polling started.
2020-08-12 14:49:35.412 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 31: Channel zwave:device:a204e4d4:node31:sensor_relhumidity linked - polling started.
2020-08-12 14:49:35.414 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 31: Channel zwave:device:a204e4d4:node31:alarm_burglar linked - polling started.
2020-08-12 14:49:35.416 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 31: Channel zwave:device:a204e4d4:node31:alarm_motion linked - polling started.
2020-08-12 14:49:35.418 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 31: Channel zwave:device:a204e4d4:node31:battery-level linked - polling started.
2020-08-12 14:49:35.453 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node30.
2020-08-12 14:49:35.460 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Channel zwave:device:a204e4d4:node30:sensor_relhumidity linked - polling started.
2020-08-12 14:49:35.460 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Channel zwave:device:a204e4d4:node30:sensor_luminance linked - polling started.
2020-08-12 14:49:35.463 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Channel zwave:device:a204e4d4:node30:sensor_temperature linked - polling started.
2020-08-12 14:49:35.463 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Channel zwave:device:a204e4d4:node30:alarm_motion linked - polling started.
2020-08-12 14:49:35.463 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Channel zwave:device:a204e4d4:node30:battery-level linked - polling started.
2020-08-12 14:49:35.463 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 30: Channel zwave:device:a204e4d4:node30:alarm_tamper linked - polling started.
2020-08-12 14:49:35.475 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node35.
2020-08-12 14:49:35.483 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 35: Channel zwave:device:a204e4d4:node35:switch_binary linked - polling started.
2020-08-12 14:49:35.496 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node34.
2020-08-12 14:49:35.502 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 34: Channel zwave:device:a204e4d4:node34:switch_binary linked - polling started.
2020-08-12 14:49:35.515 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node33.
2020-08-12 14:49:35.519 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 33: Channel zwave:device:a204e4d4:node33:switch_binary linked - polling started.
2020-08-12 14:49:35.542 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node20.
2020-08-12 14:49:35.547 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 20: Channel zwave:device:a204e4d4:node20:switch_dimmer linked - polling started.
2020-08-12 14:49:35.573 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node9.
2020-08-12 14:49:35.578 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Channel zwave:device:a204e4d4:node9:scene_number linked - polling started.
2020-08-12 14:49:35.578 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Channel zwave:device:a204e4d4:node9:switch_binary linked - polling started.
2020-08-12 14:49:35.592 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node5.
2020-08-12 14:49:35.597 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Channel zwave:device:a204e4d4:node5:switch_binary linked - polling started.
2020-08-12 14:49:35.613 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node4.
2020-08-12 14:49:35.618 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Channel zwave:device:a204e4d4:node4:switch_binary linked - polling started.
2020-08-12 14:49:35.634 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node7.
2020-08-12 14:49:35.639 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Channel zwave:device:a204e4d4:node7:switch_binary linked - polling started.
2020-08-12 14:49:35.678 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node6.
2020-08-12 14:49:35.685 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Channel zwave:device:a204e4d4:node6:alarm_raw linked - polling started.
2020-08-12 14:49:35.685 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Channel zwave:device:a204e4d4:node6:lock_door linked - polling started.
2020-08-12 14:49:35.685 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Channel zwave:device:a204e4d4:node6:battery-level linked - polling started.
2020-08-12 14:49:35.718 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node24.
2020-08-12 14:49:35.724 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Channel zwave:device:a204e4d4:node24:basic_sensor_binary linked - polling started.
2020-08-12 14:49:35.729 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Channel zwave:device:a204e4d4:node24:sensor_relhumidity linked - polling started.
2020-08-12 14:49:35.729 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Channel zwave:device:a204e4d4:node24:sensor_luminance linked - polling started.
2020-08-12 14:49:35.730 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Channel zwave:device:a204e4d4:node24:battery-level linked - polling started.
2020-08-12 14:49:35.730 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Channel zwave:device:a204e4d4:node24:alarm_motion linked - polling started.
2020-08-12 14:49:35.732 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 24: Channel zwave:device:a204e4d4:node24:sensor_temperature linked - polling started.
2020-08-12 14:49:35.746 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node29.
2020-08-12 14:49:35.750 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Channel zwave:device:a204e4d4:node29:sensor_relhumidity linked - polling started.
2020-08-12 14:49:35.751 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Channel zwave:device:a204e4d4:node29:sensor_luminance linked - polling started.
2020-08-12 14:49:35.753 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Channel zwave:device:a204e4d4:node29:sensor_temperature linked - polling started.
2020-08-12 14:49:35.755 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Channel zwave:device:a204e4d4:node29:alarm_motion linked - polling started.
2020-08-12 14:49:35.756 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Channel zwave:device:a204e4d4:node29:alarm_tamper linked - polling started.
2020-08-12 14:49:35.758 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 29: Channel zwave:device:a204e4d4:node29:battery-level linked - polling started.
2020-08-12 14:49:35.768 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node28.
2020-08-12 14:49:35.772 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 28: Channel zwave:device:a204e4d4:node28:switch_binary linked - polling started.
2020-08-12 14:49:35.789 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node27.
2020-08-12 14:49:35.800 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Channel zwave:device:a204e4d4:node27:sensor_relhumidity linked - polling started.
2020-08-12 14:49:35.803 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Channel zwave:device:a204e4d4:node27:sensor_luminance linked - polling started.
2020-08-12 14:49:35.810 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Channel zwave:device:a204e4d4:node27:sensor_temperature linked - polling started.
2020-08-12 14:49:35.829 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Channel zwave:device:a204e4d4:node27:alarm_motion linked - polling started.
2020-08-12 14:49:35.832 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Channel zwave:device:a204e4d4:node27:alarm_tamper linked - polling started.
2020-08-12 14:49:35.832 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Channel zwave:device:a204e4d4:node27:battery-level linked - polling started.
2020-08-12 14:49:35.846 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node2.
2020-08-12 14:49:35.936 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:a204e4d4:node2:scene_number linked - polling started.
2020-08-12 14:49:35.936 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:a204e4d4:node2:switch_binary linked - polling started.
2020-08-12 14:49:35.947 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node13.
2020-08-12 14:49:35.949 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node19.
2020-08-12 14:49:35.950 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node14.
2020-08-12 14:49:35.962 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node3.
2020-08-12 14:49:35.969 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Channel zwave:device:a204e4d4:node13:lock_door linked - polling started.
2020-08-12 14:49:35.976 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Channel zwave:device:a204e4d4:node13:battery-level linked - polling started.
2020-08-12 14:49:35.978 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node12.
2020-08-12 14:49:35.980 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Channel zwave:device:a204e4d4:node14:battery-level linked - polling started.
2020-08-12 14:49:35.980 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Channel zwave:device:a204e4d4:node14:alarm_raw linked - polling started.
2020-08-12 14:49:35.979 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 14: Channel zwave:device:a204e4d4:node14:lock_door linked - polling started.
2020-08-12 14:49:35.972 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 13: Channel zwave:device:a204e4d4:node13:alarm_raw linked - polling started.
2020-08-12 14:49:35.997 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node11.
2020-08-12 14:49:35.998 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 19: Channel zwave:device:a204e4d4:node19:switch_binary linked - polling started.
2020-08-12 14:49:36.004 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node16.
2020-08-12 14:49:36.012 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:meter_watts linked - polling started.
2020-08-12 14:49:36.012 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:switch_dimmer linked - polling started.
2020-08-12 14:49:36.013 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:meter_kwh linked - polling started.
2020-08-12 14:49:36.014 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:meter_reset linked - polling started.
2020-08-12 14:49:36.015 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:scene_number linked - polling started.
2020-08-12 14:49:36.017 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:config_decimal_param16 linked - polling started.
2020-08-12 14:49:36.018 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:config_decimal_param9 linked - polling started.
2020-08-12 14:49:36.019 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Channel zwave:device:a204e4d4:node3:config_decimal_param13 linked - polling started.
2020-08-12 14:49:36.021 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Channel zwave:device:a204e4d4:node12:lock_door linked - polling started.
2020-08-12 14:49:36.022 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Channel zwave:device:a204e4d4:node12:alarm_raw linked - polling started.
2020-08-12 14:49:36.022 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 12: Channel zwave:device:a204e4d4:node12:battery-level linked - polling started.
2020-08-12 14:49:36.026 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Channel zwave:device:a204e4d4:node11:lock_door linked - polling started.
2020-08-12 14:49:36.026 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Channel zwave:device:a204e4d4:node11:alarm_raw linked - polling started.
2020-08-12 14:49:36.030 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node18.
2020-08-12 14:49:36.032 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Channel zwave:device:a204e4d4:node11:battery-level linked - polling started.
2020-08-12 14:49:36.034 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 16: Channel zwave:device:a204e4d4:node16:lock_door linked - polling started.
2020-08-12 14:49:36.040 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 16: Channel zwave:device:a204e4d4:node16:alarm_raw linked - polling started.
2020-08-12 14:49:36.042 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 16: Channel zwave:device:a204e4d4:node16:battery-level linked - polling started.
2020-08-12 14:49:36.044 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node15.
2020-08-12 14:49:36.047 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Channel zwave:device:a204e4d4:node18:switch_binary linked - polling started.
2020-08-12 14:49:36.051 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Channel zwave:device:a204e4d4:node15:switch_binary linked - polling started.
2020-08-12 14:49:36.060 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:a204e4d4:node17.
2020-08-12 14:49:36.064 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Channel zwave:device:a204e4d4:node17:scene_number linked - polling started.
2020-08-12 14:49:36.064 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 17: Channel zwave:device:a204e4d4:node17:switch_binary linked - polling started.
2020-08-12 14:49:40.302 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyAMA0'
2020-08-12 14:49:40.333 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Starting receive thread
2020-08-12 14:49:40.342 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive
2020-08-12 14:49:40.345 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2020-08-12 14:49:40.347 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller
2020-08-12 14:49:40.392 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2020-08-12 14:49:40.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-08-12 14:49:40.393 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2020-08-12 14:49:40.394 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-08-12 14:49:40.396 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2020-08-12 14:49:40.401 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2020-08-12 14:49:40.404 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 12 hours time.
2020-08-12 14:49:43.395 [DEBUG] [.ZWaveController$InitializeDelayTask] - Initialising network
2020-08-12 14:49:43.425 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 0 to queue - size 1
2020-08-12 14:49:43.426 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-08-12 14:49:43.435 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 
2020-08-12 14:49:43.437 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 
2020-08-12 14:49:43.444 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-08-12 14:49:43.446 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-08-12 14:49:43.459 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-08-12 14:49:43.461 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-08-12 14:49:43.462 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-08-12 14:49:43.464 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-08-12 14:49:43.472 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-08-12 14:49:43.474 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 0: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0
2020-08-12 14:49:43.478 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-08-12 14:49:43.532 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 1 to queue - size 1
2020-08-12 14:49:43.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-08-12 14:49:43.541 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 2 to queue - size 2
2020-08-12 14:49:43.543 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-08-12 14:49:43.553 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 3 to queue - size 3
2020-08-12 14:49:43.554 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-08-12 14:49:43.559 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID
2020-08-12 14:49:43.560 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 4 to queue - size 4
2020-08-12 14:49:43.561 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-08-12 14:49:44.135 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.ui.basic_2.5.7 [282]] to http service

bdm · August 13, 2020, 12:45am

Setting TRACE-level logging for a binding restart, there seem to be timeout events around " 2020-08-12 17:35:14.877 " below.

==> /var/log/openhab2/openhab.log <==

2020-08-12 17:35:05.260 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyAMA0'

2020-08-12 17:35:05.268 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Starting receive thread

2020-08-12 17:35:05.271 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Starting ZWave thread: Receive

2020-08-12 17:35:05.271 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized

2020-08-12 17:35:05.272 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Initialising ZWave controller

2020-08-12 17:35:05.275 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller

2020-08-12 17:35:05.277 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

2020-08-12 17:35:05.281 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2020-08-12 17:35:05.282 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-08-12 17:35:05.283 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 21

==> /var/log/openhab2/events.log <==

2020-08-12 17:35:05.286 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 745 to 0

==> /var/log/openhab2/openhab.log <==

2020-08-12 17:35:05.292 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing

==> /var/log/openhab2/events.log <==

2020-08-12 17:35:05.293 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_ack changed from 174 to 0

2020-08-12 17:35:05.294 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_nak changed from 1 to 0

2020-08-12 17:35:05.296 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from 151 to 0

==> /var/log/openhab2/openhab.log <==

2020-08-12 17:35:05.298 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

==> /var/log/openhab2/events.log <==

2020-08-12 17:35:05.297 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_oof changed from 481 to 0

==> /var/log/openhab2/openhab.log <==

2020-08-12 17:35:05.305 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

2020-08-12 17:35:05.307 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Scheduling network mesh heal for 9 hours time.

==> /var/log/openhab2/events.log <==

2020-08-12 17:35:05.301 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_cse changed from 6 to 0

==> /var/log/openhab2/openhab.log <==

2020-08-12 17:35:08.298 [DEBUG] [.ZWaveController$InitializeDelayTask] - Initialising network

2020-08-12 17:35:08.303 [TRACE] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to controller queue

2020-08-12 17:35:08.304 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 7 to queue - size 1

2020-08-12 17:35:08.306 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-08-12 17:35:08.307 [TRACE] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6

2020-08-12 17:35:08.309 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating empty message of class = GetVersion (0x15), type = Request

2020-08-12 17:35:08.311 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = -23

2020-08-12 17:35:08.313 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 15 E9 

2020-08-12 17:35:08.316 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 15 E9 

2020-08-12 17:35:08.322 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06

2020-08-12 17:35:08.324 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 06 

==> /var/log/openhab2/events.log <==

2020-08-12 17:35:08.327 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_ack changed from 0 to 1

==> /var/log/openhab2/openhab.log <==

2020-08-12 17:35:08.327 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2020-08-12 17:35:08.331 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=

2020-08-12 17:35:08.333 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2020-08-12 17:35:08.335 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK

2020-08-12 17:35:08.337 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2020-08-12 17:35:08.342 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-08-12 17:35:08.344 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 7: Transaction Start type GetVersion 

2020-08-12 17:35:08.346 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-08-12 17:35:08.347 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null

2020-08-12 17:35:08.350 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null

2020-08-12 17:35:08.351 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1

2020-08-12 17:35:08.354 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:10 PDT 2020 - 2000ms

2020-08-12 17:35:08.355 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 7: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-08-12 17:35:08.357 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:08.359 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:10 PDT 2020 - 1994ms

2020-08-12 17:35:08.361 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-08-12 17:35:08.363 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...

2020-08-12 17:35:08.365 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:08.367 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:10 PDT 2020 - 1986ms

2020-08-12 17:35:08.369 [TRACE] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to controller queue

2020-08-12 17:35:08.371 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 8 to queue - size 1

2020-08-12 17:35:08.372 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-08-12 17:35:08.374 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...

2020-08-12 17:35:08.375 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:08.377 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:10 PDT 2020 - 1976ms

2020-08-12 17:35:08.378 [TRACE] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to controller queue

2020-08-12 17:35:08.380 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 9 to queue - size 2

2020-08-12 17:35:08.381 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-08-12 17:35:08.382 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...

2020-08-12 17:35:08.384 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:08.385 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:10 PDT 2020 - 1968ms

2020-08-12 17:35:08.387 [TRACE] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to controller queue

2020-08-12 17:35:08.388 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 10 to queue - size 3

2020-08-12 17:35:08.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-08-12 17:35:08.391 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...

2020-08-12 17:35:08.392 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:08.394 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:10 PDT 2020 - 1959ms

2020-08-12 17:35:08.396 [DEBUG] [rialmessage.GetSucNodeIdMessageClass] - Get SUC NodeID

2020-08-12 17:35:08.398 [TRACE] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to controller queue

2020-08-12 17:35:08.399 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 11 to queue - size 4

2020-08-12 17:35:08.400 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-08-12 17:35:08.401 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...

2020-08-12 17:35:08.402 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:08.403 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:10 PDT 2020 - 1950ms

2020-08-12 17:35:10.353 [TRACE] [sactionManager$ZWaveTransactionTimer] - Transaction Timeout.......... 1 outstanding transactions

2020-08-12 17:35:10.356 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 7: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-08-12 17:35:10.357 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 7: Transaction is current transaction, so clearing!!!!!

2020-08-12 17:35:10.360 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 7: Transaction CANCELLED

2020-08-12 17:35:10.361 [TRACE] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent

2020-08-12 17:35:10.364 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:7 CANCELLED

2020-08-12 17:35:10.366 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-08-12 17:35:10.370 [TRACE] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6

2020-08-12 17:35:10.372 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating empty message of class = MemoryGetId (0x20), type = Request

2020-08-12 17:35:10.374 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = -36

2020-08-12 17:35:10.376 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 20 DC 

2020-08-12 17:35:10.380 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 20 DC 

2020-08-12 17:35:10.383 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF

==> /var/log/openhab2/events.log <==

2020-08-12 17:35:10.390 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_sof changed from 0 to 1

==> /var/log/openhab2/openhab.log <==

2020-08-12 17:35:10.402 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-08-12 17:35:10.404 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 8: Transaction Start type MemoryGetId 

2020-08-12 17:35:10.407 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 8: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-08-12 17:35:10.410 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null

2020-08-12 17:35:10.411 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null

2020-08-12 17:35:10.414 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1

2020-08-12 17:35:10.416 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:10.418 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:12 PDT 2020 - 1997ms

2020-08-12 17:35:10.420 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 8: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-08-12 17:35:10.423 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:10.424 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:12 PDT 2020 - 1991ms

2020-08-12 17:35:10.637 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Timeout - Sending NAK

2020-08-12 17:35:12.415 [TRACE] [sactionManager$ZWaveTransactionTimer] - Transaction Timeout.......... 1 outstanding transactions

2020-08-12 17:35:12.418 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 8: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-08-12 17:35:12.420 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 8: Transaction is current transaction, so clearing!!!!!

2020-08-12 17:35:12.422 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 8: Transaction CANCELLED

2020-08-12 17:35:12.424 [TRACE] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent

2020-08-12 17:35:12.427 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:8 CANCELLED

2020-08-12 17:35:12.429 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-08-12 17:35:12.433 [TRACE] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6

2020-08-12 17:35:12.434 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating empty message of class = SerialApiGetCapabilities (0x7), type = Request

2020-08-12 17:35:12.435 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = -5

2020-08-12 17:35:12.437 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 07 FB 

2020-08-12 17:35:12.439 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 07 FB 

2020-08-12 17:35:12.443 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 18

2020-08-12 17:35:12.444 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 18 

2020-08-12 17:35:12.446 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=

==> /var/log/openhab2/events.log <==

2020-08-12 17:35:12.447 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from 0 to 1

==> /var/log/openhab2/openhab.log <==

2020-08-12 17:35:12.449 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=

2020-08-12 17:35:12.451 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2020-08-12 17:35:12.454 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2020-08-12 17:35:12.462 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-08-12 17:35:12.464 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 9: Transaction Start type SerialApiGetCapabilities 

2020-08-12 17:35:12.466 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 9: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-08-12 17:35:12.467 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null

2020-08-12 17:35:12.470 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null

2020-08-12 17:35:12.471 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1

2020-08-12 17:35:12.473 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:12.474 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:14 PDT 2020 - 1999ms

2020-08-12 17:35:12.476 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 9: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-08-12 17:35:12.477 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:12.480 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:14 PDT 2020 - 1994ms

2020-08-12 17:35:12.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-08-12 17:35:12.483 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...

2020-08-12 17:35:12.485 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:12.487 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:14 PDT 2020 - 1986ms

2020-08-12 17:35:14.473 [TRACE] [sactionManager$ZWaveTransactionTimer] - Transaction Timeout.......... 1 outstanding transactions

2020-08-12 17:35:14.475 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 9: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-08-12 17:35:14.476 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 9: Transaction is current transaction, so clearing!!!!!

2020-08-12 17:35:14.478 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 9: Transaction CANCELLED

2020-08-12 17:35:14.479 [TRACE] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent

2020-08-12 17:35:14.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:9 CANCELLED

2020-08-12 17:35:14.487 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-08-12 17:35:14.490 [TRACE] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6

2020-08-12 17:35:14.491 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating empty message of class = SerialApiSetTimeouts (0x6), type = Request

2020-08-12 17:35:14.494 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 101

2020-08-12 17:35:14.496 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 06 96 0F 65 

2020-08-12 17:35:14.498 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 06 96 0F 65 

2020-08-12 17:35:14.502 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 18

2020-08-12 17:35:14.506 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 18 

2020-08-12 17:35:14.508 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=

2020-08-12 17:35:14.510 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=CAN[4], dest=255, callback=0, payload=

==> /var/log/openhab2/events.log <==

2020-08-12 17:35:14.510 [vent.ItemStateChangedEvent] - zwave_serial_zstick_a204e4d4_serial_can changed from 1 to 2

==> /var/log/openhab2/openhab.log <==

2020-08-12 17:35:14.511 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2020-08-12 17:35:14.513 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2020-08-12 17:35:14.522 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-08-12 17:35:14.524 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 10: Transaction Start type SerialApiSetTimeouts 

2020-08-12 17:35:14.526 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 10: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-08-12 17:35:14.527 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null

2020-08-12 17:35:14.528 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null

2020-08-12 17:35:14.529 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1

2020-08-12 17:35:14.531 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:14.532 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:16 PDT 2020 - 1998ms

2020-08-12 17:35:14.534 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 10: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-08-12 17:35:14.535 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:14.536 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:16 PDT 2020 - 1994ms

2020-08-12 17:35:14.538 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

2020-08-12 17:35:14.539 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...

2020-08-12 17:35:14.540 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:14.542 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:16 PDT 2020 - 1989ms

==> /var/log/openhab2/events.log <==

2020-08-12 17:35:14.578 [vent.ItemStateChangedEvent] - systeminfo_computer_openhab_memory_availablePercent changed from 80.1 to 79.9

==> /var/log/openhab2/openhab.log <==

2020-08-12 17:35:14.877 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Protocol error (OOF). Got 0x36.

2020-08-12 17:35:16.530 [TRACE] [sactionManager$ZWaveTransactionTimer] - Transaction Timeout.......... 1 outstanding transactions

2020-08-12 17:35:16.531 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 10: Timeout at state WAIT_RESPONSE. 3 retries remaining.

2020-08-12 17:35:16.533 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 10: Transaction is current transaction, so clearing!!!!!

2020-08-12 17:35:16.535 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 10: Transaction CANCELLED

2020-08-12 17:35:16.536 [TRACE] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent

2020-08-12 17:35:16.538 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:10 CANCELLED

2020-08-12 17:35:16.543 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

2020-08-12 17:35:16.545 [TRACE] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6

2020-08-12 17:35:16.546 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating empty message of class = GetSucNodeId (0x56), type = Request

2020-08-12 17:35:16.547 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = -86

2020-08-12 17:35:16.549 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 56 AA 

2020-08-12 17:35:16.551 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 56 AA 

2020-08-12 17:35:16.592 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT

2020-08-12 17:35:16.593 [TRACE] [e.internal.protocol.ZWaveTransaction] - TID 11: Transaction Start type GetSucNodeId 

2020-08-12 17:35:16.594 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 11: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-08-12 17:35:16.595 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null

2020-08-12 17:35:16.597 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null

2020-08-12 17:35:16.598 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1

2020-08-12 17:35:16.599 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:16.600 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:18 PDT 2020 - 1999ms

2020-08-12 17:35:16.602 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 11: [WAIT_RESPONSE] priority=Controller, requiresResponse=true, callback: 0

2020-08-12 17:35:16.603 [TRACE] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer

2020-08-12 17:35:16.604 [TRACE] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Aug 12 17:35:18 PDT 2020 - 1995ms

2020-08-12 17:35:18.045 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF

I’ll try to withhold from spaming my log files futher at this point. Please let me know if there is something specific I should try target.

Bruce_Osborne · August 13, 2020, 9:01am

The log viewer may help but it takes debug logs at recommended in the binding documentation.

bdm · August 17, 2020, 5:57pm

Hi Bruce,
I had run my previous logs through Chris’ new website zwave log viewer, included in the images above. Unfortunately, it doesn’t mean a whole lot to me. I put a bigger version of what I had posted most recently into the viewer, and didn’t have anything particular jump out at me, but then I also don’t really understand how to read it / didn’t seem to get anything useful. I then moved on to a trace level log, resulting in the section that I posted, which I feel may be pertinent.

Given that it seems nobody else is running into this, I am wondering if it is due to me not updating java somehow. Does anyone know if the java dependencies of the zwave module changed?
Thanks

bdm · August 17, 2020, 7:00pm

Gah!
I have it sorted. In the system update, my installed z-way-server (used for razberry hat z-way setting backups, and potentially device firmware upgrades in the future) updated as well.
It appears that I needed to re-disable the z-way-server after an upgrade! (and also fix a signature for the z-way repository)