Un restart manuel ne supprime pas les logs, donc c’est toujours jouable tant que vous donnez les logs et la date du bug rencontré !
Pour moi oui @pierre-gilles ce sont bien des logs Z2M. Au moins c’est assez clair, il n’arrive plus à communiquer avec le serveur MQTT, juste avant le redémarrage.
Soit c’est lié au redémarrage, soit c’est lié à Gladys.
Hello tout le monde,
J’ai déjà aussi eu ce souci. Un stop/start du service a remis les choses en ordre. Même si je n’aime pas cela.
J’avais déjà eu ce souci, ou un proche, il y a quelque temps. J’avais dû relancer le docker.
Si les logs n’ont pas été supprimés lors de ma manip, je peux peut-être les récupérer et vous les transmettre ?!
Désolé, j’arrive après la bataille. 
@pierre-gilles
Oui, l’entête n’est pas le même pour Gladys je crois 
@Noj
Pas besoin de redémarrer le container, juste arrêter le service, attendre 30s puis redémarrer le service !
Je viens de rentrer de vacances et constate le même problème.
Mon bouton pour mettre en route le chauffage 20 minutes dans la salle de bain ne fonctionne plus dans Gladys.
Par contre, les changements d’état apparaissent dans l’interface IP:8080
J’ai récupéré les logs depuis le 7 février. Je vous les envoie.
Je viens de me pencher sur les logs de Z2M. Si je comprends bien, quand on relance le service, toutes les données sont bien transmises (dans lmon cas les températures de 4 pièces)mais à la seconde itération, le système envoie plusieurs fois le même topic (4 fois la même pièce : temp salon).
j’espère que cela vous permettra de trouver l’origine du problème.
voici le log depuis le rest
Zigbee2MQTT:info 2023-03-07 17:54:42: Zigbee: disabling joining new devices.
Zigbee2MQTT:info 2023-03-07 17:54:42: Connecting to MQTT server at mqtt://localhost:1884
Zigbee2MQTT:debug 2023-03-07 17:54:42: Using MQTT login with username: z2m
Zigbee2MQTT:info 2023-03-07 17:54:42: Connected to MQTT server
Zigbee2MQTT:info 2023-03-07 17:54:42: MQTT publish: topic ‹ zigbee2mqtt/bridge/state ›, payload ‹ online ›
Zigbee2MQTT:info 2023-03-07 17:54:42: Started frontend on port 0.0.0.0:8080
Zigbee2MQTT:debug 2023-03-07 17:54:42: Received MQTT message on ‹ zigbee2mqtt/bridge/0x00212effff05527d/get › with data ‹ ›
Zigbee2MQTT:info 2023-03-07 17:54:42: MQTT publish: topic ‹ zigbee2mqtt/bridge/config ›, payload ‹ {« commit »:« cdf62ea »,« coordinator »:{« meta »:{« maintrel »:0,« majorrel »:38,« minorrel »:114,« product »:0,« revision »:« 0x26720700 »,« transportrev »:0},« type »:« ConBee2/RaspBee2 »},« log_level »:« debug »,« network »:{« channel »:11,« extendedPanID »:« 0xdddddddddddddddd »,« panID »:6754},« permit_join »:false,« version »:« 1.30.2 »} ›
Zigbee2MQTT:info 2023-03-07 17:54:42: MQTT publish: topic ‹ zigbee2mqtt/0x00158d000465ad6f temp salon ›, payload ‹ {« battery »:57,« humidity »:50.5,« linkquality »:255,« power_outage_count »:31,« pressure »:981.1,« temperature »:15.23,« voltage »:2935} ›
Zigbee2MQTT:info 2023-03-07 17:54:42: MQTT publish: topic ‹ zigbee2mqtt/0x00158d000282ed1e temp chbre elise ›, payload ‹ {« battery »:43,« humidity »:55.92,« linkquality »:200,« power_outage_count »:188,« pressure »:993.9,« temperature »:22.2,« voltage »:2915} ›
Zigbee2MQTT:info 2023-03-07 17:54:42: MQTT publish: topic ‹ zigbee2mqtt/0x5c0272fffe6d678b ›, payload ‹ {« linkquality »:255,« update »:{« installed_version »:587753009,« latest_version »:587753009,« state »:« idle »},« update_available »:false} ›
Zigbee2MQTT:info 2023-03-07 17:54:42: MQTT publish: topic ‹ zigbee2mqtt/0x00158d0001d654a8 temp bureau ›, payload ‹ {« battery »:100,« humidity »:55.02,« linkquality »:255,« power_outage_count »:9,« pressure »:988.4,« temperature »:21.82,« voltage »:3025} ›
Zigbee2MQTT:info 2023-03-07 17:54:42: MQTT publish: topic ‹ zigbee2mqtt/0x00158d00040967ab ›, payload ‹ {« battery »:83,« contact »:true,« linkquality »:255,« power_outage_count »:333,« voltage »:2975} ›
Zigbee2MQTT:info 2023-03-07 17:54:42: MQTT publish: topic ‹ zigbee2mqtt/0x00158d000464c57b temp sdb parents ›, payload ‹ {« battery »:81,« humidity »:67.97,« linkquality »:255,« power_outage_count »:53,« pressure »:998,« temperature »:27.77,« voltage »:3135} ›
Zigbee2MQTT:info 2023-03-07 17:54:42: MQTT publish: topic ‹ zigbee2mqtt/0x000d6ffffecde87f telecde 3 boutons ›, payload ‹ {« battery »:100,« linkquality »:255,« voltage »:3000} ›
Zigbee2MQTT:info 2023-03-07 17:54:42: Zigbee2MQTT started!
Zigbee2MQTT:debug 2023-03-07 17:55:49: Received Zigbee message from ‹ 0x00158d000465ad6f temp salon ›, type ‹ attributeReport ›, cluster ‹ msTemperatureMeasurement ›, data ‹ {« measuredValue »:1526} › from endpoint 1 with groupID null
Zigbee2MQTT:info 2023-03-07 17:55:49: MQTT publish: topic ‹ zigbee2mqtt/0x00158d000465ad6f temp salon ›, payload ‹ {« battery »:57,« humidity »:50.5,« linkquality »:255,« power_outage_count »:31,« pressure »:981.1,« temperature »:15.26,« voltage »:2935} ›
Zigbee2MQTT:debug 2023-03-07 17:55:49: Received Zigbee message from ‹ 0x00158d000465ad6f temp salon ›, type ‹ attributeReport ›, cluster ‹ msRelativeHumidity ›, data ‹ {« measuredValue »:5046} › from endpoint 1 with groupID null
Zigbee2MQTT:info 2023-03-07 17:55:49: MQTT publish: topic ‹ zigbee2mqtt/0x00158d000465ad6f temp salon ›, payload ‹ {« battery »:57,« humidity »:50.46,« linkquality »:255,« power_outage_count »:31,« pressure »:981.1,« temperature »:15.26,« voltage »:2935} ›
Zigbee2MQTT:debug 2023-03-07 17:55:49: Received Zigbee message from ‹ 0x00158d000465ad6f temp salon ›, type ‹ attributeReport ›, cluster ‹ msPressureMeasurement ›, data ‹ {« measuredValue »:981,« scale »:-1,« scaledValue »:9813} › from endpoint 1 with groupID null
Zigbee2MQTT:info 2023-03-07 17:55:49: MQTT publish: topic ‹ zigbee2mqtt/0x00158d000465ad6f temp salon ›, payload ‹ {« battery »:57,« humidity »:50.46,« linkquality »:252,« power_outage_count »:31,« pressure »:981.3,« temperature »:15.26,« voltage »:2935} ›
Bon, j’ai des bonnes nouvelles, après 2 heures d’expérimentations je viens de réussir à reproduire le souci !! 
Je suis parti d’une installation vierge sur un Raspberry Pi 3 avec un dongle Sonoff Zigbee et un capteur de température Xiaomi Aqara.
Je pense que ce setup importe peu, mais je voulais partir d’une base totalement vierge.
1. Simulation d’un container MQTT arrêté (en cours de mise à jour peut-être ?)
docker stop gladys-z2m-mqtt
2. Redémarrage de Gladys (par exemple, lors d’une mise à jour)
docker restart gladys
Au redémarrage, le service Zigbee2mqtt relance le container MQTT arrêté :
2023-04-03T06:39:52+0200 <debug> init.js:64 (Zigbee2mqttManager.init) Zibgee2mqtt: installing and starting required docker containers...
2023-04-03T06:39:52+0200 <info> checkForContainerUpdates.js:14 (Zigbee2mqttManager.checkForContainerUpdates) Checking for current installed versions and required updates...
2023-04-03T06:39:53+0200 <info> installMqttContainer.js:98 (Zigbee2mqttManager.installMqttContainer) MQTT broker is starting...
2023-04-03T06:39:58+0200 <info> installMqttContainer.js:104 (Zigbee2mqttManager.installMqttContainer) MQTT broker container successfully started
2023-04-03T06:39:58+0200 <info> installZ2mContainer.js:59 (Zigbee2mqttManager.installZ2mContainer) Preparing Zigbee2mqtt environment...
2023-04-03T06:39:58+0200 <trace> installZ2mContainer.js:63 (Zigbee2mqttManager.installZ2mContainer) Zigbee2mqtt : configuration file already exists.
2023-04-03T06:39:58+0200 <info> installZ2mContainer.js:78 (Zigbee2mqttManager.installZ2mContainer) Zigbee2mqtt container successfully started
Puis tente de se connecter au broker:
2023-04-03T06:39:58+0200 <info> connect.js:14 (Zigbee2mqttManager.connect) Connecting Gladys to mqtt://localhost:1884 MQTT broker...
2023-04-03T06:39:59+0200 <debug> saveConfiguration.js:20 (Zigbee2mqttManager.saveConfiguration) Zigbee2mqtt: storing configuration...
2023-04-03T06:39:59+0200 <info> connect.js:24 (MqttClient.<anonymous>) Connected to MQTT container mqtt://localhost:1884
2023-04-03T06:39:59+0200 <info> subscribe.js:12 (Zigbee2mqttManager.subscribe) Subscribing to MQTT topic zigbee2mqtt/#
Jusque là tout semble bon !
Sauf qu’à partir de là, impossible de recevoir quoi que ce soit, tout échoue avec la même erreur que tout le monde a:
2023-04-03T06:40:17+0200 <debug> findMatchingExpose.js:32 (Zigbee2mqttManager.findMatchingExpose) Device "0x00158d0001a4c7c7" not found
2023-04-03T06:40:17+0200 <error> handleMqttMessage.js:103 () Failed to convert value for device 0x00158d0001a4c7c7: Error: Zigbee2mqqt expose not found on device "0x00158d0001a4c7c7" with property "battery".
at Zigbee2mqttManager.readValue (/src/server/services/zigbee2mqtt/lib/readValue.js:16:11)
at /src/server/services/zigbee2mqtt/lib/handleMqttMessage.js:99:31
at Array.forEach (<anonymous>)
at Zigbee2mqttManager.handleMqttMessage (/src/server/services/zigbee2mqtt/lib/handleMqttMessage.js:91:41)
at MqttClient.<anonymous> (/src/server/services/zigbee2mqtt/lib/connect.js:53:12)
at MqttClient.emit (node:events:513:28)
at MqttClient.\_handlePublish (/src/server/services/zigbee2mqtt/node_modules/mqtt/lib/client.js:1277:12)
at MqttClient.\_handlePacket (/src/server/services/zigbee2mqtt/node_modules/mqtt/lib/client.js:410:12)
at work (/src/server/services/zigbee2mqtt/node_modules/mqtt/lib/client.js:321:12)
at processTicksAndRejections (node:internal/process/task_queues:77:11)
2023-04-03T06:40:17+0200 <debug> findMatchingExpose.js:32 (Zigbee2mqttManager.findMatchingExpose) Device "0x00158d0001a4c7c7" not found
En investiguant un peu, je vois que ces fameux expose sont stockés dans une variable this.discoveredDevices dans le code.
Cette variable a l’air d’être remplie lors de la réception d’un message sur le topic zigbee2mqtt/bridge/devices
Ce qui devrait afficher un log Getting config devices from Zigbee2mqtt
Hors, dans mes logs, je n’ai pas ce log Getting config devices from Zigbee2mqtt, et ainsi je pense que ce fameux discoveredDevices n’est pas initialisé !
Du coup viens la question: a quelle condition le container Zigbee2mqtt envoie les informations sur les devices ?
La documentation mentionne:
Ce qui expliquerait donc pourquoi on n’obtient rien dans cette variable !
Mais du coup, j’ai du mal à comprendre comment ça peut fonctionner le reste du temps ?
Je viens de refaire un:
docker restart gladys
Et malgré ça, toujours impossible de faire marcher le service, j’obtiens toujours :
2023-04-03T07:02:30+0200 <debug> findMatchingExpose.js:32 (Zigbee2mqttManager.findMatchingExpose) Device "0x00158d0001a4c7c7" not found
2023-04-03T07:02:30+0200 <error> handleMqttMessage.js:103 () Failed to convert value for device 0x00158d0001a4c7c7: Error: Zigbee2mqqt expose not found on device "0x00158d0001a4c7c7" with property "voltage".
at Zigbee2mqttManager.readValue (/src/server/services/zigbee2mqtt/lib/readValue.js:16:11)
at /src/server/services/zigbee2mqtt/lib/handleMqttMessage.js:99:31
at Array.forEach (<anonymous>)
at Zigbee2mqttManager.handleMqttMessage (/src/server/services/zigbee2mqtt/lib/handleMqttMessage.js:91:41)
at MqttClient.<anonymous> (/src/server/services/zigbee2mqtt/lib/connect.js:53:12)
at MqttClient.emit (node:events:513:28)
at MqttClient._handlePublish (/src/server/services/zigbee2mqtt/node_modules/mqtt/lib/client.js:1277:12)
at MqttClient._handlePacket (/src/server/services/zigbee2mqtt/node_modules/mqtt/lib/client.js:410:12)
at work (/src/server/services/zigbee2mqtt/node_modules/mqtt/lib/client.js:321:12)
at processTicksAndRejections (node:internal/process/task_queues:77:11)
@AlexTrovato Est-ce que tu sais quand ce topic est appelé par Zigbee2mqtt, et quelle était l’hypothèse faite lors du développement pour que ça marche ? ^^
Dans le code de Zigbee2mqtt, voilà toutes les conditions pour que Zigbee2mqtt re-publie la liste des devices:
(Nous sommes dans la fonction Bridge.start):
@pierre-gilles du fait qe le message sur le topic zigbee2mqtt/bridge/devices soit « retained », dès lors que le client MQTT se connecte à ce topic sur le broker, ce message sera reçu, car il est « pile » dans le broker.
Donc normalement, au démarrage de Gladys, dès que le service est initialisé, Gladys reçoit l’état complet des devices z2m connectés, et devrait donc remplir cette variable.
1 « J'aime »
Bien vu, c’est le détail qui me manquait, je ne savais même pas que ça existait en MQTT ! Merci.
Mais du coup je comprend mieux pourquoi ça ne marche pas si le broker MQTT a été relancé, je ne crois pas qu’on ait de persistence sur Mosquitto, et donc si le broker est re-installé par Watchtower, puis Gladys redémarré, et que Zigbee2mqtt n’est pas redémarré, alors Gladys est « dans le noir »
Scénario:
- Mosquitto restart pour se mettre à jour et perd les messages retained
- Gladys est relancée, et ne récupère pas les listes des devices
J’ai regardé la date de la dernière mise à jour de Mosquitto, et c’était le 30 mars, pile 1 jour avant la mise à jour de Gladys.
Le scénario se vérifie !
Une option serait d’activer la persistance dans Mosquitto :
Tu en penses quoi ?
ça me paraît faire sens !
J’espère juste qu’on ne va pas stocker trop.
Sinon il faut voir s’il n’y a pas le moyen de définir une taille maximale de stockage…
La persistence ne stocke que les messages retained (à vérifier), donc ça ne va pas trop stocker je pense 
1 « J'aime »
Je prends peut-être le problème à l’envers mais est-ce que ce ne serait pas à Gladys de stocker cette information ?
Effectivement c’est une option, après est-ce que c’est pas dommage de re-coder ce comportement qui est probablement utilisé par Zigbee2mqtt a plusieurs endroits, là ou Mosquitto le fait nativement ?
Je partirais plus sur l’activation de la persistence, ce qui nous évite d’autres bugs à l’avenir si Zigbee2mqtt se met à utiliser cette fonctionnalité à d’autres endroits.
Du coup j’ai commencé une PR sur le sujet :
J’en ai profité pour retirer le script shell qui lançait le container pour passer à du code Node. Au moins c’est testé du coup, et plus fiable.
J’en ai aussi profité pour traiter cette carte:
Ca accélère grandement les tests !
1 « J'aime »
Tu as généré une image de test ?
Yes, je l’ai testé partiellement pour l’instant mais ça a l’air de fonctionner !
Image Docker:
gladysassistant/gladys:fix-zigbee2mqtt-disconnect-bug
Testé en réel, la migration a fonctionné avec succès !
2023-04-07T04:20:42+0200 <info> init.js:38 (Zigbee2mqttManager.init) Zigbee2mqtt USB dongle attached to /dev/ttyUSB0
2023-04-07T04:20:42+0200 <info> checkForContainerUpdates.js:14 (Zigbee2mqttManager.checkForContainerUpdates) Checking for current installed versions and required updates...
2023-04-07T04:20:42+0200 <info> checkForContainerUpdates.js:18 (Zigbee2mqttManager.checkForContainerUpdates) MQTT container: update #3 of the container required...
2023-04-07T04:20:42+0200 <info> checkForContainerUpdates.js:35 (Zigbee2mqttManager.checkForContainerUpdates) MQTT container: update #3 of the container done
2023-04-07T04:20:42+0200 <info> checkForContainerUpdates.js:40 (Zigbee2mqttManager.checkForContainerUpdates) Z2M container: update #3 of the container required...
2023-04-07T04:20:43+0200 <info> checkForContainerUpdates.js:57 (Zigbee2mqttManager.checkForContainerUpdates) Z2M container: update #3 of the container done
2023-04-07T04:20:43+0200 <info> installMqttContainer.js:29 (Zigbee2mqttManager.installMqttContainer) MQTT broker is being installed as Docker container...
2023-04-07T04:20:43+0200 <info> installMqttContainer.js:30 (Zigbee2mqttManager.installMqttContainer) Pulling eclipse-mosquitto:2 image...
2023-04-07T04:20:46+0200 <info> installMqttContainer.js:34 (Zigbee2mqttManager.installMqttContainer) Preparing broker environment...
2023-04-07T04:20:46+0200 <info> installMqttContainer.js:41 (Zigbee2mqttManager.installMqttContainer) Writing Mosquitto config file in /var/lib/gladysassistant/zigbee2mqtt/mqtt/mosquitto.conf
2023-04-07T04:20:46+0200 <info> installMqttContainer.js:50 (Zigbee2mqttManager.installMqttContainer) Creating container with data in "/var/lib/gladysassistant" on host...
2023-04-07T04:20:47+0200 <info> installMqttContainer.js:64 (Zigbee2mqttManager.installMqttContainer) MQTT broker is restarting...
2023-04-07T04:20:52+0200 <info> installMqttContainer.js:72 (Zigbee2mqttManager.installMqttContainer) Creating user/pass...
2023-04-07T04:20:53+0200 <info> installMqttContainer.js:81 (Zigbee2mqttManager.installMqttContainer) MQTT broker is restarting...
2023-04-07T04:20:59+0200 <info> installMqttContainer.js:86 (Zigbee2mqttManager.installMqttContainer) MQTT broker container successfully started and configured
2023-04-07T04:20:59+0200 <info> installZ2mContainer.js:34 (Zigbee2mqttManager.installZ2mContainer) Zigbee2mqtt is being installed as Docker container...
2023-04-07T04:20:59+0200 <info> installZ2mContainer.js:35 (Zigbee2mqttManager.installZ2mContainer) Pulling koenkk/zigbee2mqtt:latest image...
2023-04-07T04:21:02+0200 <info> installZ2mContainer.js:38 (Zigbee2mqttManager.installZ2mContainer) Configuration of Device /dev/ttyUSB0
2023-04-07T04:21:02+0200 <info> installZ2mContainer.js:43 (Zigbee2mqttManager.installZ2mContainer) Creation of container...
2023-04-07T04:21:03+0200 <info> installZ2mContainer.js:46 (Zigbee2mqttManager.installZ2mContainer) Zigbee2mqtt successfully installed and configured as Docker container
2023-04-07T04:21:03+0200 <info> installZ2mContainer.js:59 (Zigbee2mqttManager.installZ2mContainer) Preparing Zigbee2mqtt environment...
2023-04-07T04:21:03+0200 <info> installZ2mContainer.js:72 (Zigbee2mqttManager.installZ2mContainer) Zigbee2mqtt container is starting...
2023-04-07T04:21:08+0200 <info> installZ2mContainer.js:78 (Zigbee2mqttManager.installZ2mContainer) Zigbee2mqtt container successfully started
2023-04-07T04:21:08+0200 <info> connect.js:14 (Zigbee2mqttManager.connect) Connecting Gladys to mqtt://localhost:1884 MQTT broker...
2023-04-07T04:21:09+0200 <info> connect.js:24 (MqttClient.<anonymous>) Connected to MQTT container mqtt://localhost:1884
2023-04-07T04:21:09+0200 <info> subscribe.js:12 (Zigbee2mqttManager.subscribe) Subscribing to MQTT topic zigbee2mqtt/#
Dossier /var/lib/gladysassistant/zigbee2mqtt/mqtt:
Redémarrer Mosquitto ne semble plus gêner Gladys !
3 « J'aime »
@AlexTrovato A priori pas de risque d’avoir un disque qui grossit à vue d’oeil :
On va aussi gagner en fiabilité vu que du coup si Mosquitto redémarre pendant que Gladys est offline et que des messages sont dans le broker, on ne les perdra pas
7 « J'aime »
Bug corrigé dans Gladys Assistant v4.20 :
1 « J'aime »