Help with ZWave network - in last few days went berserk

ozarn · January 2, 2020, 5:03pm

Hello everyone,
in last few days my zwave network went berserk, not sure why nor i can figure out. Hopefully someone can help or point me in right direction to resolve it. I dread the reboot, because most likely ZWave will not come up. It seems its changing personalities.
Home assistant logs do not show any errors

I am seeing errors below in the OZW_Log.log

2020-01-02 08:52:09.830 Always, OpenZwave Version 1.4.3452 Starting Up
2020-01-02 08:52:15.831 Info, Setting Up Provided Network Key for Secure Communications
2020-01-02 08:52:15.831 Info, mgr,     Added driver for controller /dev/serial/by-id/usb-0658_0200-if00
2020-01-02 08:52:15.831 Info,   Opening controller /dev/serial/by-id/usb-0658_0200-if00
2020-01-02 08:52:15.832 Info, Trying to open serial port /dev/serial/by-id/usb-0658_0200-if00 (attempt 1)
2020-01-02 08:52:15.836 Info, Serial port /dev/serial/by-id/usb-0658_0200-if00 opened (attempt 1)
2020-01-02 08:52:15.837 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2020-01-02 08:52:15.837 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2020-01-02 08:52:15.837 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2020-01-02 08:52:15.837 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2020-01-02 08:52:15.837 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2020-01-02 08:52:15.837 Detail,
2020-01-02 08:52:15.837 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x15) - FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2020-01-02 08:52:16.837 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2020-01-02 08:52:16.837 Detail, contrlr, Removing current message
2020-01-02 08:52:16.837 Detail, contrlr, Notification: Notification - TimeOut
2020-01-02 08:52:16.843 Detail,
2020-01-02 08:52:16.843 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x20) - FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2020-01-02 08:52:17.345 Detail, Unsolicited message received while waiting for ACK.
2020-01-02 08:52:17.345 Detail, Node004,   Received: 0x01, 0x14, 0x00, 0x04, 0x00, 0x04, 0x0e, 0x60, 0x0d, 0x01, 0x00, 0x32, 0x02, 0x21, 0x32, 0x00, 0x67, 0x00, 0x02, 0x00, 0xa9, 0x66
2020-01-02 08:52:17.345 Detail,
2020-01-02 08:52:17.345 Detail, Unsolicited message received while waiting for ACK.
2020-01-02 08:52:17.346 Detail, Node004,   Received: 0x01, 0x14, 0x00, 0x04, 0x00, 0x04, 0x0e, 0x60, 0x0d, 0x01, 0x00, 0x32, 0x02, 0x21, 0x32, 0x00, 0xad, 0x00, 0x03, 0x00, 0xf4, 0xf0
2020-01-02 08:52:17.346 Detail,
2020-01-02 08:52:17.347 Detail, Unsolicited message received while waiting for ACK.
2020-01-02 08:52:17.348 Detail, Node004,   Received: 0x01, 0x14, 0x00, 0x04, 0x00, 0x04, 0x0e, 0x60, 0x0d, 0x05, 0x00, 0x32, 0x02, 0x21, 0x32, 0x00, 0x00, 0x00, 0x1e, 0x00, 0x00, 0xb0
2020-01-02 08:52:17.348 Detail,
2020-01-02 08:52:17.438 Detail, Unsolicited message received while waiting for ACK.
2020-01-02 08:52:17.438 Detail, Node004,   Received: 0x01, 0x10, 0x00, 0x04, 0x00, 0x04, 0x0a, 0x32, 0x02, 0x21, 0x32, 0x01, 0x3b, 0x00, 0x02, 0x00, 0xd4, 0x2a
2020-01-02 08:52:17.438 Detail,
2020-01-02 08:52:18.438 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2020-01-02 08:52:18.438 Detail, contrlr, Removing current message
2020-01-02 08:52:18.438 Detail, contrlr, Notification: Notification - TimeOut
2020-01-02 08:52:18.438 Detail,
2020-01-02 08:52:18.438 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x05) - FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2020-01-02 08:52:18.439 Detail, contrlr,   Received: 0x01, 0x01, 0x05
2020-01-02 08:52:18.439 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2020-01-02 08:52:18.440 Detail, contrlr,   Received: 0x01, 0x04, 0x01, 0x05, 0x1c, 0xe3
2020-01-02 08:52:18.440 Detail,
2020-01-02 08:52:18.440 Info, contrlr, Received reply to FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES:
2020-01-02 08:52:18.440 Info, contrlr,     There is a SUC ID Server (SIS) in this network.
2020-01-02 08:52:18.440 Info, contrlr,     The PC controller is an inclusion static update controller (SUC) and was the original primary before the SIS was
added.
2020-01-02 08:52:18.440 Detail, Node227,   Expected reply was received
2020-01-02 08:52:18.440 Detail, Node227,   Message transaction complete
2020-01-02 08:52:18.440 Detail,
2020-01-02 08:52:18.440 Detail, contrlr, Removing current message
2020-01-02 08:52:18.440 Detail,
2020-01-02 08:52:18.440 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x07) - FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03,
0x00, 0x07, 0xfb
2020-01-02 08:52:18.443 Detail, contrlr,   Received: 0x01, 0x2b, 0x01, 0x07, 0x01, 0x01, 0x00, 0x86, 0x01, 0x01, 0x00, 0x5a, 0xfe, 0x81, 0xff, 0x88, 0x4f, 0x1f, 0x00, 0x00, 0xfb, 0x9f, 0x7d, 0xa0, 0x67, 0x00, 0x00, 0x80, 0x00, 0x80, 0x86, 0x00, 0x00, 0x00, 0xe8, 0x73, 0x00, 0x00, 0x0e, 0x00, 0x00, 0x60, 0x00, 0x00, 0xfb
2020-01-02 08:52:18.444 Detail,
2020-01-02 08:52:18.444 Info, contrlr,  Received reply to FUNC_ID_SERIAL_API_GET_CAPABILITIES
2020-01-02 08:52:18.444 Info, contrlr,     Serial API Version:   1.1
2020-01-02 08:52:18.444 Info, contrlr,     Manufacturer ID:      0x0086
2020-01-02 08:52:18.444 Info, contrlr,     Product Type:         0x0101
2020-01-02 08:52:18.444 Info, contrlr,     Product ID:           0x005a
2020-01-02 08:52:18.444 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_RANDOM: 0x01, 0x04, 0x00, 0x1c, 0x20, 0xc7
2020-01-02 08:52:18.444 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_GET_INIT_DATA: 0x01, 0x03, 0x00, 0x02, 0xfe
2020-01-02 08:52:18.444 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_SET_TIMEOUTS: 0x01, 0x05, 0x00, 0x06, 0x64, 0x0f, 0x97
2020-01-02 08:52:18.444 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_APPL_NODE_INFORMATION: 0x01, 0x07, 0x00, 0x03, 0x01, 0x02, 0x01, 0x00, 0xf9
2020-01-02 08:52:18.444 Detail, Node001,   Expected reply was received
2020-01-02 08:52:18.444 Detail, Node001,   Message transaction complete
2020-01-02 08:52:18.444 Detail,
2020-01-02 08:52:18.444 Detail, contrlr, Removing current message
2020-01-02 08:52:18.444 Detail,
2020-01-02 08:52:18.444 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x56) - FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2020-01-02 08:52:18.445 Detail, contrlr,   Received: 0x01, 0x04, 0x01, 0x56, 0x01, 0xad
2020-01-02 08:52:18.445 Detail,
2020-01-02 08:52:18.445 Info, contrlr, Received reply to GET_SUC_NODE_ID.  Node ID = 1
2020-01-02 08:52:18.445 Detail, Node173,   Expected reply was received
2020-01-02 08:52:18.445 Detail, Node173,   Message transaction complete
2020-01-02 08:52:18.445 Detail,
2020-01-02 08:52:18.445 Detail, contrlr, Removing current message
2020-01-02 08:52:18.445 Detail,
2020-01-02 08:52:18.445 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x1c) - FUNC_ID_ZW_GET_RANDOM: 0x01, 0x04, 0x00, 0x1c, 0x20, 0xc7
2020-01-02 08:52:18.999 Warning, WARNING: 500ms passed without reading the rest of the frame...aborting frame read
2020-01-02 08:52:18.999 Detail, contrlr,   Received: 0x01, 0x1c, 0x20, 0x76, 0x5f, 0x4d, 0x9c, 0x16, 0xac, 0x40, 0x3a, 0x56, 0x84, 0x17, 0x0d, 0x6a, 0x3a, 0xab, 0x90, 0x9a, 0x9b, 0x5a, 0x14, 0x6c, 0x69, 0xa7, 0xfc, 0x59, 0x3f, 0xce
2020-01-02 08:52:18.999 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2020-01-02 08:52:19.002 Detail, contrlr,   Received: 0x01, 0x25, 0x01, 0x1c, 0x01, 0x20, 0x76, 0x5f, 0x4d, 0x9c, 0x16, 0xac, 0x40, 0x3a, 0x56, 0x84, 0x17, 0x0d, 0x6a, 0x3a, 0xab, 0x90, 0x9a, 0x9b, 0x5a, 0x14, 0x6c, 0x69, 0xa7, 0xfc, 0x59, 0x3f, 0xce, 0x6f, 0x20, 0xe5, 0x24, 0xcd, 0x87
2020-01-02 08:52:19.002 Detail,
2020-01-02 08:52:19.002 Info, contrlr, Received reply to FUNC_ID_ZW_GET_RANDOM: true
2020-01-02 08:52:19.002 Detail, Node032,   Expected reply was received
2020-01-02 08:52:19.002 Detail, Node032,   Message transaction complete
2020-01-02 08:52:19.002 Detail,
2020-01-02 08:52:19.002 Detail, contrlr, Removing current message
2020-01-02 08:52:19.002 Detail,
2020-01-02 08:52:19.002 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x02) - FUNC_ID_SERIAL_API_GET_INIT_DATA: 0x01, 0x03, 0x00, 0x02, 0xfe
2020-01-02 08:52:19.101 Detail, contrlr,   Received: 0x01, 0x25, 0x01, 0x02, 0x05, 0x08, 0x1d, 0xe9, 0x01, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x05, 0x00, 0x24
2020-01-02 08:52:19.101 Detail,
2020-01-02 08:52:19.101 Fatal, Failed to get HomeID or Controller Node ID during Init Sequence, m_homeId = 0x00000000, m_Controller_nodeId = 255
2020-01-02 08:52:19.101 Detail, Notification: DriverFailed

