Erreur: NCP entered failed state. Requesting APP controller restart

olivr2s · Octobre 7, 2021, 2:45

Bonjour,

depuis plusieurs jours, j’ai régulièrement des erreurs dans les logs du plugin Zigbee alors qu’avant tout était parfaitement stable.

[2021-10-06 10:30:08][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-06 11:10:44][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-06 11:10:49][ERROR] : Task exception was never retrieved
future: <Task finished coro=<Device.request() done, defined at /usr/local/lib/python3.7/dist-packages/zigpy/device.py:249> exception=TimeoutError()>
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/zigpy/device.py", line 274, in request
    use_ieee=use_ieee,
  File "/usr/local/lib/python3.7/dist-packages/bellows/zigbee/application.py", line 551, in request
    await self._ezsp.setExtendedTimeout(device.ieee, True)
  File "/usr/lib/python3.7/asyncio/tasks.py", line 423, in wait_for
    raise futures.TimeoutError()
concurrent.futures._base.TimeoutError
[2021-10-06 11:54:30][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-06 11:54:30][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-06 11:54:30][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-06 11:54:30][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-06 13:13:35][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-06 13:13:35][ERROR] : Task exception was never retrieved
future: <Task finished coro=<PollControl.set_poll_parameters() done, defined at /var/www/html/plugins/zigbee/resources/zigbeed/channels/general.py:238> exception=ControllerError('ApplicationController is not running')>
Traceback (most recent call last):
  File "/var/www/html/plugins/zigbee/resources/zigbeed/channels/general.py", line 241, in set_poll_parameters
    await cluster.checkin_response(True, fast_poll_timeout, tsn=tsn)
  File "/usr/local/lib/python3.7/dist-packages/zigpy/device.py", line 274, in request
    use_ieee=use_ieee,
  File "/usr/local/lib/python3.7/dist-packages/bellows/zigbee/application.py", line 501, in request
    raise ControllerError("ApplicationController is not running")
bellows.exception.ControllerError: ApplicationController is not running
[2021-10-06 13:13:35][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-06 13:13:35][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-06 13:13:35][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-06 13:50:59][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-06 13:50:59][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-06 13:50:59][ERROR] : NCP entered failed state. Requesting APP controller restart

Sur mon Jeedom:

Clé USB Zigbee Elelabs Popp reliée avec rallonge USB

image2369×1479 286 KB

image2677×585 99.4 KB

Sur le Github de Zigpy on peut voir ceci concernant les erreurs NCP entered failed state

Sauf que mon contrôleur Zigbee Elelabs est relié à mon Jeedom par USB et pas par Wifi.
Pendant plusieurs jours j’ai essayé en changeant de câble USB, ou avec un hub USB alimenté, mais au bout d’un moment, toujours NCP entered failed state
En, il y a d’autre erreurs, mais je vois pas à quoi cela pourrait correspondre.

Des idées ?

olivr2s · Octobre 19, 2021, 7:12

Toujours des messages dans les logs…
Je croyais que cela pouvait venir de perte de connexion de mon ports USB, mais ce n’est pas le cas lorsque j’interroge le journal de connexion des ports USB, les dernières remonte à un redémarrage de mon Jeedom hier à 18h55

log de ce matin


[2021-10-18 21:39:10][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-18 21:55:44][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-18 21:55:44][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-18 21:55:44][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-18 23:36:19][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 00:00:48][ERROR] : [5c:02:72:ff:fe:c8:8a:d2][zdevices.write_attributes] Write attribut retry in 1s : [0xee35:1:0x000a]: Message send failure
[2021-10-19 00:01:22][ERROR] : [5c:02:72:ff:fe:c9:c1:b6][zdevices.write_attributes] Write attribut retry in 1s : [0x187a:1:0x000a]: Message send failure
[2021-10-19 00:01:33][ERROR] : [5c:02:72:ff:fe:c9:c1:18][zdevices.write_attributes] Write attribut retry in 1s : [0xdeac:1:0x000a]: Message send failure
[2021-10-19 00:26:36][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 01:16:53][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 01:16:53][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 01:16:53][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 01:26:16][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 01:26:21][ERROR] : Task exception was never retrieved
future: <Task finished coro=<Device.request() done, defined at /usr/local/lib/python3.7/dist-packages/zigpy/device.py:249> exception=TimeoutError()>
Traceback (most recent call last):
  File "/usr/local/lib/python3.7/dist-packages/zigpy/device.py", line 274, in request
    use_ieee=use_ieee,
  File "/usr/local/lib/python3.7/dist-packages/bellows/zigbee/application.py", line 551, in request
    await self._ezsp.setExtendedTimeout(device.ieee, True)
  File "/usr/lib/python3.7/asyncio/tasks.py", line 423, in wait_for
    raise futures.TimeoutError()
