Can't include a Fibaro Z-wave device

Configuration Z-Wave
1

Hi,
I’ve been struggling for so long now with the same problem… I’ve bought two Z-wave devices which I want to connect to Home assistant through an Aeotec Z-stick gen 5 connected to a RPI 2. I’ve tried and retried for hours. It always ends up in the same way.
The first device is a Nexa AN179 on/off switch. This is always working perfectly, even if I include it using the button on the Aeotec (which I know I shouldn’t) or using the add node secure command.
The other node is a Fibaro FGD-212 Dimmer. If I include it using the button, it shows up in HA but are tagged “dead”. If I use the add node secure nothing happens. I’ve tried to reset both the stick and the devices between the different approaches I’ve been describing several times with the same result. I can’t see any errors in the OZW log. Strangely I can’t see more or less anything in connection to pressing the add node secure. Should I?
I’ve also tested to include the Fibaro device (using the button) in an Openhab system. There both devices work! But I want all my devices to be in the HA environment.

Right now the RPI is about 3m from the Fibaro. What am I’m doing wrong?

Brgds
Daniel

2

Who said you shouldn’t? This way works 100% of the time and doesn’t require HA. I’ve never included a device another way.

After you include the device on your stick, do you see communications in the logs from that node when you press the buttons?

3

Thanks for your reply.

According to the home assistant documentation, https://www.home-assistant.io/docs/z-wave/adding/: “Don’t use the OpenZWave control panel (OZWCP), or the physical button on a controller , to add or remove devices. Many devices will only send the information about their capabilities at the time you include them. If you use the OpenZWave control panel, or the button on a device, then Home Assistant won’t have that information. Using the physical button on a controller will also result in a non-security inclusion being performed, which may limit the features the device supports.”

But what I find strange is that it works in OpenHab?? But if I perform the inclusion of both devices in Openhab and just move the stick to my Home assistant RPI I still get the same problem with the Fibaro shown as dead.

No. I just went through the inclusion process using the button again. From what I can see the first messages after Home assistant is restarted looks ok, but then all of a sudden it says that the node is presumed dead. When toggling the physical switch connected to the device nothing is shown in the log.
Below is the log from my latest try. I’ve tried to remove everything related to the other node (node002) in order to make it more visible. The node in question is Node0004:

2019-07-18 14:59:59.027 Always, OpenZwave Version 1.4.3322 Starting Up
2019-07-18 15:00:03.573 Info, Setting Up Provided Network Key for Secure Communications
2019-07-18 15:00:03.574 Info, mgr, Added driver for controller /dev/serial/by-id/usb-0658_0200-if00
2019-07-18 15:00:03.574 Info, Opening controller /dev/serial/by-id/usb-0658_0200-if00
2019-07-18 15:00:03.574 Info, Trying to open serial port /dev/serial/by-id/usb-0658_0200-if00 (attempt 1)
2019-07-18 15:00:03.577 Info, Serial port /dev/serial/by-id/usb-0658_0200-if00 opened (attempt 1)
2019-07-18 15:00:03.578 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2019-07-18 15:00:03.579 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2019-07-18 15:00:03.579 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2019-07-18 15:00:03.579 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2019-07-18 15:00:03.579 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2019-07-18 15:00:03.579 Detail,
2019-07-18 15:00:03.579 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x15) - FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2019-07-18 15:00:03.582 Detail, contrlr, Received: 0x01, 0x10, 0x01, 0x15, 0x5a, 0x2d, 0x57, 0x61, 0x76, 0x65, 0x20, 0x34, 0x2e, 0x35, 0x34, 0x00, 0x01, 0x93
2019-07-18 15:00:03.582 Detail,
2019-07-18 15:00:03.582 Info, contrlr, Received reply to FUNC_ID_ZW_GET_VERSION:
2019-07-18 15:00:03.582 Info, contrlr, Static Controller library, version Z-Wave 4.54
2019-07-18 15:00:03.582 Detail, Node045, Expected reply was received
2019-07-18 15:00:03.582 Detail, Node045, Message transaction complete
2019-07-18 15:00:03.582 Detail,
2019-07-18 15:00:03.583 Detail, contrlr, Removing current message
2019-07-18 15:00:03.583 Detail,
2019-07-18 15:00:03.583 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x20) - FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2019-07-18 15:00:03.586 Detail, contrlr, Received: 0x01, 0x08, 0x01, 0x20, 0xeb, 0x68, 0xe8, 0x59, 0x01, 0xe5
2019-07-18 15:00:03.586 Detail,
2019-07-18 15:00:03.586 Info, contrlr, Received reply to FUNC_ID_ZW_MEMORY_GET_ID. Home ID = 0xeb68e859. Our node ID = 1
2019-07-18 15:00:03.586 Detail, Node104, Expected reply was received
2019-07-18 15:00:03.587 Detail, Node104, Message transaction complete
2019-07-18 15:00:03.587 Detail,
2019-07-18 15:00:03.587 Detail, contrlr, Removing current message
2019-07-18 15:00:03.587 Detail,
2019-07-18 15:00:03.587 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x05) - FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2019-07-18 15:00:03.589 Detail, contrlr, Received: 0x01, 0x04, 0x01, 0x05, 0x08, 0xf7
2019-07-18 15:00:03.593 Detail,
2019-07-18 15:00:03.593 Info, contrlr, Received reply to FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES:
2019-07-18 15:00:03.593 Info, contrlr, There is no SUC ID Server (SIS) in this network.
2019-07-18 15:00:03.593 Info, contrlr, The PC controller is a primary controller.
2019-07-18 15:00:03.593 Detail, Node247, Expected reply was received
2019-07-18 15:00:03.593 Detail, Node247, Message transaction complete
2019-07-18 15:00:03.594 Detail,
2019-07-18 15:00:03.594 Detail, contrlr, Removing current message
2019-07-18 15:00:03.594 Detail,
2019-07-18 15:00:03.594 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x07) - FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2019-07-18 15:00:03.600 Detail, contrlr, Received: 0x01, 0x2b, 0x01, 0x07, 0x01, 0x01, 0x00, 0x86, 0x00, 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, 0xfa
2019-07-18 15:00:03.600 Detail,
2019-07-18 15:00:03.600 Info, contrlr, Received reply to FUNC_ID_SERIAL_API_GET_CAPABILITIES
2019-07-18 15:00:03.600 Info, contrlr, Serial API Version: 1.1
2019-07-18 15:00:03.600 Info, contrlr, Manufacturer ID: 0x0086
2019-07-18 15:00:03.601 Info, contrlr, Product Type: 0x0001
2019-07-18 15:00:03.601 Info, contrlr, Product ID: 0x005a
2019-07-18 15:00:03.601 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_RANDOM: 0x01, 0x04, 0x00, 0x1c, 0x20, 0xc7
2019-07-18 15:00:03.601 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_GET_INIT_DATA: 0x01, 0x03, 0x00, 0x02, 0xfe
2019-07-18 15:00:03.601 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_SET_TIMEOUTS: 0x01, 0x05, 0x00, 0x06, 0x64, 0x0f, 0x97
2019-07-18 15:00:03.601 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_APPL_NODE_INFORMATION: 0x01, 0x07, 0x00, 0x03, 0x01, 0x02, 0x01, 0x00, 0xf9
2019-07-18 15:00:03.601 Detail, Node001, Expected reply was received
2019-07-18 15:00:03.601 Detail, Node001, Message transaction complete
2019-07-18 15:00:03.601 Detail,
2019-07-18 15:00:03.601 Detail, contrlr, Removing current message
2019-07-18 15:00:03.602 Detail,
2019-07-18 15:00:03.602 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x56) - FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2019-07-18 15:00:03.604 Detail, contrlr, Received: 0x01, 0x04, 0x01, 0x56, 0x00, 0xac
2019-07-18 15:00:03.604 Detail,
2019-07-18 15:00:03.604 Info, contrlr, Received reply to GET_SUC_NODE_ID. Node ID = 0
2019-07-18 15:00:03.604 Info, Controller Does not Support SUC - Cannot Setup Controller as SUC Node
2019-07-18 15:00:03.604 Detail, Node172, Expected reply was received
2019-07-18 15:00:03.604 Detail, Node172, Message transaction complete
2019-07-18 15:00:03.604 Detail,
2019-07-18 15:00:03.604 Detail, contrlr, Removing current message
2019-07-18 15:00:03.605 Detail,
2019-07-18 15:00:03.605 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x1c) - FUNC_ID_ZW_GET_RANDOM: 0x01, 0x04, 0x00, 0x1c, 0x20, 0xc7
2019-07-18 15:00:03.661 Detail, contrlr, Received: 0x01, 0x25, 0x01, 0x1c, 0x01, 0x20, 0xa2, 0x80, 0xe8, 0xe9, 0x34, 0xbe, 0xc5, 0x93, 0xc0, 0xc8, 0xdc, 0x92, 0xd7, 0x16, 0xbd, 0x98, 0xfc, 0xcf, 0x26, 0xb6, 0xfe, 0x8b, 0x71, 0xb9, 0x51, 0x93, 0xf6, 0x56, 0x32, 0x61, 0x9e, 0x4b, 0x41
2019-07-18 15:00:03.661 Detail,
2019-07-18 15:00:03.662 Info, contrlr, Received reply to FUNC_ID_ZW_GET_RANDOM: true
2019-07-18 15:00:03.662 Detail, Node032, Expected reply was received
2019-07-18 15:00:03.662 Detail, Node032, Message transaction complete
2019-07-18 15:00:03.662 Detail,
2019-07-18 15:00:03.662 Detail, contrlr, Removing current message
2019-07-18 15:00:03.662 Detail,
2019-07-18 15:00:03.662 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x02) - FUNC_ID_SERIAL_API_GET_INIT_DATA: 0x01, 0x03, 0x00, 0x02, 0xfe
2019-07-18 15:00:03.766 Detail, contrlr, Received: 0x01, 0x25, 0x01, 0x02, 0x05, 0x00, 0x1d, 0x0b, 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, 0x00, 0x05, 0x00, 0xcf
2019-07-18 15:00:03.766 Detail,
2019-07-18 15:00:03.767 Info, mgr, Driver with Home ID of 0xeb68e859 is now ready.
2019-07-18 15:00:03.767 Info,
2019-07-18 15:00:03.774 Detail, Node002, Queuing (Controller) Delete All Return Routes
2019-07-18 15:00:03.774 Detail, Node002, Queuing (Controller) Assign Return Route
2019-07-18 15:00:03.776 Info, contrlr, Received reply to FUNC_ID_SERIAL_API_GET_INIT_DATA:
2019-07-18 15:00:03.776 Info, contrlr, Node 001 - Known
2019-07-18 15:00:03.776 Detail, Node001, AdvanceQueries queryPending=0 queryRetries=0 queryStage=CacheLoad live=1
2019-07-18 15:00:03.776 Detail, Node001, QueryStage_CacheLoad
2019-07-18 15:00:03.778 Info, Node001, Node Identity Codes: 0086:0001:005a
2019-07-18 15:00:03.778 Detail, Node001, QueryStage_Associations
2019-07-18 15:00:03.778 Detail, Node001, QueryStage_Neighbors
2019-07-18 15:00:03.778 Detail, contrlr, Requesting routing info (neighbor list) for Node 1
2019-07-18 15:00:03.778 Detail, Node001, Queuing (Command) Get Routing Info (Node=1): 0x01, 0x07, 0x00, 0x80, 0x01, 0x00, 0x00, 0x03, 0x7a
2019-07-18 15:00:03.778 Detail, Node001, Queuing (Query) Query Stage Complete (Neighbors)
2019-07-18 15:00:03.778 Info, contrlr, Node 002 - Known
2019-07-18 15:00:03.778 Detail, Node002, AdvanceQueries queryPending=0 queryRetries=0 queryStage=CacheLoad live=1
2019-07-18 15:00:03.778 Detail, Node002, QueryStage_CacheLoad
2019-07-18 15:00:03.778 Info, Node002, Node Identity Codes: 0060:0004:0008
2019-07-18 15:00:03.778 Info, Node002, NoOperation::Set - Routing=true
2019-07-18 15:00:03.779 Detail, Node002, Queuing (NoOp) NoOperation_Set (Node=2): 0x01, 0x09, 0x00, 0x13, 0x02, 0x02, 0x00, 0x00, 0x25, 0x0a, 0xca
2019-07-18 15:00:03.779 Detail, Node002, Queuing (Query) Query Stage Complete (CacheLoad)
2019-07-18 15:00:03.779 Info, contrlr, Node 004 - New
2019-07-18 15:00:03.779 Detail, Node004, AdvanceQueries queryPending=0 queryRetries=0 queryStage=None live=1
2019-07-18 15:00:03.779 Detail, Node004, QueryStage_ProtocolInfo
2019-07-18 15:00:03.779 Detail, Node004, Queuing (Query) Get Node Protocol Info (Node=4): 0x01, 0x04, 0x00, 0x41, 0x04, 0xbe
2019-07-18 15:00:03.779 Detail, Node004, Queuing (Query) Query Stage Complete (ProtocolInfo)
2019-07-18 15:00:03.779 Info, Node004, Initializing Node. New Node: false (false)
2019-07-18 15:00:03.779 Detail, Expected reply was received
2019-07-18 15:00:03.780 Detail, Message transaction complete
2019-07-18 15:00:03.780 Detail,
2019-07-18 15:00:03.780 Detail, contrlr, Removing current message
2019-07-18 15:00:03.780 Detail, Node001, Notification: DriverReady
2019-07-18 15:00:03.816 Detail, Node001, Notification: NodeAdded
2019-07-18 15:00:03.958 Detail, Node001, Notification: NodeProtocolInfo
2019-07-18 15:00:03.962 Detail, Node001, Notification: EssentialNodeQueriesComplete
2019-07-18 15:00:03.974 Detail, Node001, Notification: ValueAdded
2019-07-18 15:00:03.976 Detail, Node001, Notification: NodeNaming
2019-07-18 15:00:04.288 Detail, Node004, Notification: NodeNew
2019-07-18 15:00:04.289 Detail, Node004, Notification: NodeAdded
2019-07-18 15:00:04.295 Detail,
2019-07-18 15:00:04.296 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x06) - FUNC_ID_SERIAL_API_SET_TIMEOUTS: 0x01, 0x05, 0x00, 0x06, 0x64, 0x0f, 0x97
2019-07-18 15:00:04.298 Detail, contrlr, Received: 0x01, 0x05, 0x01, 0x06, 0x96, 0x0f, 0x64
2019-07-18 15:00:04.299 Detail,
2019-07-18 15:00:04.299 Info, contrlr, Received reply to FUNC_ID_SERIAL_API_SET_TIMEOUTS
2019-07-18 15:00:04.299 Detail, Node015, Expected reply was received
2019-07-18 15:00:04.299 Detail, Node015, Message transaction complete
2019-07-18 15:00:04.299 Detail,
2019-07-18 15:00:04.299 Detail, contrlr, Removing current message
2019-07-18 15:00:04.299 Detail,
2019-07-18 15:00:04.300 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x00) - FUNC_ID_SERIAL_API_APPL_NODE_INFORMATION: 0x01, 0x07, 0x00, 0x03, 0x01, 0x02, 0x01, 0x00, 0xf9
2019-07-18 15:00:04.301 Detail, contrlr, Removing current message
2019-07-18 15:00:04.301 Detail,
2019-07-18 15:00:04.301 Info, Node001, Sending (Command) message (Callback ID=0x00, Expected Reply=0x80) - Get Routing Info (Node=1): 0x01, 0x07, 0x00, 0x80, 0x01, 0x00, 0x00, 0x03, 0x7a
2019-07-18 15:00:04.306 Detail, Node001, Received: 0x01, 0x20, 0x01, 0x80, 0x02, 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, 0x00, 0x5c
2019-07-18 15:00:04.306 Detail,
2019-07-18 15:00:04.307 Info, Node001, Received reply to FUNC_ID_ZW_GET_ROUTING_INFO
2019-07-18 15:00:04.307 Info, Node001, Neighbors of this node are:
2019-07-18 15:00:04.307 Info, Node001, Node 2
2019-07-18 15:00:04.307 Detail, Expected reply was received
2019-07-18 15:00:04.307 Detail, Message transaction complete
2019-07-18 15:00:04.307 Detail,
2019-07-18 15:00:04.307 Detail, Node001, Removing current message
2019-07-18 15:00:04.307 Detail,
2019-07-18 15:00:25.035 Detail,
2019-07-18 15:00:25.035 Info, Node004, Sending (Query) message (Callback ID=0x00, Expected Reply=0x41) - Get Node Protocol Info (Node=4): 0x01, 0x04, 0x00, 0x41, 0x04, 0xbe
2019-07-18 15:00:25.038 Detail, Node004, Received: 0x01, 0x09, 0x01, 0x41, 0xd3, 0x9c, 0x01, 0x04, 0x11, 0x01, 0xec
2019-07-18 15:00:25.038 Detail,
2019-07-18 15:00:25.038 Info, Node004, Received reply to FUNC_ID_ZW_GET_NODE_PROTOCOL_INFO
2019-07-18 15:00:25.039 Info, Node004, Protocol Info for Node 4:
2019-07-18 15:00:25.039 Info, Node004, Listening = true
2019-07-18 15:00:25.039 Info, Node004, Beaming = true
2019-07-18 15:00:25.039 Info, Node004, Routing = true
2019-07-18 15:00:25.039 Info, Node004, Max Baud Rate = 40000
2019-07-18 15:00:25.039 Info, Node004, Version = 4
2019-07-18 15:00:25.039 Info, Node004, Security = false
2019-07-18 15:00:25.053 Info, Node004, Basic device class (0x04) - Routing Slave
2019-07-18 15:00:25.054 Info, Node004, Generic device Class (0x11) - Multilevel Switch
2019-07-18 15:00:25.054 Info, Node004, Specific device class (0x01) - Multilevel Power Switch
2019-07-18 15:00:25.054 Info, Node004, COMMAND_CLASS_BASIC will be mapped to COMMAND_CLASS_SWITCH_MULTILEVEL
2019-07-18 15:00:25.054 Info, Node004, Mandatory Command Classes for Node 4:
2019-07-18 15:00:25.054 Info, Node004, COMMAND_CLASS_BASIC
2019-07-18 15:00:25.054 Info, Node004, COMMAND_CLASS_SWITCH_MULTILEVEL
2019-07-18 15:00:25.054 Info, Node004, COMMAND_CLASS_SWITCH_ALL
2019-07-18 15:00:25.054 Info, Node004, Mandatory Command Classes controlled by Node 4:
2019-07-18 15:00:25.054 Info, Node004, None
2019-07-18 15:00:25.054 Detail, Node156, Expected reply was received
2019-07-18 15:00:25.054 Detail, Node156, Message transaction complete
2019-07-18 15:00:25.054 Detail,
2019-07-18 15:00:25.054 Detail, Node004, Removing current message
2019-07-18 15:00:25.055 Detail, Node004, Notification: NodeProtocolInfo
2019-07-18 15:00:25.057 Detail, Node004, Notification: ValueAdded
2019-07-18 15:00:25.067 Detail, Node004, Notification: ValueAdded
2019-07-18 15:00:25.074 Detail, Node004, Notification: ValueAdded
2019-07-18 15:00:25.077 Detail, Node004, Notification: ValueAdded
2019-07-18 15:00:25.079 Detail, Node004, Notification: ValueAdded
2019-07-18 15:00:25.084 Detail, Node004, Notification: ValueAdded
2019-07-18 15:00:25.086 Detail, Node004, Query Stage Complete (ProtocolInfo)
2019-07-18 15:00:25.086 Detail, Node004, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Probe live=1
2019-07-18 15:00:25.087 Detail, Node004, QueryStage_Probe
2019-07-18 15:00:25.087 Info, Node004, NoOperation::Set - Routing=true
2019-07-18 15:00:25.087 Detail, Node004, Queuing (NoOp) NoOperation_Set (Node=4): 0x01, 0x09, 0x00, 0x13, 0x04, 0x02, 0x00, 0x00, 0x25, 0x10, 0xd6
2019-07-18 15:00:25.087 Detail, Node004, Queuing (Query) Query Stage Complete (Probe)
2019-07-18 15:00:25.087 Detail,
2019-07-18 15:00:25.087 Info, Node004, Sending (NoOp) message (Callback ID=0x10, Expected Reply=0x13) - NoOperation_Set (Node=4): 0x01, 0x09, 0x00, 0x13, 0x04, 0x02, 0x00, 0x00, 0x25, 0x10, 0xd6
2019-07-18 15:00:25.100 Detail, Node004, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-07-18 15:00:25.100 Detail, Node004, ZW_SEND_DATA delivered to Z-Wave stack
2019-07-18 15:00:29.168 Detail, Node004, Received: 0x01, 0x07, 0x00, 0x13, 0x10, 0x01, 0x01, 0x97, 0x6c
2019-07-18 15:00:29.168 Detail, Node004, ZW_SEND_DATA Request with callback ID 0x10 received (expected 0x10)
2019-07-18 15:00:29.168 Info, Node004, WARNING: ZW_SEND_DATA failed. No ACK received - device may be asleep.
2019-07-18 15:00:29.168 Warning, Node004, WARNING: Device is not a sleeping node.
2019-07-18 15:00:29.168 Info, Node004, QueryStageRetry stage Probe requested stage Probe max 3 retries 0 pending 1
2019-07-18 15:00:29.168 Detail, Node001, Expected callbackId was received
2019-07-18 15:00:29.168 Detail, Node001, Expected reply was received
2019-07-18 15:00:29.169 Detail, Node001, Message transaction complete
2019-07-18 15:00:29.169 Detail,
2019-07-18 15:00:29.169 Detail, Node004, Removing current message
2019-07-18 15:00:29.169 Detail, Node004, Notification: Notification - NoOperation
2019-07-18 15:00:29.180 Detail, Node004, Query Stage Complete (Probe)
2019-07-18 15:00:29.180 Detail, Node004, AdvanceQueries queryPending=0 queryRetries=1 queryStage=Probe live=1
2019-07-18 15:00:29.180 Detail, Node004, QueryStage_Probe
2019-07-18 15:00:29.180 Info, Node004, NoOperation::Set - Routing=true
2019-07-18 15:00:29.180 Detail, Node004, Queuing (NoOp) NoOperation_Set (Node=4): 0x01, 0x09, 0x00, 0x13, 0x04, 0x02, 0x00, 0x00, 0x25, 0x11, 0xd7
2019-07-18 15:00:29.180 Detail, Node004, Queuing (Query) Query Stage Complete (Probe)
2019-07-18 15:00:29.180 Detail,
2019-07-18 15:00:29.181 Info, Node004, Sending (NoOp) message (Callback ID=0x11, Expected Reply=0x13) - NoOperation_Set (Node=4): 0x01, 0x09, 0x00, 0x13, 0x04, 0x02, 0x00, 0x00, 0x25, 0x11, 0xd7
2019-07-18 15:00:29.194 Detail, Node004, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-07-18 15:00:29.194 Detail, Node004, ZW_SEND_DATA delivered to Z-Wave stack
2019-07-18 15:00:33.321 Detail, Node004, Received: 0x01, 0x07, 0x00, 0x13, 0x11, 0x01, 0x01, 0x9e, 0x64
2019-07-18 15:00:33.322 Detail, Node004, ZW_SEND_DATA Request with callback ID 0x11 received (expected 0x11)
2019-07-18 15:00:33.322 Info, Node004, WARNING: ZW_SEND_DATA failed. No ACK received - device may be asleep.
2019-07-18 15:00:33.322 Warning, Node004, WARNING: Device is not a sleeping node.
2019-07-18 15:00:33.322 Info, Node004, QueryStageRetry stage Probe requested stage Probe max 3 retries 1 pending 1
2019-07-18 15:00:33.322 Detail, Node001, Expected callbackId was received
2019-07-18 15:00:33.322 Detail, Node001, Expected reply was received
2019-07-18 15:00:33.323 Detail, Node001, Message transaction complete
2019-07-18 15:00:33.323 Detail,
2019-07-18 15:00:33.323 Detail, Node004, Removing current message
2019-07-18 15:00:33.323 Detail, Node004, Notification: Notification - NoOperation
2019-07-18 15:00:33.329 Detail, Node004, Query Stage Complete (Probe)
2019-07-18 15:00:33.329 Detail, Node004, AdvanceQueries queryPending=0 queryRetries=2 queryStage=Probe live=1
2019-07-18 15:00:33.329 Detail, Node004, QueryStage_Probe
2019-07-18 15:00:33.329 Info, Node004, NoOperation::Set - Routing=true
2019-07-18 15:00:33.329 Detail, Node004, Queuing (NoOp) NoOperation_Set (Node=4): 0x01, 0x09, 0x00, 0x13, 0x04, 0x02, 0x00, 0x00, 0x25, 0x14, 0xd2
2019-07-18 15:00:33.330 Detail, Node004, Queuing (Query) Query Stage Complete (Probe)
2019-07-18 15:00:33.330 Detail,
2019-07-18 15:00:33.330 Info, Node004, Sending (NoOp) message (Callback ID=0x14, Expected Reply=0x13) - NoOperation_Set (Node=4): 0x01, 0x09, 0x00, 0x13, 0x04, 0x02, 0x00, 0x00, 0x25, 0x14, 0xd2
2019-07-18 15:00:33.343 Detail, Node004, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-07-18 15:00:33.343 Detail, Node004, ZW_SEND_DATA delivered to Z-Wave stack
2019-07-18 15:00:37.502 Detail, Node004, Received: 0x01, 0x07, 0x00, 0x13, 0x14, 0x01, 0x01, 0xa1, 0x5e
2019-07-18 15:00:37.502 Detail, Node004, ZW_SEND_DATA Request with callback ID 0x14 received (expected 0x14)
2019-07-18 15:00:37.502 Info, Node004, WARNING: ZW_SEND_DATA failed. No ACK received - device may be asleep.
2019-07-18 15:00:37.502 Warning, Node004, WARNING: Device is not a sleeping node.
2019-07-18 15:00:37.502 Error, Node004, ERROR: node presumed dead
2019-07-18 15:00:37.503 Warning, CheckCompletedNodeQueries m_allNodesQueried=0 m_awakeNodesQueried=0
2019-07-18 15:00:37.503 Warning, CheckCompletedNodeQueries all=0, deadFound=1 sleepingOnly=0
2019-07-18 15:00:37.503 Info, Node004, QueryStageRetry stage Probe requested stage Probe max 3 retries 2 pending 1
2019-07-18 15:00:37.503 Detail, Node001, Expected callbackId was received
2019-07-18 15:00:37.503 Detail, Node001, Expected reply was received
2019-07-18 15:00:37.503 Detail, Node001, Message transaction complete
2019-07-18 15:00:37.503 Detail,
2019-07-18 15:00:37.503 Detail, Node004, Removing current message
2019-07-18 15:00:37.503 Detail, Node004, Notification: Notification - NoOperation
2019-07-18 15:00:37.507 Detail, Node004, Notification: Notification - Node Dead
2019-07-18 15:00:58.326 Detail, Node004, Query Stage Complete (Probe)
2019-07-18 15:00:58.326 Detail, Node004, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Probe live=0
2019-07-18 15:00:58.327 Detail, Node002, Query Stage Complete (Dynamic)
2019-07-18 15:00:58.327 Detail, Node002, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Configuration live=1
2019-07-18 15:00:58.327 Detail, Node002, QueryStage_Configuration
2019-07-18 15:00:58.327 Detail, Node002, QueryStage_Complete
2019-07-18 15:00:58.327 Warning, CheckCompletedNodeQueries m_allNodesQueried=0 m_awakeNodesQueried=0
2019-07-18 15:00:58.327 Warning, CheckCompletedNodeQueries all=1, deadFound=1 sleepingOnly=1
2019-07-18 15:00:58.327 Info, Node query processing complete except for dead nodes.
2019-07-18 15:00:58.327 Detail, Node002, Notification: NodeQueriesComplete
2019-07-18 15:00:58.332 Detail, contrlr, Notification: AllNodesQueriedSomeDead

