Problem with Fibaro FGS221

Hello,

I’ve been using a fibaro relay switch FGS221 for a time without any problem, but since I updated to openhab 1.8.1 (running in a raspberry pi2) I’m having problems. I’m not really sure the problem is related with the upgrade, but problems started at the same time than the upgrade.

The problem I’m having is that in habmin the device is shown as FAILED DONE. In the log file I get messages like:

2016-03-14 00:01:26.208 [ERROR] [WaveController$ZWaveSendThread] - NODE 15: Timeout while sending message. Requeueing - 2 attempts left!
2016-03-14 00:01:26.209 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 15: Got an error while sending data. Resending message.
2016-03-14 00:01:30.091 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 15: Got an error while sending data. Resending message.
2016-03-14 00:02:26.059 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 15: Got an error while sending data. Resending message.



2016-03-14 00:04:45.713 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 15: Node is DEAD. Dropping message.
2016-03-14 00:04:45.722 [WARN ] [i.p.s.IsFailedNodeMessageClass] - NODE 15: Is currently marked as failed by the controller!
2016-03-14 00:04:45.733 [WARN ] [i.p.s.IsFailedNodeMessageClass] - NODE 15: Is currently marked as failed by the controller!
2016-03-14 00:04:53.046 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 15: Got an error while sending data. Resending message.
2016-03-14 00:04:53.846 [WARN ] [b.z.i.p.s.SendDataMessageClass] - NODE 15: Already processed another send data request for this callback Id, ignoring.

2016-03-14 03:14:13.590 [ERROR] [.DeleteReturnRouteMessageClass] - NODE 15: Delete return routes failed with error 0x1.

2016-03-14 07:19:11.304 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 15: Node is DEAD. Dropping message.
2016-03-14 07:19:16.616 [ERROR] [NodeNeighborUpdateMessageClass] - NODE 15: NodeNeighborUpdate FAILED
2016-03-14 07:19:25.741 [ERROR] [NodeNeighborUpdateMessageClass] - NODE 15: NodeNeighborUpdate FAILED
2016-03-14 07:19:31.310 [ERROR] [NodeNeighborUpdateMessageClass] - NODE 15: NodeNeighborUpdate FAILED
2016-03-14 07:19:36.463 [ERROR] [NodeNeighborUpdateMessageClass] - NODE 15: NodeNeighborUpdate FAILED
2016-03-14 07:19:41.000 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 15: Node is DEAD. Dropping message.

I tried to reset the device and then it started working fine, but after a while is marked as failed again.

And althoug the device is marked as failed, I can still control its light (switching it on and off) without any problem. The problem is that a scheduled actions I have are not working.

I have attached a screenshot of my zwave network, where device 15 is the problematic fibaro FGS221.

Any help?

The ‘failed’ status comes from the controller itself. I don’t completely know what triggers it - maybe the device can receive your commands, but it is not responding properly. I also see that openhab also thinks the device is DEAD - this is caused by openhab not receiving a response…

So, if I had to guess, I would guess that the device can receive, but when it responds, it is not being received by the controller.

But then, why I can manage it? Or why its state updates are shown in openhab?

Sorry - I’m not sure what you mean by this? Do you mean that you are able to receive back status updates?

All I can tell from the log is the following -:

  • the controller thinks the device has failed. This is normally a good indication that the devie is in a bad state.
  • openhab is seeing timeouts - this means that either the device isn’t receiving the message, -or-, openhab isn’t receiving the response
  • you say that the device can be controlled ok, so this means messages are getting -to- the device, but it doesn’t mean the responses are getting back

That’s about all I can say - a debug log might help, but possibly not…

Yes, I receive updates. If I turn it on/off from Openhab, the light is switched on/off. If I turn it on/off manually, Openhab is updated and shows itsb correct state.

All this while habmin shows it as failed.

Well, it must be unreliable then since I saw in the log above that there are timeouts. Maybe it’s not very reliable and should be closer to the controller.

