Hi Openhab-ers…
I’ve been up and running for a while now with zwave for my lights, it was all working fine until a few days ago (nothing changed), then I started getting a constant stream of zwave CAN errors and now nearly all my zwave nodes have gone grey or red in HABmin and have stopped responding. I’ve installed the latest 1.9.0 snapshot zwave binding and everything else is 1.8.3 - these errors were happening when I was on 1.8.2 but upgrading has not helped anything. Running on Ubuntu 14.04. Aeon Labs Z-stick Gen 5.I hope someone can help please…
Log:
2016-06-21 19:26:44.457 [INFO ] [.o.core.internal.CoreActivator] - openHAB runtime has been started (v1.8.3).
2016-06-21 19:26:45.305 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl] - mDNS service has been started
2016-06-21 19:26:45.338 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl] - Service Discovery initialization completed.
2016-06-21 19:26:45.343 [INFO ] [.io.transport.mqtt.MqttService] - MQTT Service initialization completed.
2016-06-21 19:26:45.343 [INFO ] [o.i.t.m.i.MqttBrokerConnection] - Starting MQTT broker connection 'mymosquitto’
2016-06-21 19:26:47.143 [INFO ] [penhab.io.rest.RESTApplication] - Started REST API at /rest
2016-06-21 19:26:55.044 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'reynolds.sitemap’
2016-06-21 19:26:55.204 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'myopenhab.persist’
2016-06-21 19:26:55.216 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'exec.persist’
2016-06-21 19:26:55.251 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'reynolds.items’
2016-06-21 19:26:55.358 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'presence.items’
2016-06-21 19:26:55.613 [INFO ] [.o.u.w.i.servlet.WebAppServlet] - Started Classic UI at /classicui/openhab.app
2016-06-21 19:26:59.129 [INFO ] [.service.AbstractActiveService] - Sonos Refresh Service has been started
2016-06-21 19:26:59.255 [INFO ] [.b.sonos.internal.SonosBinding] - Querying the network for a predefined Sonos device with UDN uuid:RINCON_B8E9373208C601400
2016-06-21 19:26:59.277 [INFO ] [.b.sonos.internal.SonosBinding] - Querying the network for a predefined Sonos device with UDN uuid:RINCON_5CAAFD01B2A401400
2016-06-21 19:26:59.282 [INFO ] [.b.sonos.internal.SonosBinding] - Querying the network for a predefined Sonos device with UDN uuid:RINCON_B8E93792274001400
2016-06-21 19:26:59.288 [INFO ] [.b.sonos.internal.SonosBinding] - Querying the network for any other Sonos device
2016-06-21 19:26:59.650 [INFO ] [.o.io.habmin.HABminApplication] - Started HABmin REST API at /services/habmin
2016-06-21 19:27:00.189 [INFO ] [.b.sonos.internal.SonosBinding] - Found a Sonos device (ZP90) with UDN uuid:RINCON_B8E93792274001400
2016-06-21 19:27:00.342 [INFO ] [.b.sonos.internal.SonosBinding] - Found a Sonos device (S3) with UDN uuid:RINCON_B8E9373208C601400
2016-06-21 19:27:00.364 [INFO ] [.b.sonos.internal.SonosBinding] - Found a Sonos device (S6) with UDN uuid:RINCON_5CAAFD01B2A401400
2016-06-21 19:27:05.101 [INFO ] [.service.AbstractActiveService] - NTP Refresh Service has been started
2016-06-21 19:27:05.155 [INFO ] [.service.AbstractActiveService] - NetworkHealth Refresh Service has been started
2016-06-21 19:27:05.226 [INFO ] [.service.AbstractActiveService] - XBMC Refresh Service has been started
2016-06-21 19:27:05.554 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'dashboard.rules’
2016-06-21 19:27:05.761 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'reynolds.rules’
2016-06-21 19:27:08.579 [ERROR] [b.x.internal.XbmcActiveBinding] - Connection failed for ‘#bedroom’ on 10.0.26.41
2016-06-21 19:27:08.580 [INFO ] [.z.internal.ZWaveActiveBinding] - Update config, port = /dev/ttyACM0
2016-06-21 19:27:08.581 [INFO ] [.z.internal.ZWaveActiveBinding] - Update config, healtime = 2
2016-06-21 19:27:08.581 [INFO ] [.service.AbstractActiveService] - ZWave Refresh Service has been started
2016-06-21 19:27:08.600 [INFO ] [b.z.i.protocol.ZWaveController] - Starting Z-Wave controller
2016-06-21 19:27:08.600 [INFO ] [b.z.i.protocol.ZWaveController] - Z-Wave timeout is set to 5000ms. Soft reset is false.
2016-06-21 19:27:08.601 [INFO ] [b.z.i.protocol.ZWaveController] - Connecting to serial port /dev/ttyACM0
2016-06-21 19:27:08.636 [INFO ] [b.z.i.protocol.ZWaveController] - Serial port is initialized
2016-06-21 19:27:08.656 [WARN ] [ApplicationCommandMessageClass] - NODE 17: Not initialized yet, ignoring message.
2016-06-21 19:27:08.659 [WARN ] [ApplicationCommandMessageClass] - NODE 17: Not initialized yet, ignoring message.
2016-06-21 19:27:08.677 [INFO ] [o.o.b.w.i.common.WeatherConfig] - LocationConfig[providerName=YAHOO,language=en,updateInterval=30,latitude=xx,longitude=xx,woeid=xx,locationId=home,name=xx]
2016-06-21 19:27:09.792 [WARN ] [ApplicationCommandMessageClass] - NODE 17: Not initialized yet, ignoring message.
2016-06-21 19:27:10.639 [WARN ] [ApplicationCommandMessageClass] - NODE 11: Not initialized yet, ignoring message.
2016-06-21 19:27:10.665 [WARN ] [ApplicationCommandMessageClass] - NODE 15: Not initialized yet, ignoring message.
2016-06-21 19:27:10.902 [INFO ] [.myopenhab.internal.MyOHClient] - Connected to my.openHAB service (UUID = xxxxx, local base URL = http://localhost:8080)
2016-06-21 19:27:11.160 [ERROR] [b.x.internal.XbmcActiveBinding] - Connection failed for ‘#loungeroom’ on 10.0.26.40
2016-06-21 19:27:11.161 [WARN ] [b.x.internal.XbmcActiveBinding] - Received update (OFF) for item Media_Loungeroom but the connection to the XBMC instance #loungeroom is down, ignoring
2016-06-21 19:27:11.275 [WARN ] [ApplicationCommandMessageClass] - NODE 19: Not initialized yet, ignoring message.
2016-06-21 19:27:11.681 [INFO ] [.o.b.w.i.s.WeatherJobScheduler] - Starting and scheduling weatherJob-home with interval of 30 minutes
2016-06-21 19:27:11.776 [INFO ] [rialApiGetInitDataMessageClass] - NODE 1: Node found
2016-06-21 19:27:11.776 [INFO ] [rialApiGetInitDataMessageClass] - NODE 2: Node found
2016-06-21 19:27:11.777 [INFO ] [rialApiGetInitDataMessageClass] - NODE 4: Node found
2016-06-21 19:27:11.777 [INFO ] [rialApiGetInitDataMessageClass] - NODE 5: Node found
2016-06-21 19:27:11.777 [INFO ] [rialApiGetInitDataMessageClass] - NODE 7: Node found
2016-06-21 19:27:11.777 [INFO ] [rialApiGetInitDataMessageClass] - NODE 8: Node found
2016-06-21 19:27:11.777 [INFO ] [rialApiGetInitDataMessageClass] - NODE 11: Node found
2016-06-21 19:27:11.777 [INFO ] [rialApiGetInitDataMessageClass] - NODE 12: Node found
2016-06-21 19:27:11.777 [INFO ] [rialApiGetInitDataMessageClass] - NODE 13: Node found
2016-06-21 19:27:11.777 [INFO ] [rialApiGetInitDataMessageClass] - NODE 14: Node found
2016-06-21 19:27:11.777 [INFO ] [rialApiGetInitDataMessageClass] - NODE 15: Node found
2016-06-21 19:27:11.777 [INFO ] [rialApiGetInitDataMessageClass] - NODE 16: Node found
2016-06-21 19:27:11.778 [INFO ] [rialApiGetInitDataMessageClass] - NODE 17: Node found
2016-06-21 19:27:11.778 [INFO ] [rialApiGetInitDataMessageClass] - NODE 18: Node found
2016-06-21 19:27:11.778 [INFO ] [rialApiGetInitDataMessageClass] - NODE 19: Node found
2016-06-21 19:27:11.778 [INFO ] [rialApiGetInitDataMessageClass] - NODE 20: Node found
2016-06-21 19:27:11.778 [INFO ] [rialApiGetInitDataMessageClass] - ZWave Controller using Controller API
2016-06-21 19:27:11.778 [INFO ] [rialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
2016-06-21 19:27:11.778 [INFO ] [rialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------
2016-06-21 19:27:11.778 [INFO ] [rialApiGetInitDataMessageClass] - # Nodes = 16
2016-06-21 19:27:11.778 [INFO ] [rialApiGetInitDataMessageClass] - ----------------------------------------------------------------------------
2016-06-21 19:27:12.179 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 20: Unsupported command class SCENE_ACTUATOR_CONF
2016-06-21 19:27:12.202 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 12: Unsupported command class SCENE_ACTUATOR_CONF
2016-06-21 19:27:12.235 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 13: Unsupported command class SCENE_ACTUATOR_CONF
2016-06-21 19:27:12.253 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 16: Unsupported command class SCENE_ACTUATOR_CONF
2016-06-21 19:27:12.259 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 18: Unsupported command class SCENE_ACTUATOR_CONF
2016-06-21 19:27:12.265 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass] - NODE 14: Unsupported command class SCENE_ACTUATOR_CONF
2016-06-21 19:27:12.581 [WARN ] [i.p.s.IsFailedNodeMessageClass] - NODE 2: Is currently marked as failed by the controller!
2016-06-21 19:27:12.633 [WARN ] [i.p.s.IsFailedNodeMessageClass] - NODE 11: Is currently marked as failed by the controller!
2016-06-21 19:27:15.173 [WARN ] [b.x.internal.XbmcActiveBinding] - Received update (OFF) for item Media_Bedroom but the connection to the XBMC instance #bedroom is down, ignoring
2016-06-21 19:27:19.761 [ERROR] [WaveController$ZWaveSendThread] - NODE 5: Timeout while sending message. Requeueing - 2 attempts left!
2016-06-21 19:27:19.762 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 5: Got an error while sending data. Resending message.
2016-06-21 19:27:24.763 [ERROR] [WaveController$ZWaveSendThread] - NODE 5: Timeout while sending message. Requeueing - 1 attempts left!
2016-06-21 19:27:24.763 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 5: Got an error while sending data. Resending message.
2016-06-21 19:27:29.764 [ERROR] [WaveController$ZWaveSendThread] - NODE 5: Timeout while sending message. Requeueing - 0 attempts left!
2016-06-21 19:27:29.764 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 5: Got an error while sending data. Resending message.
2016-06-21 19:27:34.766 [WARN ] [WaveController$ZWaveSendThread] - NODE 5: Too many retries. Discarding message: Message: class = SendData (0x13), type = Request (0x00), payload = 05 03 32 01 08
2016-06-21 19:27:41.719 [ERROR] [WaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 0 attempts left!
2016-06-21 19:27:41.719 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 2: Node is DEAD. Dropping message.
2016-06-21 19:27:46.720 [ERROR] [WaveController$ZWaveSendThread] - NODE 4: Timeout while sending message. Requeueing - 0 attempts left!
2016-06-21 19:27:46.720 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 4: Got an error while sending data. Resending message.
2016-06-21 19:27:51.883 [WARN ] [WaveController$ZWaveSendThread] - NODE 4: Too many retries. Discarding message: Message: class = SendData (0x13), type = Request (0x00), payload = 04 01 00
2016-06-21 19:27:55.322 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:27:55.423 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:27:55.524 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:27:55.624 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:27:55.725 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:27:55.825 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:27:55.926 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:27:56.027 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:27:56.127 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:27:56.228 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:42.120 [ERROR] [WaveController$ZWaveSendThread] - NODE 12: Timeout while sending message. Requeueing - 0 attempts left!
2016-06-21 19:28:42.120 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 12: Got an error while sending data. Resending message.
2016-06-21 19:28:42.120 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:42.221 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:42.322 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:42.422 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:42.523 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:42.623 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:42.724 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:42.824 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:42.925 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:43.026 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:43.127 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:43.227 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:43.328 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:43.428 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:43.529 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:43.629 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:43.730 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:43.830 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:43.931 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:44.031 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:44.132 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:44.232 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:44.333 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:44.433 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:44.534 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:44.634 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:44.735 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:44.836 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:44.937 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:45.038 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:45.139 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:45.240 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:45.340 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:45.441 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:45.542 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:45.642 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:45.743 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:45.844 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:45.944 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:46.045 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:46.146 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:46.246 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:46.348 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:46.448 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:46.549 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:46.649 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:46.750 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:46.851 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:46.951 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:47.053 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:47.153 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:47.254 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:47.355 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:47.455 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:47.556 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2016-06-21 19:28:47.656 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending