Erreur dropping command sur le contrôleur

[cstan77]

Salut tous !!!
alors j’ai un BIG bug !!!
Ca fait 2 ans que ça que mon installation tourne nickel mais depuis 3 jours mon réseau Zwave est HS et impossible de le faire repartir !

Vendredi matin toute mon installation était OK et le soir mes volets roulant ne se sont pas fermés j’ai mis ça sur le dos de mon scénario…
Le samedi matin pareil pas d’ouverture automatique des volets roulants… là y a quelque chose

Je me suis donc connecté sur mon Jeedom qui est en pleine forme et pas d’erreurs…
J’essaie les commandes des volets roulant et rien les modules ne reçoivent rien.

Sachant que je n’ai pas fait de bidouille depuis un un bout de temps, je sèche un peu.
Sur la page du plugin tout est OK …

J’ai tout essayé aujourd’hui pour le remettre en marche mais sans succès.

Sur certains post, il fallait décocher des options de configuration du plugin, retirer le dongle 15 minutes, rebooter le Jeedom, mettre une rallonge, changer le port de communication en auto, réinstaller les dépendances, modifier les droits d’écriture sur le mount du dongle… bref j’ai tout éteint durant la nuit et à l’heure actuelle j’en suis toujours sur le même problème.

voici l’origine du BUG :

root@JEEDOM_CySo:~# cat /var/www/html/log/openzwaved
2022-05-22 19:25:40.859 Always, OpenZwave Version 1.4.0 Starting Up
2022-05-22 19:25:40.860 Info, Setting Up Provided Network Key for Secure Communications
2022-05-22 19:25:40.860 Info, mgr,     Added driver for controller /dev/ttyACM0
2022-05-22 19:25:40.860 Info,   Opening controller /dev/ttyACM0
2022-05-22 19:25:40.861 Info, Trying to open serial port /dev/ttyACM0 (attempt 1)
2022-05-22 19:25:40.861 Info, Serial port /dev/ttyACM0 opened (attempt 1)
2022-05-22 19:25:40.861 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2022-05-22 19:25:40.861 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2022-05-22 19:25:40.861 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2022-05-22 19:25:40.861 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2022-05-22 19:25:40.861 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2022-05-22 19:25:40.861 Detail,
2022-05-22 19:25:40.861 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x15) - FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2022-05-22 19:25:41.861 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2022-05-22 19:25:41.861 Detail, contrlr, Removing current message
2022-05-22 19:25:41.861 Detail, contrlr, Notification: Notification - TimeOut
2022-05-22 19:25:41.862 Detail,
2022-05-22 19:25:41.862 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x20) - FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2022-05-22 19:25:42.862 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2022-05-22 19:25:42.862 Detail, contrlr, Removing current message
2022-05-22 19:25:42.862 Detail, contrlr, Notification: Notification - TimeOut
2022-05-22 19:25:42.863 Detail,
2022-05-22 19:25:42.863 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x05) - FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2022-05-22 19:25:43.863 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2022-05-22 19:25:43.863 Detail, contrlr, Removing current message
2022-05-22 19:25:43.863 Detail, contrlr, Notification: Notification - TimeOut
2022-05-22 19:25:43.863 Detail,
2022-05-22 19:25:43.863 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x07) - FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2022-05-22 19:25:44.864 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2022-05-22 19:25:44.864 Detail, contrlr, Removing current message
2022-05-22 19:25:44.864 Detail, contrlr, Notification: Notification - TimeOut
2022-05-22 19:25:44.864 Detail,
2022-05-22 19:25:44.864 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x56) - FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2022-05-22 19:25:45.865 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2022-05-22 19:25:45.865 Detail, contrlr, Removing current message
2022-05-22 19:25:45.865 Detail, contrlr, Notification: Notification - TimeOut

Un timeout sur le contrôleur…

Ma page du plugin :

Quand je fais un redémarrage du démon voici les logs en temps réel :

==> /var/www/html/log/openzwave <==
[2022-05-22 20:05:52][INFO] : Graceful stopping the ZWave network.
[2022-05-22 20:05:52][INFO] : Stop Openzwave network.

==> /var/www/html/log/openzwaved <==
2022-05-22 20:05:52.766 Error, mgr,     Manager::GetDriver failed - Home ID 0x00000000 is unknown
2022-05-22 20:05:52.766 Warning, Exception: Manager.cpp:373 - 100 - Invalid HomeId passed to GetDriver
2022-05-22 20:05:52.766 Info, mgr,     Manager::WriteConfig failed - _homeId 0 not found

==> /var/www/html/log/openzwave <==
[2022-05-22 20:05:52][INFO] : ZWave configuration written to user directory.

==> /var/www/html/log/openzwaved <==
2022-05-22 20:05:53.766 Always, ***************************************************************************
2022-05-22 20:05:53.766 Always, *********************  Cumulative Network Statistics  *********************
2022-05-22 20:05:53.766 Always, *** General
2022-05-22 20:05:53.766 Always, Driver run time: . .  . 0 days, 0 hours, 1 minutes
2022-05-22 20:05:53.766 Always, Frames processed: . . . . . . . . . . . . . . . . . . . . 0
2022-05-22 20:05:53.766 Always, Total messages successfully received: . . . . . . . . . . 0
2022-05-22 20:05:53.766 Always, Total Messages successfully sent: . . . . . . . . . . . . 5
2022-05-22 20:05:53.766 Always, ACKs received from controller:  . . . . . . . . . . . . . 0
2022-05-22 20:05:53.766 Always, *** Errors
2022-05-22 20:05:53.766 Always, Unsolicited messages received while waiting for ACK:  . . 0
2022-05-22 20:05:53.766 Always, Reads aborted due to timeouts:  . . . . . . . . . . . . . 0
2022-05-22 20:05:53.766 Always, Bad checksum errors:  . . . . . . . . . . . . . . . . . . 0
2022-05-22 20:05:53.766 Always, CANs received from controller:  . . . . . . . . . . . . . 0
2022-05-22 20:05:53.766 Always, NAKs received from controller:  . . . . . . . . . . . . . 0
2022-05-22 20:05:53.766 Always, Out of frame data flow errors:  . . . . . . . . . . . . . 0
2022-05-22 20:05:53.766 Always, Messages retransmitted: . . . . . . . . . . . . . . . . . 0
2022-05-22 20:05:53.766 Always, Messages dropped and not delivered: . . . . . . . . . . . 5
2022-05-22 20:05:53.766 Always, ***************************************************************************
2022-05-22 20:05:53.766 Warning, WARNING: Tried to write driver config with no home ID set
2022-05-22 20:05:55.767 Info, mgr,     Driver for controller /dev/ttyACM0 removed

==> /var/www/html/log/openzwave <==
[2022-05-22 20:05:57][INFO] : Openzwave network are Network is stopped
[2022-05-22 20:05:57][INFO] : The Openzwave REST-server was stopped in a normal way
[2022-05-22 20:05:57][INFO] : Backup xml config file with mode: stop
[2022-05-22 20:05:57][INFO] : More than 12 auto backups found. Cleaning the folder
[2022-05-22 20:05:57][INFO] : Xml config file successfully backup
[2022-05-22 20:05:59][INFO] : Lancement démon openzwave : /usr/bin/python /var/www/html/plugins/openzwave/core/class/../../resources/openzwaved/openzwaved.py  --device /dev/ttyACM0 --loglevel debug --port 8083 --config_folder /var/www/html/plugins/openzwave/core/class/../../resources/openzwaved/config --data_folder /var/www/html/plugins/openzwave/core/class/../../data --callback http://127.0.0.1:80/plugins/openzwave/core/php/jeeZwave.php --apikey 4htAEXDgNViN3OhhD4BqrEqHRhBNiwEE --suppressRefresh 0 --cycle 0.3 --pid /tmp/jeedom/openzwave/deamon.pid --disabledNodes 20,33,34
[2022-05-22 20:06:00][INFO] : Start openzwaved
[2022-05-22 20:06:00][INFO] : Log level : debug
[2022-05-22 20:06:00][DEBUG] : PID file : /tmp/jeedom/openzwave/deamon.pid
[2022-05-22 20:06:00][INFO] : Device : /dev/ttyACM0
[2022-05-22 20:06:00][DEBUG] : Apikey : 4htAEXDgNViN3OhhD4BqrEqHRhBNiwEE
[2022-05-22 20:06:00][INFO] : Callback : http://127.0.0.1:80/plugins/openzwave/core/php/jeeZwave.php
[2022-05-22 20:06:00][INFO] : Cycle : 0.3
[2022-05-22 20:06:00][DEBUG] : Initial disabled nodes list: [20, 33, 34]
[2022-05-22 20:06:00][DEBUG] : Init request module v2.27.1
[2022-05-22 20:06:00][DEBUG] : Starting new HTTP connection (1): 127.0.0.1:80
[2022-05-22 20:06:00][DEBUG] : http://127.0.0.1:80 "GET /plugins/openzwave/core/php/jeeZwave.php?apikey=4htAEXDgNViN3OhhD4BqrEqHRhBNiwEE HTTP/1.1" 200 0
[2022-05-22 20:06:00][INFO] : Check if the port REST server available
[2022-05-22 20:06:00][INFO] : --> pass
[2022-05-22 20:06:00][INFO] : Check OpenZWave Devices Database
[2022-05-22 20:06:00][INFO] : --> pass
[2022-05-22 20:06:00][INFO] : Validate zwcfg configuration file(s)
[2022-05-22 20:06:00][INFO] : ... check: /var/www/html/plugins/openzwave/core/class/../../data/zwcfg_0xe163dd92.xml
[2022-05-22 20:06:00][INFO] : ... check: /var/www/html/plugins/openzwave/core/class/../../data/zwcfg_0x00000000.xml
[2022-05-22 20:06:00][DEBUG] : Create network object.
tail: /var/www/html/log/openzwaved: file truncated

==> /var/www/html/log/openzwaved <==
2022-05-22 20:06:00.077 Always, OpenZwave Version 1.4.0 Starting Up

==> /var/www/html/log/openzwave <==
[2022-05-22 20:06:00][DEBUG] : Use sqlite version : (u'3.27.2',)
[2022-05-22 20:06:00][DEBUG] : connect to the louie dispatcher
[2022-05-22 20:06:00][INFO] : ******** The ZWave network is being started ********
[2022-05-22 20:06:00][INFO] : Start Openzwave network.

==> /var/www/html/log/openzwaved <==
2022-05-22 20:06:00.078 Info, Setting Up Provided Network Key for Secure Communications
2022-05-22 20:06:00.078 Info, mgr,     Added driver for controller /dev/ttyACM0

==> /var/www/html/log/openzwave <==
[2022-05-22 20:06:00][INFO] : OpenZwave Library Version 1.4.0
[2022-05-22 20:06:00][INFO] : Python-OpenZwave Wrapper Version 0.3.1
[2022-05-22 20:06:00][INFO] : --> pass
[2022-05-22 20:06:00][INFO] : Waiting for network to become ready
[2022-05-22 20:06:00][DEBUG] : Writing PID 26595 to /tmp/jeedom/openzwave/deamon.pid

==> /var/www/html/log/openzwaved <==
2022-05-22 20:06:00.079 Info,   Opening controller /dev/ttyACM0
2022-05-22 20:06:00.079 Info, Trying to open serial port /dev/ttyACM0 (attempt 1)
2022-05-22 20:06:00.079 Info, Serial port /dev/ttyACM0 opened (attempt 1)
2022-05-22 20:06:00.079 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9
2022-05-22 20:06:00.079 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2022-05-22 20:06:00.080 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2022-05-22 20:06:00.080 Detail, contrlr, Queuing (Command) FUNC_ID_SERIAL_API_GET_CAPABILITIES: 0x01, 0x03, 0x00, 0x07, 0xfb
2022-05-22 20:06:00.080 Detail, contrlr, Queuing (Command) FUNC_ID_ZW_GET_SUC_NODE_ID: 0x01, 0x03, 0x00, 0x56, 0xaa
2022-05-22 20:06:00.080 Detail,
2022-05-22 20:06:00.080 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x15) - FUNC_ID_ZW_GET_VERSION: 0x01, 0x03, 0x00, 0x15, 0xe9

==> /var/www/html/log/openzwave <==
[2022-05-22 20:06:00][INFO] : Démon openzwave lancé

==> /var/www/html/log/openzwaved <==
2022-05-22 20:06:01.080 Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)
2022-05-22 20:06:01.080 Detail, contrlr, Removing current message
2022-05-22 20:06:01.080 Detail, contrlr, Notification: Notification - TimeOut

==> /var/www/html/log/openzwave <==
[2022-05-22 20:06:01][DEBUG] : notif_callback : new notification
[2022-05-22 20:06:01][DEBUG] : notif_callback : Notification type : 26, nodeId : 255
[2022-05-22 20:06:01][DEBUG] : notif_callback : call callback context
[2022-05-22 20:06:01][DEBUG] : zwcallback args=[{'homeId': 0, 'notificationCode': 1, 'notificationType': 'Notification', 'nodeId': 255}]
[2022-05-22 20:06:01][DEBUG] : Z-Wave Notification : {'homeId': 0, 'notificationCode': 1, 'notificationType': 'Notification', 'nodeId': 255}
[2022-05-22 20:06:01][DEBUG] : notif_callback : end

Mon dongle USB est bien monté sur ma VM

Le plugin est en écoute mais impossible de discuter avec le dongle

Si quelqu’un a une piste…

[Nicoca-ine]

Bonjour

Ca sent le dongle HS

[cstan77]

Bon, j’ai pas mal parcouru les github et forum… sans plus de piste.

J’ai vu que mon Jeedom c’était mis à jour (4.2.14 => 4.2.16) durant la nuit juste avant le bug… donc j’ai rechargé un dump de l’année dernière de mon Docker et j’ai le meme bug, ca pue la panne du contrôleur malgré qu’il clignote (jaune, rouge,blue…)

[cstan77]

Bon bha le dongle fonctionne !!!
Je l’ai installé sous Windows avec Domoticz et il fonctionne !
J’ai utilisé aussi l’outil « Z-wave PC controller » qui m’a permis de voir les trames passées

j’allume et j’éteint une prise.

Donc le soucis est dans Jeedom…

[cstan77]

J’ai retrouvé mon dongle !!

j’ai rebranché mon dongle sur mon Jeedom relancé le plugin ZWave et pafff pareil planté…

Error, contrlr, ERROR: Dropping command, expected response not received after 1 attempt(s)

dans mon terminal SSH, le dongle est bien là…

je l’ai débranché et j’ai fait le ménage :

dmesg -C

ca vide les messages du kernel (noyau) du system host

j’ai rebranché le dongle, le kernel l’a bien vu et bien chargé

j’ai relancé le demon du plugin Zwave et j’ai vu les traces d’emissions

Alors est ce que le tampon était plein ?? normalement c’est du FIFO donc j’en toute.
est-ce qu’il été corrompu quelque part ?? c’est des traces donc normalement le system s’en fout…

bref il a bien rechargé le dongle