As I mentioned above, the fact that the controller is saying the device has failed is nothing to do with HABmin or the binding, and normally indicates serious problems communicating with the device, although I don’t know exactly what criteria it uses. Given both the controller AND HABmin think there are problems, I think it’s fair to assume that everything can’t be running quite as well as you think :wink:

Hi @chris
My Healing process always fails at 2 am:
logs are:

       2017-01-04 02:00:14.178 [ERROR] [NodeNeighborUpdateMessageClass] - NODE 1: NodeNeighborUpdate FAILED
       2017-01-04 02:00:22.463 [ERROR] [NodeNeighborUpdateMessageClass] - NODE 1: NodeNeighborUpdate FAILED
       2017-01-04 02:00:30.748 [ERROR] [NodeNeighborUpdateMessageClass] - NODE 1: NodeNeighborUpdate FAILED
      2017-01-04 02:00:39.033 [ERROR] [NodeNeighborUpdateMessageClass] - NODE 1: NodeNeighborUpdate FAILED
     2017-01-04 07:19:34.308 [WARN ] [.i.p.c.ZWaveSecureNonceTracker] - NODE 141: Received new nonce from device, ejecting Nonce RECEIVED   CF A9 E0 72 A2 BD 65 56 ; time left=4942.
    2017-01-04 07:19:34.396 [INFO ] [.p.c.ZWaveDoorLockCommandClass] - NODE 141: Door Lock report - lockState = 0x00,handlesMode = 0x10, doorCondition = 0x02, lockTimeoutMinutes = 0xfe,lockTimeoutSeconds = 0xfe
     2017-01-04 07:19:39.403 [ERROR] [WaveController$ZWaveSendThread] - NODE 141: Timeout while sending message. Requeueing - 2 attempts left!
   2017-01-04 07:19:39.404 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 141: Got an error while sending data. Resending message: Message: class = SendData (0x13), type = Request (0x00), payload = 8D 02 80 02 , callbackid = 194
 2017-01-04 12:36:43.205 [ERROR] [WaveController$ZWaveSendThread] - NODE 255: Timeout while sending message. Requeueing - 2 attempts left!
 2017-01-04 12:36:48.237 [ERROR] [WaveController$ZWaveSendThread] - NODE 255: Timeout while sending message. Requeueing - 1 attempts left!
  2017-01-04 12:36:51.088 [ERROR] [.DeleteReturnRouteMessageClass] - NODE 147: Delete return routes failed with error 0x1.
      2017-01-04 12:36:53.239 [ERROR] [WaveController$ZWaveSendThread] - NODE 255: Timeout while sending message. Requeueing - 0 attempts left!
      2017-01-04 12:36:55.858 [ERROR] [.DeleteReturnRouteMessageClass] - NODE 147: Delete return routes failed with error 0x1.
      2017-01-04 12:36:58.241 [WARN ] [WaveController$ZWaveSendThread] - NODE 255: Too many retries. Discarding message: Message: class = DeleteReturnRoute (0x47), type = Request (0x00), payload = 93 , callbackid = 0
     2017-01-04 12:37:00.872 [ERROR] [.AssignReturnRouteMessageClass] - NODE 147: Assign return routes failed.  

i don’t know why this happens…?

Can i stop this healing process…?

So this is just the FGS221 that’s failing? What are the other nodes in the log? (sorry - I’m just a bit confused if this is really related to the FDG221 thread from 9 months ago?)

Hi @chris
actually above logs are for FGS222

i am pasting complete logs

Node neighbour update failed for all devices

2017-01-04 02:00:14.178 [ERROR] [NodeNeighborUpdateMessageClass] - NODE 1: NodeNeighborUpdate FAILED
 2017-01-04 02:00:22.463 [ERROR] [NodeNeighborUpdateMessageClass] - NODE 1: NodeNeighborUpdate FAILED
