I've broken ZWave!

I tried to upgrade openzwave in my latest docker image and it did not go well!

I figured that as I was using docker there would be no impact as I could just tear down the docker-compose environment and start again. There were no changes to the configuration - at least knowingly.

I am now getting errors at ZWave startup:

2018-05-13 18:17:17 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=139866092555232-1>
2018-05-13 18:17:17 INFO (MainThread) [homeassistant.setup] Setting up zwave
2018-05-13 18:17:17 ERROR (MainThread) [homeassistant.setup] Error during setup of component zwave
Traceback (most recent call last):
File “/usr/src/app/homeassistant/setup.py”, line 145, in _async_setup_component
component.setup, hass, processed_config)
File “/usr/local/lib/python3.6/concurrent/futures/thread.py”, line 56, in run
result = self.fn(*self.args, **self.kwargs)
File “/usr/src/app/homeassistant/components/zwave/init.py”, line 227, in setup
from openzwave.option import ZWaveOption
File “/config/deps/lib/python3.6/site-packages/openzwave/option.py”, line 29, in
import libopenzwave
ImportError: /config/deps/lib/python3.6/site-packages/libopenzwave.cpython-36m-x86_64-linux-gnu.so: failed to map segment from shared object: Operation not permitted
2018-05-13 18:17:17 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=persistent_notification, service=create, service_data=title=Invalid config, message=The following components and platforms could not be set up:

  • zwave
    Please check your config., notification_id=invalid_config, service_call_id=139866092555232-2>

I’ve torn down the docker environment and rebuild multiple times without success

config:

Z-Wave

zwave:
usb_path: /dev/ttyACM0
network_key: !secret z_wave_network_key
debug: ‘true’

What’s the top 20 lines (or so) of your OZW_Log.txt?

failed to map segment from shared object: Operation not permitted

That’s almost certainly a large part of the problem. A quick Google found this thread which might help you.

Nothing in there since the last shutdown - unless its changed location - this is from /config:

2018-05-13 15:14:02.952 Info, mgr, Driver for controller /dev/ttyACM0 pending removal
2018-05-13 15:14:02.952 Detail, Notification: DriverRemoved
2018-05-13 15:14:02.952 Always, ***************************************************************************
2018-05-13 15:14:02.952 Always, ********************* Cumulative Network Statistics *********************
2018-05-13 15:14:02.952 Always, *** General
2018-05-13 15:14:02.952 Always, Driver run time: . . . 4 days, 19 hours, 52 minutes
2018-05-13 15:14:02.952 Always, Frames processed: . . . . . . . . . . . . . . . . . . . . 20360
2018-05-13 15:14:02.952 Always, Total messages successfully received: . . . . . . . . . . 20359
2018-05-13 15:14:02.952 Always, Total Messages successfully sent: . . . . . . . . . . . . 487
2018-05-13 15:14:02.952 Always, ACKs received from controller: . . . . . . . . . . . . . 3226
2018-05-13 15:14:02.952 Always, *** Errors
2018-05-13 15:14:02.952 Always, Unsolicited messages received while waiting for ACK: . . 13
2018-05-13 15:14:02.952 Always, Reads aborted due to timeouts: . . . . . . . . . . . . . 1
2018-05-13 15:14:02.952 Always, Bad checksum errors: . . . . . . . . . . . . . . . . . . 0
2018-05-13 15:14:02.952 Always, CANs received from controller: . . . . . . . . . . . . . 13
2018-05-13 15:14:02.952 Always, NAKs received from controller: . . . . . . . . . . . . . 0
2018-05-13 15:14:02.952 Always, Out of frame data flow errors: . . . . . . . . . . . . . 7
2018-05-13 15:14:02.952 Always, Messages retransmitted: . . . . . . . . . . . . . . . . . 6
2018-05-13 15:14:02.952 Always, Messages dropped and not delivered: . . . . . . . . . . . 30
2018-05-13 15:14:02.952 Always, ***************************************************************************
2018-05-13 15:14:07.088 Info, mgr, Driver for controller /dev/ttyACM0 removed
2018-05-13 15:14:08.182 Error, mgr, Manager::GetDriver failed - Home ID 0xd3df1dff is unknown
2018-05-13 15:14:08.182 Warning, Exception: Manager.cpp:373 - 100 - Invalid HomeId passed to GetDriver
2018-05-13 15:14:08.182 Info, mgr, GetSendQueueCount() failed - _homeId -740352513 not found

Yup, it looks like your problem is that error message. I’d raise an issue with the repository for whatever image you used.

Thanks for pointer - there was a local python library structure sitting under config/deps - I deleted this and let the docker image recreate it and zwave is working and several other issues have cleared themselves up at the same time.