hassio hardware info is showing that hosts sees my Aeotec USB ZWave controller

- /dev/serial/by-id/usb-0658_0200-if00
- /dev/ttyS18
- /dev/ttyS2
- /dev/ttyS27
- /dev/ttyS6
- /dev/ttyS24
- /dev/ttyS5
- /dev/ttyS1
- /dev/ttyACM0

and my config file is:

# Z-Wave
zwave:
  usb_path: /dev/serial/by-id/usb-0658_0200-if00
  network_key: !secret zwave_network_key
  autoheal: "False"
  config_path: /config/openzwave_config

any help or pointers greatly appreciated. All fixes that i found searching forums were temporarily. After reboot or 2, or upgrade issue came back.

I hope i do not have to start from scratch.

thank you

honikos · January 2, 2020, 5:55pm

Which hardware do you use for your installation? What kind of hass.io installation?

After stopping hass.io you should try replacing the /dev/serial/by-id/usb-0658_0200-if00 with /dev/ttyACM0 or /dev/ttyACM1 (depending on which tty your Aeotec stick is addressed to).

ozarn · January 2, 2020, 6:01pm

Thank you Honikos,

i did try several times to use /dev/ttyACM0 instead of “by-id”, same results.

I am using Intel NUC running ESX, Ubuntu VM is hosting Hass.io. with HA running on docker.

honikos · January 2, 2020, 6:07pm

It’s not /dev/ttyACMO it’s /dev/ttyACM0

ozarn · January 2, 2020, 6:08pm

correct, just my typo here.

honikos · January 2, 2020, 6:14pm

ok, I read it just a few days before here in the forum (ubuntu problem):
just uninstall Modem Manager:

sudo systemctl disable ModemManager and remove with sudo apt-get purge modemmanager (commands are for Debian/Ubuntu).

ozarn · January 2, 2020, 7:27pm

du bist wunderbar!!!

that did it, thank you so much!!! do you know if that was recently added or its been there for a while. My ZWave worked fine for several months until recently.

thanks again!!

honikos · January 2, 2020, 10:20pm

You are welcome

No, I don’t. The docs only say it happens randomly.