Thanks,

Daniel

4

What version of hassio are you using? I noticed that something was changed around 0.95 introduction in how the z-wave operates and this resulted in my fibaro dimmer 2 (exactly the same model as yours) to be broken. It was working perfectly fine before, but now I cannot control it from UI. It works when operated from hardwired button and reports properly its status back to hassio, but I found no way to control it - looking at log I see some messages being send to dimmer and being droped due to no response. Perhaps problem is broader and while using newer version of hassio it is not possible to add this specific device?
BTW, also Aeon Labs Nano Dimmer behaves now exactly the same way - switch entity on this node does not respond. All other z-wave devices I have work perfectly fine.
After reading your post, I doubt I want to try to remove/add again (which I planned) these devices, I might loose them for all…

5

Thanks Mirek
I running version Home assistant 0.89.2.

I forgot to mention that during startup the Home assistant log shows “Z-Wave entity Unknown Node 4 Level (node_id: 4) not ready after 30 seconds, continuing anyway”.

6

How many devices do you have and how far away from each other and the hub are they?

7

I have two. Right now they are too far apart from each other. But the problem was the same when both the devices and the RPI were in the same room. Right now the RPI is about 3m from the Fibaro device causing my problems.

Brgds
Daniel

8

Remove the node and readd it and post the OZW_Log.txt of the repairing process. This will help shed better light on the issue.

