Aeon Labs ZW117 Range Extender 6 marked dead

cexshun · October 19, 2019, 6:18pm

I have a problem corner of the basement, so I added a range extender. The extender added with no problem.

However, Home Assistant is marking the node dead as OpenZwave seems to be sending the extender a lot of requests that simply aren’t supported as it’s only an extender.

So my question is, since the unit is marked dead, will it still relay communication between nodes? Log below.

2019-10-19 13:03:13.447 Info, Node059, Sending (NoOp) message (Callback ID=0x26, Expected Reply=0x13) - NoOperation_Set (Node=59): 0x01, 0x09, 0x00, 0x13, 0x3b, 0x02, 0x00, 0x00, 0x25, 0x26, 0xdf
2019-10-19 13:03:13.456 Detail, Node059,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-10-19 13:03:13.456 Detail, Node059,   ZW_SEND_DATA delivered to Z-Wave stack
2019-10-19 13:03:13.495 Detail, Node059,   Received: 0x01, 0x07, 0x00, 0x13, 0x26, 0x00, 0x00, 0x05, 0xc8
2019-10-19 13:03:13.495 Detail, Node059,   ZW_SEND_DATA Request with callback ID 0x26 received (expected 0x26)
2019-10-19 13:03:13.496 Info, Node059, Request RTT 48 Average Request RTT 48
2019-10-19 13:03:13.497 Detail, Node059, Removing current message
2019-10-19 13:03:13.497 Detail, Node059, Notification: Notification - NoOperation
2019-10-19 13:03:44.720 Detail, Node059, Queuing (Command) ControllerCommand_DeleteAllReturnRoutess (Node=59): 0x01, 0x05, 0x00, 0x47, 0x3b, 0x4a, 0xcc
2019-10-19 13:03:44.724 Info, Node059, Sending (Command) message (Callback ID=0x4a, Expected Reply=0x47) - ControllerCommand_DeleteAllReturnRoutess (Node=59): 0x01, 0x05, 0x00, 0x47, 0x3b, 0x4a, 0xcc
2019-10-19 13:03:44.732 Detail, Node059,   Received: 0x01, 0x04, 0x01, 0x47, 0x01, 0xbc
2019-10-19 13:03:44.732 Info, Node059, Received reply to FUNC_ID_ZW_DELETE_RETURN_ROUTE - command in progress
2019-10-19 13:03:46.261 Detail, Node059,   Received: 0x01, 0x05, 0x00, 0x47, 0x4a, 0x00, 0xf7
2019-10-19 13:03:46.268 Info, Node059, Received reply to FUNC_ID_ZW_DELETE_RETURN_ROUTE for node 59 - SUCCESS
2019-10-19 13:03:46.270 Detail, Node059, Removing current message
2019-10-19 13:03:46.275 Detail, Node059, Queuing (Command) ControllerCommand_AssignReturnRoute (Node=59): 0x01, 0x06, 0x00, 0x46, 0x3b, 0x01, 0x4b, 0xce
2019-10-19 13:03:46.280 Info, Node059, Sending (Command) message (Callback ID=0x4b, Expected Reply=0x46) - ControllerCommand_AssignReturnRoute (Node=59): 0x01, 0x06, 0x00, 0x46, 0x3b, 0x01, 0x4b, 0xce
2019-10-19 13:03:47.387 Detail, Node059,   Received: 0x01, 0x04, 0x01, 0x46, 0x01, 0xbd
2019-10-19 13:03:47.389 Info, Node059, Received reply to FUNC_ID_ZW_ASSIGN_RETURN_ROUTE - command in progress
2019-10-19 13:03:48.705 Detail, Node059,   Received: 0x01, 0x05, 0x00, 0x46, 0x4b, 0x00, 0xf7
2019-10-19 13:03:48.706 Info, Node059, Received reply to FUNC_ID_ZW_ASSIGN_RETURN_ROUTE for node 59 - SUCCESS
2019-10-19 13:03:48.708 Detail, Node059, Removing current message
2019-10-19 13:04:12.780 Detail, Node059, Query Stage Complete (CacheLoad)
2019-10-19 13:04:12.780 Detail, Node059, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Associations live=1
2019-10-19 13:04:12.781 Detail, Node059, QueryStage_Associations
2019-10-19 13:04:12.781 Info, Node059, Number of association groups reported for node 59 is 1.
2019-10-19 13:04:12.781 Info, Node059, Get Associations for group 1 of node 59
2019-10-19 13:04:12.781 Detail, Node059, Queuing (Send) AssociationCmd_Get (Node=59): 0x01, 0x0a, 0x00, 0x13, 0x3b, 0x03, 0x85, 0x02, 0x01, 0x25, 0x6d, 0x10
2019-10-19 13:04:12.781 Detail, Node059, Queuing (Query) Query Stage Complete (Associations)
2019-10-19 13:04:12.781 Info, Node059, Sending (Send) message (Callback ID=0x6d, Expected Reply=0x04) - AssociationCmd_Get (Node=59): 0x01, 0x0a, 0x00, 0x13, 0x3b, 0x03, 0x85, 0x02, 0x01, 0x25, 0x6d, 0x10
2019-10-19 13:04:12.790 Detail, Node059,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-10-19 13:04:12.790 Detail, Node059,   ZW_SEND_DATA delivered to Z-Wave stack
2019-10-19 13:04:22.782 Error, Node059, ERROR: Dropping command, expected response not received after 1 attempt(s)
2019-10-19 13:04:22.783 Detail, Node059, Removing current message
2019-10-19 13:04:22.783 Detail, Node059, Notification: Notification - TimeOut
2019-10-19 13:04:24.165 Detail, Node059, Query Stage Complete (Associations)
2019-10-19 13:04:24.165 Detail, Node059, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Neighbors live=1
2019-10-19 13:04:24.165 Detail, Node059, QueryStage_Neighbors
2019-10-19 13:04:24.165 Detail, Node059, Queuing (Command) Get Routing Info (Node=59): 0x01, 0x07, 0x00, 0x80, 0x3b, 0x00, 0x00, 0x03, 0x40
2019-10-19 13:04:24.165 Detail, Node059, Queuing (Query) Query Stage Complete (Neighbors)
2019-10-19 13:04:24.166 Info, Node059, Sending (Command) message (Callback ID=0x00, Expected Reply=0x80) - Get Routing Info (Node=59): 0x01, 0x07, 0x00, 0x80, 0x3b, 0x00, 0x00, 0x03, 0x40
2019-10-19 13:04:24.170 Detail, Node059,   Received: 0x01, 0x20, 0x01, 0x80, 0x84, 0x01, 0x38, 0x00, 0x16, 0x40, 0x08, 0x02, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0xbf
2019-10-19 13:04:24.171 Info, Node059, Received reply to FUNC_ID_ZW_GET_ROUTING_INFO
2019-10-19 13:04:24.171 Info, Node059,     Neighbors of this node are:
2019-10-19 13:04:24.171 Info, Node059,     Node 3
2019-10-19 13:04:24.171 Info, Node059,     Node 8
2019-10-19 13:04:24.171 Info, Node059,     Node 9
2019-10-19 13:04:24.171 Info, Node059,     Node 20
2019-10-19 13:04:24.171 Info, Node059,     Node 21
2019-10-19 13:04:24.171 Info, Node059,     Node 22
2019-10-19 13:04:24.171 Info, Node059,     Node 34
2019-10-19 13:04:24.171 Info, Node059,     Node 35
2019-10-19 13:04:24.171 Info, Node059,     Node 37
2019-10-19 13:04:24.171 Info, Node059,     Node 47
2019-10-19 13:04:24.172 Info, Node059,     Node 52
2019-10-19 13:04:24.172 Info, Node059,     Node 58
2019-10-19 13:04:24.172 Detail, Node059, Removing current message
2019-10-19 13:04:26.268 Detail, Node059, Query Stage Complete (Neighbors)
2019-10-19 13:04:26.268 Detail, Node059, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Session live=1
2019-10-19 13:04:26.268 Detail, Node059, QueryStage_Session
2019-10-19 13:04:26.268 Detail, Node059, Queuing (Query) PowerlevelCmd_Get (Node=59): 0x01, 0x09, 0x00, 0x13, 0x3b, 0x02, 0x73, 0x02, 0x25, 0xa8, 0x20
2019-10-19 13:04:26.268 Detail, Node059, Queuing (Query) Query Stage Complete (Session)
2019-10-19 13:05:34.591 Info, Node059, Sending (Query) message (Callback ID=0xa8, Expected Reply=0x04) - PowerlevelCmd_Get (Node=59): 0x01, 0x09, 0x00, 0x13, 0x3b, 0x02, 0x73, 0x02, 0x25, 0xa8, 0x20
2019-10-19 13:05:35.606 Detail, Node059,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-10-19 13:05:35.606 Detail, Node059,   ZW_SEND_DATA delivered to Z-Wave stack
2019-10-19 13:05:44.592 Error, Node059, ERROR: Dropping command, expected response not received after 1 attempt(s)
2019-10-19 13:05:44.592 Detail, Node059, Removing current message
2019-10-19 13:05:44.592 Detail, Node059, Notification: Notification - TimeOut
2019-10-19 13:05:44.598 Detail, Node059, Query Stage Complete (Session)
2019-10-19 13:05:44.598 Detail, Node059, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Dynamic live=1
2019-10-19 13:05:44.598 Detail, Node059, QueryStage_Dynamic
2019-10-19 13:05:44.598 Info, Node059, BasicCmd_Get Not Supported on this node
2019-10-19 13:05:44.598 Detail, Node059, Queuing (Send) SwitchMultilevelCmd_Get (Node=59): 0x01, 0x09, 0x00, 0x13, 0x3b, 0x02, 0x26, 0x02, 0x25, 0xe1, 0x3c
2019-10-19 13:05:44.599 Detail, Node059, Queuing (Send) ColorCmd_Get (Node=59): 0x01, 0x0a, 0x00, 0x13, 0x3b, 0x03, 0x33, 0x03, 0x02, 0x25, 0xe2, 0x2b
2019-10-19 13:05:44.599 Detail, Node059, Queuing (Send) ColorCmd_Get (Node=59): 0x01, 0x0a, 0x00, 0x13, 0x3b, 0x03, 0x33, 0x03, 0x03, 0x25, 0xe3, 0x2b
2019-10-19 13:05:44.599 Detail, Node059, Queuing (Send) ColorCmd_Get (Node=59): 0x01, 0x0a, 0x00, 0x13, 0x3b, 0x03, 0x33, 0x03, 0x04, 0x25, 0xe4, 0x2b
2019-10-19 13:05:44.599 Detail, Node059, Queuing (Query) Query Stage Complete (Dynamic)
2019-10-19 13:05:44.600 Info, Node059, Sending (Send) message (Callback ID=0xe1, Expected Reply=0x04) - SwitchMultilevelCmd_Get (Node=59): 0x01, 0x09, 0x00, 0x13, 0x3b, 0x02, 0x26, 0x02, 0x25, 0xe1, 0x3c
2019-10-19 13:05:45.615 Detail, Node059,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-10-19 13:05:45.615 Detail, Node059,   ZW_SEND_DATA delivered to Z-Wave stack
2019-10-19 13:05:45.645 Detail, Node059,   Received: 0x01, 0x07, 0x00, 0x13, 0xe1, 0x01, 0x00, 0x68, 0x63
2019-10-19 13:05:45.645 Detail, Node059,   ZW_SEND_DATA Request with callback ID 0xe1 received (expected 0xe1)
2019-10-19 13:05:45.645 Info, Node059, WARNING: ZW_SEND_DATA failed. No ACK received - device may be asleep.
2019-10-19 13:05:45.645 Warning, Node059, WARNING: Device is not a sleeping node.
2019-10-19 13:05:54.601 Error, Node059, ERROR: Dropping command, expected response not received after 1 attempt(s)
2019-10-19 13:05:54.601 Detail, Node059, Removing current message
2019-10-19 13:05:54.601 Detail, Node059, Notification: Notification - TimeOut
2019-10-19 13:05:54.612 Info, Node059, Sending (Send) message (Callback ID=0xe2, Expected Reply=0x04) - ColorCmd_Get (Node=59): 0x01, 0x0a, 0x00, 0x13, 0x3b, 0x03, 0x33, 0x03, 0x02, 0x25, 0xe2, 0x2b
2019-10-19 13:05:54.736 Detail, Node059,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-10-19 13:05:54.737 Detail, Node059,   ZW_SEND_DATA delivered to Z-Wave stack
2019-10-19 13:05:58.387 Detail, Node059,   Received: 0x01, 0x07, 0x00, 0x13, 0xe2, 0x01, 0x01, 0x79, 0x70
2019-10-19 13:05:58.387 Detail, Node059,   ZW_SEND_DATA Request with callback ID 0xe2 received (expected 0xe2)
2019-10-19 13:05:58.387 Info, Node059, WARNING: ZW_SEND_DATA failed. No ACK received - device may be asleep.
2019-10-19 13:05:58.387 Warning, Node059, WARNING: Device is not a sleeping node.
2019-10-19 13:06:04.612 Error, Node059, ERROR: Dropping command, expected response not received after 1 attempt(s)
2019-10-19 13:06:04.613 Detail, Node059, Removing current message
2019-10-19 13:06:04.613 Detail, Node059, Notification: Notification - TimeOut
2019-10-19 13:06:04.624 Info, Node059, Sending (Send) message (Callback ID=0xe3, Expected Reply=0x04) - ColorCmd_Get (Node=59): 0x01, 0x0a, 0x00, 0x13, 0x3b, 0x03, 0x33, 0x03, 0x03, 0x25, 0xe3, 0x2b
2019-10-19 13:06:04.749 Detail, Node059,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-10-19 13:06:04.750 Detail, Node059,   ZW_SEND_DATA delivered to Z-Wave stack
2019-10-19 13:06:08.497 Detail, Node059,   Received: 0x01, 0x07, 0x00, 0x13, 0xe3, 0x01, 0x01, 0x83, 0x8b
2019-10-19 13:06:08.497 Detail, Node059,   ZW_SEND_DATA Request with callback ID 0xe3 received (expected 0xe3)
2019-10-19 13:06:08.497 Info, Node059, WARNING: ZW_SEND_DATA failed. No ACK received - device may be asleep.
2019-10-19 13:06:08.498 Warning, Node059, WARNING: Device is not a sleeping node.
2019-10-19 13:06:08.498 Error, Node059, ERROR: node presumed dead
2019-10-19 13:06:08.498 Detail, Node059, Notification: Notification - Node Dead
2019-10-19 13:06:14.624 Error, Node059, ERROR: Dropping command because node is presumed dead
2019-10-19 13:06:14.624 Detail, Node059, Removing current message
2019-10-19 13:06:14.625 Detail, Node059, Notification: Notification - TimeOut
2019-10-19 13:06:14.635 Error, Node059, ERROR: Dropping command because node is presumed dead
2019-10-19 13:06:14.636 Detail, Node059, Removing current message
2019-10-19 13:06:39.200 Detail, Node059, Query Stage Complete (Dynamic)
2019-10-19 13:06:39.200 Detail, Node059, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Configuration live=0