concurrent.futures._base.TimeoutError
[2021-10-19 02:00:08][ERROR] : Task was destroyed but it is pending!
task: <Task pending coro=<Gateway._send_task() running at /usr/local/lib/python3.7/dist-packages/bellows/uart.py:238> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0xffffbb436498>()]>>
[2021-10-19 02:07:09][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 02:40:45][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 02:53:35][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 02:57:26][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 02:57:26][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 02:57:26][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 02:57:26][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 03:31:00][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 03:54:34][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 04:00:08][ERROR] : Task was destroyed but it is pending!
task: <Task pending coro=<Gateway._send_task() done, defined at /usr/local/lib/python3.7/dist-packages/bellows/uart.py:225> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0xffffbb436f18>()]>>
[2021-10-19 06:01:44][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 06:52:00][ERROR] : NCP entered failed state. Requesting APP controller restart
[2021-10-19 08:49:20][ERROR] : NCP entered failed state. Requesting APP controller restart

dim83fr · Octobre 20, 2021, 5:54

Bonjour,

J’ai exactement le même problème, et c’est très difficile de revenir dans un état fonctionnel.
Je dois redémarrer un nombre incalculable de fois.

olivr2s · Octobre 20, 2021, 5:57

J’ai bien les erreurs dans les logs, mais je ne suis pas obligé de redémarrer le démon ou autre.
C’est juste que j’ai ces erreurs qui apparaissent.
Par contre côté prise USB, pas de déconnexion
Et avec un hub alimenté pareil… c’est bizarre…

llaumgui · Novembre 5, 2021, 10:12

Pareil chez moi. Et ça déstabilise tout mon Zigbee

olivr2s · Novembre 5, 2021, 7:59

J’ai peut être fini par trouver ce qui provoquait ces messages d’erreur régulier.
J’avais pas fait attention à partir de quand ça avait commencé mais ça semblait coïncider avec l’ajout d’un SONOFF zbmini sur mon réseau Zigbee.

Je l’ai retiré hier de mon réseau pour faire une modification et depuis plus aucunes erreurs dans les logs. Coïncidence ? J’attends encore un peu pour voir mais il semblerait que c’était à cause de lui.

olivr2s · Novembre 7, 2021, 9:49

Hier matin, comme j’avais toujours aucune erreurs dans les logs, j’ai réinclus le module Sonoff zbmini pour voir et depuis aucune erreurs…

Il y a quelques temps, j’avais ajouté le Sonoff car j’avais des capteurs un peu loin avec parfois quelques pertes de communication mais pas les erreurs NCP dans les logs.
Quand j’ai ajouté le Sonoff, ça avait un peu amélioré la communication avec les capteurs mais avec encore quelques pertes et les erreurs NCP très régulières.
Comme le Sonoff restait juste pour router correctement les capteurs, j’ai dernièrement résolu le problème avec un autre routeur qui fait bien le job depuis.

Au final, on dirait que les erreurs NCP venait peut être parce que j’avais un routeur avec une liaison trop juste et instable car c’est uniquement sur une modification matériel de mon réseau zigbee et aucune mise à jour du plugin, des dépendances ou du firmware que les erreurs dans les logs ont disparus.
Je vais voir encore quelques jours mais il se pourrait que les erreurs NCP venaient d’un routeur (le Sonoff) qui avait une mauvaise communication avec le coordinateur…