Moderately frustrated- cannot start Zwave

suburbazine · June 2, 2020, 9:38pm

Been struggling with a move from Wink to HASS, trying to get Zwave started and the errors aren’t being self explanatory. I’ve tried both /dev/ttyACM0 and the direct path, both seem to open then choke as below. I’m using a Zooz S2 Plus USB adapter running a HASS ESXi image, up to date. What am I missing here?


    serial:
        /dev/ttyACM0
        /dev/ttyS0
        /dev/ttyS3
        /dev/ttyS1
        /dev/ttyS2
        /dev/serial/by-id/usb-0658_0200-if00
    input:
        Power Button
        ImPS/2 Generic Wheel Mouse
        VMware VMware Virtual USB Mouse
        AT Translated Set 2 keyboard
    disk:
    gpio:
    audio:

2020-06-02 16:33:31.948 Always, OpenZwave Version 1.4.3469 Starting Up
2020-06-02 16:33:38.888 Info, Setting Up Provided Network Key for Secure Communications
2020-06-02 16:33:38.888 Info, mgr,     Added driver for controller /dev/serial/by-id/usb-0658_0200-if00
2020-06-02 16:33:38.888 Info,   Opening controller /dev/serial/by-id/usb-0658_0200-if00
2020-06-02 16:33:38.888 Info, Trying to open serial port /dev/serial/by-id/usb-0658_0200-if00 (attempt 1)
2020-06-02 16:33:39.081 Info, Serial port /dev/serial/by-id/usb-0658_0200-if00 opened (attempt 1)
2020-06-02 16:33:39.082 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2020-06-02 16:33:39.082 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2020-06-02 16:33:39.082 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2020-06-02 16:33:39.082 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2020-06-02 16:33:39.082 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2020-06-02 16:33:39.082 Detail,
2020-06-02 16:33:39.082 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x15) - FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2020-06-02 16:33:39.086 Warning, WARNING: Out of frame flow! (0x61).  Sending NAK.
2020-06-02 16:33:39.094 Warning, WARNING: Out of frame flow! (0x20).  Sending NAK.
2020-06-02 16:33:39.100 Warning, WARNING: Out of frame flow! (0x30).  Sending NAK.
2020-06-02 16:33:49.083 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2020-06-02 16:33:49.083 Detail, contrlr, Removing current message
2020-06-02 16:33:49.083 Detail, contrlr, Notification: Notification - TimeOut
2020-06-02 16:33:49.083 Detail,
2020-06-02 16:33:49.083 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x20) - FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2020-06-02 16:33:49.174 Detail, Unsolicited message received while waiting for ACK.
2020-06-02 16:33:49.681 Warning, WARNING: 500ms passed without reading the rest of the frame...aborting frame read
2020-06-02 16:33:49.770 Detail, Unsolicited message received while waiting for ACK.
2020-06-02 16:33:50.271 Warning, WARNING: 500ms passed without reading the rest of the frame...aborting frame read
2020-06-02 16:33:50.271 Warning, WARNING: Out of frame flow! (0x20).  Sending NAK.
2020-06-02 16:33:50.273 Detail, Unsolicited message received while waiting for ACK.
2020-06-02 16:33:50.773 Warning, WARNING: 500ms passed without reading the rest of the frame...aborting frame read
2020-06-02 16:33:50.773 Detail, Unsolicited message received while waiting for ACK.
2020-06-02 16:33:51.273 Warning, WARNING: 500ms passed without reading the rest of the frame...aborting frame read
2020-06-02 16:33:51.273 Warning, WARNING: Out of frame flow! (0x20).  Sending NAK.
2020-06-02 16:33:51.401 Detail, Unsolicited message received while waiting for ACK.
2020-06-02 16:33:51.401 Detail, contrlr,   Received: 0x01, 0x01, 0x02
2020-06-02 16:33:51.401 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2020-06-02 16:33:51.401 Warning, WARNING: Out of frame flow! (0x00).  Sending NAK.
2020-06-02 16:33:51.408 Warning, WARNING: Out of frame flow! (0x00).  Sending NAK.
2020-06-02 16:33:51.411 Warning, WARNING: Out of frame flow! (0x00).  Sending NAK.
2020-06-02 16:33:51.418 Warning, WARNING: Out of frame flow! (0x00).  Sending NAK.
2020-06-02 16:33:51.421 Warning, WARNING: Out of frame flow! (0x00).  Sending NAK.
2020-06-02 16:33:52.421 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2020-06-02 16:33:52.421 Detail, contrlr, Removing current message
2020-06-02 16:33:52.421 Detail, contrlr, Notification: Notification - TimeOut
2020-06-02 16:33:52.422 Detail,
2020-06-02 16:33:52.422 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x05) - FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2020-06-02 16:33:53.422 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2020-06-02 16:33:53.423 Detail, contrlr, Removing current message
2020-06-02 16:33:53.423 Detail, contrlr, Notification: Notification - TimeOut
2020-06-02 16:33:53.423 Detail,
2020-06-02 16:33:53.423 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x07) - FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2020-06-02 16:33:53.427 Warning, WARNING: Out of frame flow! (0x07).  Sending NAK.
2020-06-02 16:33:53.427 Warning, WARNING: Out of frame flow! (0x03).  Sending NAK.
2020-06-02 16:33:53.429 Detail, Unsolicited message received while waiting for ACK.
2020-06-02 16:33:53.442 Detail, contrlr,   Received: 0x01, 0x02, 0x87, 0x88
2020-06-02 16:33:53.442 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2020-06-02 16:33:53.445 Warning, WARNING: Out of frame flow! (0x2b).  Sending NAK.
2020-06-02 16:33:53.445 Warning, WARNING: Out of frame flow! (0x07).  Sending NAK.
2020-06-02 16:33:53.445 Warning, WARNING: Out of frame flow! (0x02).  Sending NAK.
2020-06-02 16:33:53.445 Warning, WARNING: Out of frame flow! (0x7a).  Sending NAK.
2020-06-02 16:33:53.445 Warning, WARNING: Out of frame flow! (0x04).  Sending NAK.
2020-06-02 16:33:53.447 Warning, WARNING: Out of frame flow! (0x02).  Sending NAK.
2020-06-02 16:33:53.451 Warning, WARNING: Out of frame flow! (0x87).  Sending NAK.
2020-06-02 16:33:53.457 Warning, WARNING: Out of frame flow! (0x88).  Sending NAK.
2020-06-02 16:33:54.457 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2020-06-02 16:33:54.457 Detail, contrlr, Removing current message
2020-06-02 16:33:54.457 Detail, contrlr, Notification: Notification - TimeOut
2020-06-02 16:33:54.457 Detail,
2020-06-02 16:33:54.457 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x56) - FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2020-06-02 16:33:54.464 Warning, WARNING: Out of frame flow! (0x04).  Sending NAK.
2020-06-02 16:33:54.467 Warning, WARNING: Out of frame flow! (0x56).  Sending NAK.
2020-06-02 16:33:54.468 Warning, WARNING: Out of frame flow! (0x56).  Sending NAK.
2020-06-02 16:33:54.468 Warning, WARNING: Out of frame flow! (0x00).  Sending NAK.
2020-06-02 16:33:54.469 Warning, WARNING: Out of frame flow! (0xac).  Sending NAK.
2020-06-02 16:33:54.472 Warning, WARNING: Out of frame flow! (0x04).  Sending NAK.
2020-06-02 16:33:54.477 Warning, WARNING: Out of frame flow! (0x00).  Sending NAK.
2020-06-02 16:34:02.032 Warning, WARNING: 500ms passed without reading the rest of the frame...aborting frame read
2020-06-02 16:34:02.032 Warning, WARNING: Out of frame flow! (0x0f).  Sending NAK.
2020-06-02 16:34:02.041 Detail, contrlr,   Received: 0x01, 0x06, 0x64, 0x0f, 0x96, 0x01, 0x01, 0x06
2020-06-02 16:34:02.041 Warning, contrlr, WARNING: Checksum incorrect - sending NAK
2020-06-02 16:34:02.047 Warning, WARNING: Out of frame flow! (0x0f).  Sending NAK.
2020-06-02 16:34:02.051 Warning, WARNING: Out of frame flow! (0x96).  Sending NAK.
2020-06-02 16:34:02.057 Warning, WARNING: Out of frame flow! (0x05).  Sending NAK.
2020-06-02 16:34:02.560 Warning, WARNING: 500ms passed without reading the rest of the frame...aborting frame read
2020-06-02 16:34:02.560 Warning, WARNING: Out of frame flow! (0x64).  Sending NAK.
2020-06-02 16:34:04.458 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2020-06-02 16:34:04.458 Detail, contrlr, Removing current message
2020-06-02 16:34:04.458 Detail, contrlr, Notification: Notification - TimeOut

freshcoast · June 2, 2020, 10:02pm

WARNING: Out of frame flow! usually means there are multiple processes, such as two instances of OZW, accessing the serial port at the same time.

suburbazine · June 2, 2020, 10:27pm

That answer was perfect. So apparently I didn’t need the OZW app running in the Supervisor pane if I’m using the Zwave integration in Configuration.

Aggie · November 9, 2020, 3:25pm

Can you explain how you fixed this?

Aggie · November 10, 2020, 1:29am

Just in case someone else comes looking for this. I had a similar issue where it appeared 2 processes were trying to use the HUSBZB-1 stick. All my z-wave and zigbee devices disconnected after an update to a new version of HA. Restoring to the old version via snapshot didn’t work.

What finally did it was pulling the USB stick and restarting, then restarting the Pi again with the stick back in. Hope that helps someone.