Aeotec Z-Stick ERROR: Cannot get exclusive lock for serial port

Configuration
1

So i had a powercut a few days ago that has wiped out my zwave network. Having looked at HA logs i see that it couldn’t connect to the network (all my devices are missing here).

So i fired up OZWCP and this is the output i’m getting. HA is stopped and i haven’t changed anything from the working config. Any ideas?

2017-05-28 09:53:48.772 Always, OpenZwave Version 1.4.2315 Starting Up
webserver starting port 8124
post: key=dev data=/dev/ttyACM0 size=12
post: key=fn data=open size=4
post: key=usb data=false size=5
2017-05-28 09:53:58.489 Info, Setting Up Provided Network Key for Secure Communications
2017-05-28 09:53:58.489 Warning, Failed - Network Key Not Set
2017-05-28 09:53:58.489 Info, mgr,     Added driver for controller /dev/ttyACM0
2017-05-28 09:53:58.489 Info,   Opening controller /dev/ttyACM0
2017-05-28 09:53:58.489 Info, Trying to open serial port /dev/ttyACM0 (attempt 1)
2017-05-28 09:53:58.489 Error, ERROR: Cannot get exclusive lock for serial port /dev/ttyACM0. Error code 11
2017-05-28 09:53:58.489 Info, Serial port /dev/ttyACM0 opened (attempt 1)
2017-05-28 09:53:58.489 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2017-05-28 09:53:58.489 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2017-05-28 09:53:58.489 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2017-05-28 09:53:58.489 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2017-05-28 09:53:58.489 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2017-05-28 09:53:58.489 Detail, 
2017-05-28 09:53:58.489 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x15) - FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2017-05-28 09:53:58.491 Detail, contrlr,   Received: 0x01, 0x10, 0x01, 0x15, 0x5a, 0x2d, 0x57, 0x61, 0x76, 0x65, 0x20, 0x33, 0x2e, 0x39, 0x35, 0x00, 0x01, 0x99
2017-05-28 09:53:58.491 Detail, 
2017-05-28 09:53:58.491 Info, contrlr, Received reply to FUNC_ID_ZW_GET_VERSION:
2017-05-28 09:53:58.491 Info, contrlr,     Static Controller library, version Z-Wave 3.95
2017-05-28 09:53:58.491 Detail, Node045,   Expected reply was received
2017-05-28 09:53:58.491 Detail, Node045,   Message transaction complete
2017-05-28 09:53:58.491 Detail, 
2017-05-28 09:53:58.491 Detail, contrlr, Removing current message
2017-05-28 09:53:58.491 Detail, 
2017-05-28 09:53:58.491 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x20) - FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2017-05-28 09:53:58.493 Warning, WARNING: Out of frame flow! (0x20).  Sending NAK.
2017-05-28 09:53:58.493 Warning, WARNING: Out of frame flow! (0x8e).  Sending NAK.
2017-05-28 09:53:58.494 Warning, WARNING: Out of frame flow! (0xbe).  Sending NAK.
2017-05-28 09:53:58.496 Detail, contrlr,   Received: 0x01, 0x08, 0x01, 0x20, 0xed, 0xbe, 0x0b, 0x8e, 0x01, 0x20
2017-05-28 09:53:58.496 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2017-05-28 09:53:58.496 Warning, WARNING: Out of frame flow! (0xbe).  Sending NAK.
2017-05-28 09:54:08.492 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2017-05-28 09:54:08.492 Detail, contrlr, Removing current message
2017-05-28 09:54:08.492 Detail, contrlr, Notification: Notification - TimeOut
2017-05-28 09:54:08.492 Info, Notification: Notification home 00000000 node 255 Timeout
2017-05-28 09:54:08.492 Detail, 
2017-05-28 09:54:08.492 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x05) - FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2017-05-28 09:54:08.493 Detail, contrlr,   Received: 0x01, 0x04, 0x01, 0x05, 0x08, 0xf7
2017-05-28 09:54:08.493 Detail, 
2017-05-28 09:54:08.493 Info, contrlr, Received reply to FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES:
2017-05-28 09:54:08.493 Info, contrlr,     There is no SUC ID Server (SIS) in this network.
2017-05-28 09:54:08.493 Info, contrlr,     The PC controller is a primary controller.
2017-05-28 09:54:08.493 Detail, Node247,   Expected reply was received
2017-05-28 09:54:08.493 Detail, Node247,   Message transaction complete
2017-05-28 09:54:08.493 Detail, 
2017-05-28 09:54:08.493 Detail, contrlr, Removing current message
2017-05-28 09:54:08.493 Detail, 
2017-05-28 09:54:08.493 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x07) - FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2017-05-28 09:54:08.501 Detail, contrlr,   Received: 0x01, 0x2b, 0x01, 0x07, 0x01, 0x00, 0x00, 0xff, 0x88, 0x4f, 0x00, 0xfb, 0x9f, 0x7d, 0x00, 0x80, 0x86, 0xe8, 0x73, 0x00, 0x60, 0x00, 0xfb, 0x01, 0x07, 0x01, 0x86, 0x5a, 0xfe, 0x88, 0x4f, 0x1f, 0xfb, 0x9f, 0x67, 0x00, 0x80, 0x00, 0x00, 0x00, 0x0e, 0x60, 0x01, 0x2b, 0x81
2017-05-28 09:54:08.501 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2017-05-28 09:54:08.502 Warning, WARNING: Out of frame flow! (0x00).  Sending NAK
2