9

Thanks for your tips. Based on my interpretation of your suggestion I just tried the following sequence:

  1. For node 004 I pressed “Remove failed node” and then “Replace failed node”.
    After that I pressed “Heal node” (which gave an error message in HA). I finally pressed “Heal network”. This resulted in the OZW messages as shown below. I did not touch the Fibaro device during this process.

2019-07-18 21:42:03.210 Detail, Node004, Queuing (Controller) Remove Failed Node
2019-07-18 21:42:03.211 Info, ControllerCommand_RemoveFailedNode
2019-07-18 21:42:03.212 Detail, contrlr, Queuing (Command) ControllerCommand_RemoveFailedNode: 0x01, 0x05, 0x00, 0x61, 0x04, 0x1e, 0x81
2019-07-18 21:42:03.212 Detail, Notification: ControllerCommand - Starting
2019-07-18 21:42:03.215 Detail,
2019-07-18 21:42:03.215 Info, contrlr, Sending (Command) message (Callback ID=0x1e, Expected Reply=0x61) - ControllerCommand_RemoveFailedNode: 0x01, 0x05, 0x00, 0x61, 0x04, 0x1e, 0x81
2019-07-18 21:42:03.228 Detail, contrlr, Received: 0x01, 0x04, 0x01, 0x61, 0x00, 0x9b
2019-07-18 21:42:03.228 Detail,
2019-07-18 21:42:03.228 Info, contrlr, Received reply to FUNC_ID_ZW_REMOVE_FAILED_NODE_ID - Command in progress
2019-07-18 21:42:03.228 Detail, Node155, Expected reply was received
2019-07-18 21:42:03.228 Detail, Notification: ControllerCommand - InProgress
2019-07-18 21:42:03.408 Detail, contrlr, Received: 0x01, 0x05, 0x00, 0x61, 0x1e, 0x01, 0x84
2019-07-18 21:42:03.408 Detail,
2019-07-18 21:42:03.408 Info, contrlr, Received reply to FUNC_ID_ZW_REMOVE_FAILED_NODE_ID - node 4 successfully moved to failed nodes list
2019-07-18 21:42:03.408 Detail, Node001, Expected callbackId was received
2019-07-18 21:42:03.408 Detail, Node001, Message transaction complete
2019-07-18 21:42:03.409 Detail,
2019-07-18 21:42:03.409 Detail, contrlr, Removing current message
2019-07-18 21:42:03.409 Detail, Node004, Notification: ValueRemoved
2019-07-18 21:42:03.429 Detail, Node004, Notification: ValueRemoved
2019-07-18 21:42:03.435 Detail, Node004, Notification: ValueRemoved
2019-07-18 21:42:03.441 Detail, Node004, Notification: ValueRemoved
2019-07-18 21:42:03.446 Detail, Node004, Notification: ValueRemoved
2019-07-18 21:42:03.452 Detail, Node004, Notification: ValueRemoved
2019-07-18 21:42:03.458 Detail, Node004, Notification: NodeRemoved
2019-07-18 21:42:03.460 Detail, Notification: ControllerCommand - Completed
2019-07-18 21:42:28.447 Detail, Node004, Queuing (Controller) Replace Failed Node
2019-07-18 21:42:28.448 Info, Replace Failed Node 4
2019-07-18 21:42:28.448 Detail, contrlr, Queuing (Command) ControllerCommand_ReplaceFailedNode: 0x01, 0x05, 0x00, 0x63, 0x04, 0x1f, 0x82
2019-07-18 21:42:28.448 Detail, Notification: ControllerCommand - Starting
2019-07-18 21:42:28.453 Detail,
2019-07-18 21:42:28.453 Info, contrlr, Sending (Command) message (Callback ID=0x1f, Expected Reply=0x63) - ControllerCommand_ReplaceFailedNode: 0x01, 0x05, 0x00, 0x63, 0x04, 0x1f, 0x82
2019-07-18 21:42:28.456 Detail, contrlr, Received: 0x01, 0x04, 0x01, 0x63, 0x08, 0x91
2019-07-18 21:42:28.457 Detail,
2019-07-18 21:42:28.457 Warning, contrlr, WARNING: Received reply to FUNC_ID_ZW_REPLACE_FAILED_NODE - command failed
2019-07-18 21:42:28.457 Detail, Node145, Expected callbackId was received
2019-07-18 21:42:28.457 Detail, Node145, Message transaction complete
2019-07-18 21:42:28.457 Detail,
2019-07-18 21:42:28.457 Detail, contrlr, Removing current message
2019-07-18 21:42:28.457 Detail, Notification: ControllerCommand - Failed
2019-07-18 21:43:03.125 Detail, Node001, Queuing (Controller) Request Node Neighbor Update
2019-07-18 21:43:03.125 Detail, Node002, Queuing (Controller) Request Node Neighbor Update
2019-07-18 21:43:03.125 Info, Requesting Neighbor Update for node 1
2019-07-18 21:43:03.126 Detail, Node001, Queuing (Command) ControllerCommand_RequestNodeNeighborUpdate (Node=1): 0x01, 0x05, 0x00, 0x48, 0x01, 0x20, 0x93
2019-07-18 21:43:03.126 Detail, Notification: ControllerCommand - Starting
2019-07-18 21:43:03.133 Detail,
2019-07-18 21:43:03.133 Info, Node001, Sending (Command) message (Callback ID=0x20, Expected Reply=0x48) - ControllerCommand_RequestNodeNeighborUpdate (Node=1): 0x01, 0x05, 0x00, 0x48, 0x01, 0x20, 0x93
2019-07-18 21:43:03.295 Detail, Node001, Received: 0x01, 0x05, 0x00, 0x48, 0x20, 0x21, 0xb3
2019-07-18 21:43:03.295 Detail,
2019-07-18 21:43:03.295 Info, Node001, REQUEST_NEIGHBOR_UPDATE_STARTED
2019-07-18 21:43:03.296 Detail, Node033, Expected callbackId was received
2019-07-18 21:43:03.296 Detail, Node033, Expected reply was received
2019-07-18 21:43:03.296 Detail, Node033, Message transaction complete
2019-07-18 21:43:03.296 Detail,
2019-07-18 21:43:03.296 Detail, Node001, Removing current message
2019-07-18 21:43:03.296 Detail, Notification: ControllerCommand - InProgress
2019-07-18 21:43:03.302 Info, WriteNextMsg Controller nothing to do
2019-07-18 21:43:12.976 Detail, Received: 0x01, 0x05, 0x00, 0x48, 0x20, 0x23, 0xb1
2019-07-18 21:43:12.976 Detail,
2019-07-18 21:43:12.976 Warning, WARNING: REQUEST_NEIGHBOR_UPDATE_FAILED
2019-07-18 21:43:12.976 Detail, Notification: ControllerCommand - Failed
2019-07-18 21:43:12.978 Info, Requesting Neighbor Update for node 2
2019-07-18 21:43:12.978 Detail, Node002, Queuing (Command) ControllerCommand_RequestNodeNeighborUpdate (Node=2): 0x01, 0x05, 0x00, 0x48, 0x02, 0x21, 0x91
2019-07-18 21:43:12.978 Detail, Notification: ControllerCommand - Starting
2019-07-18 21:43:12.979 Detail,
2019-07-18 21:43:12.979 Info, Node002, Sending (Command) message (Callback ID=0x21, Expected Reply=0x48) - ControllerCommand_RequestNodeNeighborUpdate (Node=2): 0x01, 0x05, 0x00, 0x48, 0x02, 0x21, 0x91
2019-07-18 21:43:13.012 Detail, Node002, Received: 0x01, 0x05, 0x00, 0x48, 0x21, 0x21, 0xb2
2019-07-18 21:43:13.012 Detail,
2019-07-18 21:43:13.013 Info, Node002, REQUEST_NEIGHBOR_UPDATE_STARTED
2019-07-18 21:43:13.013 Detail, Node033, Expected callbackId was received
2019-07-18 21:43:13.013 Detail, Node033, Expected reply was received
2019-07-18 21:43:13.013 Detail, Node033, Message transaction complete
2019-07-18 21:43:13.013 Detail,
2019-07-18 21:43:13.013 Detail, Node002, Removing current message
2019-07-18 21:43:13.013 Detail, Notification: ControllerCommand - InProgress
2019-07-18 21:43:13.019 Info, WriteNextMsg Controller nothing to do
2019-07-18 21:43:13.537 Detail, Received: 0x01, 0x05, 0x00, 0x48, 0x21, 0x23, 0xb0
2019-07-18 21:43:13.538 Detail,
2019-07-18 21:43:13.538 Warning, WARNING: REQUEST_NEIGHBOR_UPDATE_FAILED
2019-07-18 21:43:13.538 Detail, Notification: ControllerCommand - Failed

Thanks
Daniel

10

By the way. After I did the “replace node” thing I notice there is one difference . Before the node was presumed dead. Now it’s stuck initializing. When I open the Node information window I also notice that now the node is not failed which is was before. But not ready either.

Sk%C3%A4rmklipp
Sk%C3%A4rmklipp365×679 33.4 KB

//Daniel

11

Anyone that can shed some light over this issue as explained above?

Brgds
Daniel

12

Quick update: I bought another identical Fibaro unit and did the exact same procedure by adding the new node from the HA interface (not via the button on the Aeotec stick). For some reason it worked right away. I’ve repeated these steps with the old unit several times more after that with the same unsuccessful result. So in summary, one node keeps failing, the other, identical works perfectly. No idea why.

13

Sounds like defective/dead hardware then on your failed node.
You could try a factory reset on it, that might help.