2017-01-04 02:00:30.748 [ERROR] [NodeNeighborUpdateMessageClass] - NODE 1: NodeNeighborUpdate FAILED
2017-01-04 02:00:39.033 [ERROR] [NodeNeighborUpdateMessageClass] - NODE 1: NodeNeighborUpdate FAILED
2017-01-04 07:19:34.308 [WARN ] [.i.p.c.ZWaveSecureNonceTracker] - NODE 141: Received new nonce from device, ejecting Nonce RECEIVED   CF A9 E0 72 A2 BD 65 56 ; time left=4942.
2017-01-04 07:19:34.396 [INFO ] [.p.c.ZWaveDoorLockCommandClass] - NODE 141: Door Lock report - lockState = 0x00,handlesMode = 0x10, doorCondition = 0x02, lockTimeoutMinutes = 0xfe,lockTimeoutSeconds = 0xfe
2017-01-04 07:19:39.403 [ERROR] [WaveController$ZWaveSendThread] - NODE 141: Timeout while sending message. Requeueing - 2 attempts left!
2017-01-04 07:19:39.404 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 141: Got an error while sending data. Resending message: Message: class = SendData (0x13), type = Request (0x00), payload = 8D 02 80 02 , callbackid = 194
2017-01-04 12:36:43.205 [ERROR] [WaveController$ZWaveSendThread] - NODE 255: Timeout while sending message. Requeueing - 2 attempts left!
2017-01-04 12:36:48.237 [ERROR] [WaveController$ZWaveSendThread] - NODE 255: Timeout while sending message. Requeueing - 1 attempts left!
2017-01-04 12:36:51.088 [ERROR] [.DeleteReturnRouteMessageClass] - NODE 147: Delete return routes failed with error 0x1.
 2017-01-04 12:36:53.239 [ERROR] [WaveController$ZWaveSendThread] - NODE 255: Timeout while sending message. Requeueing - 0 attempts left!
2017-01-04 12:36:55.858 [ERROR] [.DeleteReturnRouteMessageClass] - NODE 147: Delete return routes failed with error 0x1.
 2017-01-04 12:36:58.241 [WARN ] [WaveController$ZWaveSendThread] - NODE 255: Too many retries. Discarding message: Message: class = DeleteReturnRoute (0x47), type = Request (0x00), payload = 93 , callbackid = 0
 2017-01-04 12:37:00.872 [ERROR] [.AssignReturnRouteMessageClass] - NODE 147: Assign return routes failed.