A320Peter · October 19, 2019, 6:25pm

I don’t think so. But then something is wrong with the setup. I used this extender multiple times without any problem. Rarely and occasionally I had it marked as ‘dead’ after a restart or a power failure just like any other node can die, but a full reboot of my Raspi always solves the problem and they come back. Sometimes unplugging the extender’s power for a minute also helps.

cexshun · October 19, 2019, 6:29pm

Looking at the logs, it seems OpenZwave thinks it’s a light/switch. It’s sending it Switch and Color commands, which fail. And those failures get it marked as dead. No idea what’s going on.

A320Peter · October 19, 2019, 6:43pm

I suggest to exclude the device from the network by using the Aeon stick and not by software. Reboot the computer not just HA and try to add it to the network again.

cexshun · October 19, 2019, 11:02pm

Cancel that. It just died again.

2019-10-19 14:13:13.116 Detail, Node060, QueryStage_Session
2019-10-19 14:13:13.116 Detail, Node060, Queuing (Query) PowerlevelCmd_Get (Node=60): 0x01, 0x09, 0x00, 0x13, 0x3c, 0x02, 0x73, 0x02, 0x25, 0xe4, 0x6b
2019-10-19 14:13:13.116 Detail, Node060, Queuing (Query) Query Stage Complete (Session)
2019-10-19 14:13:38.603 Info, Node060, Sending (Query) message (Callback ID=0xe4, Expected Reply=0x04) - PowerlevelCmd_Get (Node=60): 0x01, 0x09, 0x00, 0x13, 0x3c, 0x02, 0x73, 0x02, 0x25, 0xe4, 0x6b
2019-10-19 14:13:39.619 Detail, Node060,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-10-19 14:13:39.619 Detail, Node060,   ZW_SEND_DATA delivered to Z-Wave stack
2019-10-19 14:13:48.604 Error, Node060, ERROR: Dropping command, expected response not received after 1 attempt(s)
2019-10-19 14:13:48.605 Detail, Node060, Removing current message
2019-10-19 14:13:48.605 Detail, Node060, Notification: Notification - TimeOut
2019-10-19 14:13:48.616 Detail, Node060, Query Stage Complete (Session)
2019-10-19 14:13:48.616 Detail, Node060, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Dynamic live=1
2019-10-19 14:13:48.616 Detail, Node060, QueryStage_Dynamic
2019-10-19 14:13:48.616 Info, Node060, BasicCmd_Get Not Supported on this node
2019-10-19 14:13:48.616 Detail, Node060, Queuing (Send) SwitchMultilevelCmd_Get (Node=60): 0x01, 0x09, 0x00, 0x13, 0x3c, 0x02, 0x26, 0x02, 0x25, 0xed, 0x37
2019-10-19 14:13:48.617 Detail, Node060, Queuing (Send) ColorCmd_Get (Node=60): 0x01, 0x0a, 0x00, 0x13, 0x3c, 0x03, 0x33, 0x03, 0x02, 0x25, 0xee, 0x20
2019-10-19 14:13:48.617 Detail, Node060, Queuing (Send) ColorCmd_Get (Node=60): 0x01, 0x0a, 0x00, 0x13, 0x3c, 0x03, 0x33, 0x03, 0x03, 0x25, 0xef, 0x20
2019-10-19 14:13:48.617 Detail, Node060, Queuing (Send) ColorCmd_Get (Node=60): 0x01, 0x0a, 0x00, 0x13, 0x3c, 0x03, 0x33, 0x03, 0x04, 0x25, 0xf0, 0x38
2019-10-19 14:13:48.617 Detail, Node060, Queuing (Query) Query Stage Complete (Dynamic)
2019-10-19 14:13:48.617 Info, Node060, Sending (Send) message (Callback ID=0xed, Expected Reply=0x04) - SwitchMultilevelCmd_Get (Node=60): 0x01, 0x09, 0x00, 0x13, 0x3c, 0x02, 0x26, 0x02, 0x25, 0xed, 0x37
2019-10-19 14:13:49.633 Detail, Node060,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-10-19 14:13:49.633 Detail, Node060,   ZW_SEND_DATA delivered to Z-Wave stack
2019-10-19 14:13:49.663 Detail, Node060,   Received: 0x01, 0x07, 0x00, 0x13, 0xed, 0x01, 0x00, 0x68, 0x6f
2019-10-19 14:13:49.663 Detail, Node060,   ZW_SEND_DATA Request with callback ID 0xed received (expected 0xed)
2019-10-19 14:13:49.663 Info, Node060, WARNING: ZW_SEND_DATA failed. No ACK received - device may be asleep.
2019-10-19 14:13:49.663 Warning, Node060, WARNING: Device is not a sleeping node.
2019-10-19 14:13:58.618 Error, Node060, ERROR: Dropping command, expected response not received after 1 attempt(s)
2019-10-19 14:13:58.619 Detail, Node060, Removing current message
2019-10-19 14:13:58.619 Detail, Node060, Notification: Notification - TimeOut
2019-10-19 14:13:58.630 Info, Node060, Sending (Send) message (Callback ID=0xee, Expected Reply=0x04) - ColorCmd_Get (Node=60): 0x01, 0x0a, 0x00, 0x13, 0x3c, 0x03, 0x33, 0x03, 0x02, 0x25, 0xee, 0x20
2019-10-19 14:13:58.756 Detail, Node060,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-10-19 14:13:58.756 Detail, Node060,   ZW_SEND_DATA delivered to Z-Wave stack
2019-10-19 14:13:59.098 Detail, Node060,   Received: 0x01, 0x07, 0x00, 0x13, 0xee, 0x01, 0x00, 0x2f, 0x2b
2019-10-19 14:13:59.098 Detail, Node060,   ZW_SEND_DATA Request with callback ID 0xee received (expected 0xee)
2019-10-19 14:13:59.099 Info, Node060, WARNING: ZW_SEND_DATA failed. No ACK received - device may be asleep.
2019-10-19 14:13:59.099 Warning, Node060, WARNING: Device is not a sleeping node.
2019-10-19 14:13:59.099 Error, Node060, ERROR: node presumed dead
2019-10-19 14:13:59.099 Detail, Node060, Notification: Notification - Node Dead
2019-10-19 14:14:08.630 Error, Node060, ERROR: Dropping command because node is presumed dead
2019-10-19 14:14:08.631 Detail, Node060, Removing current message
2019-10-19 14:14:08.631 Detail, Node060, Notification: Notification - TimeOut
2019-10-19 14:14:08.642 Error, Node060, ERROR: Dropping command because node is presumed dead
2019-10-19 14:14:08.642 Detail, Node060, Removing current message
2019-10-19 14:14:08.643 Error, Node060, ERROR: Dropping command because node is presumed dead
2019-10-19 14:14:08.643 Detail, Node060, Removing current message
2019-10-19 14:14:12.871 Detail, Node060, Query Stage Complete (Dynamic)
2019-10-19 14:14:12.871 Detail, Node060, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Configuration live=0

A320Peter · October 19, 2019, 11:08pm

Very strange. Have you updated HA recently? Which version you have?

To check if it is relaying messages despite the fact it’s dead, you may try to set parameter 82 to ON in the Node Config Options. The green LED will flash each time a message is relayed. Probably you have to reset and readd it again to be marked as not dead before you can change config parameters.

cexshun · October 19, 2019, 11:11pm

I’m on 99.3

The extender is running v1.05. What version is yours?