You need to stop home assistant before using OpenZwave is what that typically means…

3

Yup, said that in the OP > “HA is stopped”

4

Did you stop it with the GUI or the command line? Something still has control over that port. The GUI sometimes fails at stopping HA

1 Like
5

True - you might want to do a

sudo systemctl status home-assistant.service -l

just to be sure.

6

I always use shell, it’s only recent addition that you can do this from GUI so i’ve not taking to using it yet (and as you say it seems unreliable)

7

Yes its stopped, but i notice some logs here not sure if they are useful at all:

May 28 09:33:03 ha hass[602]: 2017-05-28 09:33:03 WARNING (Thread-1) [homeassistant.components.zwave] zwave not ready after 30 seconds, continuing anyway
May 28 09:33:14 ha systemd[1]: Stopping Home Assistant...
May 28 09:33:18 ha hass[602]: 2017-05-28 09:33:18 ERROR (Thread-5) [openzwave] Stop network : %s
May 28 09:33:18 ha hass[602]: Traceback (most recent call last):
May 28 09:33:18 ha hass[602]:   File "/home/shaun/.homeassistant/deps/openzwave/network.py", line 396, in stop
May 28 09:33:18 ha hass[602]:     self._manager.removeWatcher(self.zwcallback)
May 28 09:33:18 ha hass[602]:   File "src-lib/libopenzwave/libopenzwave.pyx", line 4039, in libopenzwave.PyManager.removeWatcher (openzwave-embed/open-zwave-master/python-openzwave
May 28 09:33:18 ha hass[602]: ValueError: call to RemoveWatcher failed
May 28 09:33:19 ha hass[602]: Config directory: /home/.homeassistant
May 28 09:33:19 ha systemd[1]: Stopped Home Assistant
8

If you have ‘lsof’ installed you can do ‘lsof /dev/ttyACM0’ i believe, it should show you which process has it in use, if any.

9

Not a dev, but this seems suspect to me. Almost like “watcher” is what uses the port and RemoveWatcher is supposed to return that port’s availability.

Have you rebooted the Pi itself?

10

That returns nothing.

It’s not a Pi, its a LXC container, but yes i’ve rebooted it :slight_smile:

11

If its not returning anything, that should be “ok” then :slight_smile: but since its a LXC container there might be more at play, but that is out of my knowledge.

12

I assume it worked before, so you can try and look if something is blocking the device on the host system. Is the device exclusively bound to your hass container?

1 Like
13

Someone get this man a beer! :beers:

Turns out i had ran domoticz to make some config edits that HA/ozwcp didn’t offer me. On restart it was starting up (installed itself a nice service :))

14

Great. Just disable that service so it doesn’t come back with the next reboot.
I’m using LXC as well, had my very first instance of hass running there and kept it for playing around without messing with my main instance on a RPi3.

1 Like
15

So I guess this wasn’t far off then.