2017-01-04 13:19:37.921 [WARN ] [.i.p.c.ZWaveSecureNonceTracker] - NODE 141: Received new nonce from device, ejecting Nonce RECEIVED A5 66 CA 29 D3 A9 50 13 ; time left=4938.
2017-01-04 13:19:38.002 [INFO ] [.p.c.ZWaveDoorLockCommandClass] - NODE 141: Door Lock report - lockState = 0x00,handlesMode = 0x10, doorCondition = 0x02, lockTimeoutMinutes = 0xfe,lockTimeoutSeconds = 0xfe
2017-01-04 17:04:13.379 [WARN ] [.w.internal.WifiSettingBinding] - internalReceiveCommand(wifi_setting_425,get) is called!
2017-01-04 17:42:01.854 [ERROR] [WaveController$ZWaveSendThread] - NODE 137: Timeout while sending message. Requeueing - 2 attempts left!
2017-01-04 17:42:01.855 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 137: Got an error while sending data. Resending message: Message: class = SendData (0x13), type = Request (0x00), payload = 89 01 00 , callbackid = 213
2017-01-04 17:42:01.886 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 137: Got an error while sending data. Resending message: Message: class = SendData (0x13), type = Request (0x00), payload = 89 01 00 , callbackid = 213
2017-01-04 17:42:06.769 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 137: Node is DEAD. Dropping message.
2017-01-04 17:42:06.770 [WARN ] [b.z.i.p.s.SendDataMessageClass] - Item Name :SWITCH_425_426_137_0 Node ID :137
2017-01-04 17:42:06.771 [WARN ] [b.z.i.p.s.SendDataMessageClass] - Item Name :SWITCH_425_426_137_2 Node ID :137
2017-01-04 17:42:06.774 [WARN ] [b.z.i.p.s.SendDataMessageClass] - published on event bus :SWITCH_425_426_137_0
2017-01-04 17:42:06.776 [WARN ] [b.z.i.p.s.SendDataMessageClass] - published on event bus :SWITCH_425_426_137_2
2017-01-04 17:42:06.782 [WARN ] [i.p.s.IsFailedNodeMessageClass] - NODE 137: Is currently marked as failed by the controller!
2017-01-04 17:42:06.789 [WARN ] [i.p.s.IsFailedNodeMessageClass] - NODE 137: Is currently marked as failed by the controller!
2017-01-04 17:42:07.626 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 137: Node is DEAD. Dropping message.
2017-01-04 17:42:07.627 [WARN ] [b.z.i.p.s.SendDataMessageClass] - Item Name :SWITCH_425_426_137_0 Node ID :137
2017-01-04 17:42:07.628 [WARN ] [b.z.i.p.s.SendDataMessageClass] - Item Name :SWITCH_425_426_137_2 Node ID :137
2017-01-04 17:42:07.630 [WARN ] [b.z.i.p.s.SendDataMessageClass] - published on event bus :SWITCH_425_426_137_0
2017-01-04 17:42:07.634 [WARN ] [b.z.i.p.s.SendDataMessageClass] - published on event bus :SWITCH_425_426_137_2
2017-01-04 17:42:11.824 [WARN ] [b.z.i.p.s.SendDataMessageClass] - Node not found!
2017-01-04 17:42:17.971 [ERROR] [NodeNeighborUpdateMessageClass] - NODE 137: NodeNeighborUpdate FAILED
2017-01-04 17:42:28.307 [ERROR] [NodeNeighborUpdateMessageClass] - NODE 137: NodeNeighborUpdate FAILED
2017-01-04 17:42:56.664 [ERROR] [WaveController$ZWaveSendThread] - NODE 137: Timeout while sending message. Requeueing - 2 attempts left!
2017-01-04 17:42:56.665 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 137: Got an error while sending data. Resending message: Message: class = SendData (0x13), type = Request (0x00), payload = 89 03 25 01 00 , callbackid = 218
2017-01-04 17:42:56.697 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 137: Got an error while sending data. Resending message: Message: class = SendData (0x13), type = Request (0x00), payload = 89 03 25 01 00 , callbackid = 218
2017-01-04 17:43:01.606 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 137: Node is DEAD. Dropping message.
2017-01-04 17:43:01.606 [WARN ] [b.z.i.p.s.SendDataMessageClass] - Item Name :SWITCH_425_426_137_0 Node ID :137
2017-01-04 17:43:01.607 [WARN ] [b.z.i.p.s.SendDataMessageClass] - Item Name :SWITCH_425_426_137_2 Node ID :137
2017-01-04 17:43:01.609 [WARN ] [b.z.i.p.s.SendDataMessageClass] - published on event bus :SWITCH_425_426_137_0
2017-01-04 17:43:01.612 [WARN ] [b.z.i.p.s.SendDataMessageClass] - published on event bus :SWITCH_425_426_137_2
2017-01-04 17:43:01.617 [WARN ] [i.p.s.IsFailedNodeMessageClass] - NODE 137: Is currently marked as failed by the controller!
2017-01-04 17:43:01.623 [WARN ] [i.p.s.IsFailedNodeMessageClass] - NODE 137: Is currently marked as failed by the controller!
2017-01-04 17:43:02.578 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 137: Node is DEAD. Dropping message.
2017-01-04 17:43:02.578 [WARN ] [b.z.i.p.s.SendDataMessageClass] - Item Name :SWITCH_425_426_137_0 Node ID :137
2017-01-04 17:43:02.579 [WARN ] [b.z.i.p.s.SendDataMessageClass] - Item Name :SWITCH_425_426_137_2 Node ID :137
2017-01-04 17:43:02.582 [WARN ] [b.z.i.p.s.SendDataMessageClass] - published on event bus :SWITCH_425_426_137_0
2017-01-04 17:43:02.585 [WARN ] [b.z.i.p.s.SendDataMessageClass] - published on event bus :SWITCH_425_426_137_2
2017-01-04 17:43:06.697 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 137: Node is DEAD. Dropping message.
2017-01-04 17:43:06.698 [WARN ] [b.z.i.p.s.SendDataMessageClass] - Item Name :SWITCH_425_426_137_0 Node ID :137
2017-01-04 17:43:06.699 [WARN ] [b.z.i.p.s.SendDataMessageClass] - Item Name :SWITCH_425_426_137_2 Node ID :137
2017-01-04 17:43:06.701 [WARN ] [b.z.i.p.s.SendDataMessageClass] - published on event bus :SWITCH_425_426_137_0
2017-01-04 17:43:06.703 [WARN ] [b.z.i.p.s.SendDataMessageClass] - published on event bus :SWITCH_425_426_137_2
2017-01-04 17:43:07.623 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 143: Got an error while sending data. Resending message: Message: class = SendData (0x13), type = Request (0x00), payload = 8F 02 26 02 , callbackid = 221
2017-01-04 17:43:07.629 [ERROR] [b.z.i.p.s.SendDataMessageClass] - NODE 143: Sent Data was not placed on stack due to error 0.
2017-01-04 17:43:17.021 [ERROR] [NodeNeighborUpdateMessageClass] - NODE 143: NodeNeighborUpdate FAILED
2017-01-04 17:43:57.513 [WARN ] [i.p.s.IsFailedNodeMessageClass] - NODE 137: Is currently marked as failed by the controller!
2017-01-04 17:43:57.518 [WARN ] [i.p.s.IsFailedNodeMessageClass] - NODE 137: Is currently marked as failed by the controller!
2017-01-04 17:43:57.741 [WARN ] [i.p.s.IsFailedNodeMessageClass] - NODE 137: Is currently marked as failed by the controller!
2017-01-04 17:43:57.747 [WARN ] [i.p.s.IsFailedNodeMessageClass] - NODE 137: Is currently marked as failed by the controller!
2017-01-04 17:44:03.900 [ERROR] [eController$ZWaveReceiveThread] - Protocol error (CAN), resending
2017-01-04 17:44:04.007 [WARN ] [i.p.s.IsFailedNodeMessageClass] - NODE 137: Is currently marked as failed by the controller!
2017-01-04 17:44:04.012 [WARN ] [i.p.s.IsFailedNodeMessageClass] - NODE 137: Is currently marked as failed by the controller!
2017-01-04 17:44:44.550 [ERROR] [WaveController$ZWaveSendThread] - NODE 255: Timeout while sending message. Requeueing - 2 attempts left!
2017-01-04 17:44:49.552 [ERROR] [WaveController$ZWaveSendThread] - NODE 255: Timeout while sending message. Requeueing - 1 attempts left!
2017-01-04 17:44:54.556 [ERROR] [WaveController$ZWaveSendThread] - NODE 255: Timeout while sending message. Requeueing - 0 attempts left!
2017-01-04 17:44:59.604 [WARN ] [WaveController$ZWaveSendThread] - NODE 255: Too many retries. Discarding message: Message: class = DeleteReturnRoute (0x47), type = Request (0x00), payload = 89 , callbackid = 0

Ok - this is a very old thread and and I don’t really intend to look at the heal process in OH1. I know there are problems due to the way the transaction work, and I definately will not change this - sorry.

@chris

thanks for reply
can you please tell me how to stop healing process which happens every night 2 am ?.

I’m not sure - maybe setting it to -1 might stop it?

Or alternatively removing the configuration might also work.