(Re)démarrage auto du démon

Hello,

J’ai des soucis où le démon ne (re)démarre pas automatiquement alors que je suis en « Gestion automatique ». De même j’ai aussi « Heartbeat (min) » à 60 et « Redémarrer démon » coché.

Par contre, en lancement manuel, aucun problème.

J’ai 9 brokers avec un Mosquitto distant et une centaine d’équipements. Je voulais savoir si d’autres personnes rencontrent aussi le problème, car j’ai rien vu dans les logs.

PS : Tous les autres plugins se (re)lancent en auto.

Bonjour,

Peut-on voir la page config du plugin et la page santé jeedom? + les logs

Tout est vert de mon côté :


c’est plus pour avoir toutes les infos nécessaires que de savoir si c’est vert ou rouge…

et il manque les logs (au moment d’une coupure & non redémarrage évidement)

Je regarderais pour activer le debug dans les logs, comme c’est de la production j’évite de solliciter à tout va.

L’idée du post c’était aussi de savoir si ça marche chez les autres ou c’est que chez moi. Si je suis un cas isolé, alors je dois avoir une spécificité et ça m’aidera dans la solution.

Quand vous tuez le démon, ça redémarre chez vous ?

Le démarrage du démon n’est pas géré par le plugin mais par le core, par jeedom.

donc la réponse à

me semble évidente sinon il y aurait des milliers de personnes avec le problème, tout plugin confondu.

Ca fonctionne sur tes autres plugins?

Justement oui, tous les plugins hormis jmqtt, c’est pour ça que j’aimerais des retours pour savoir si je suis un cas isolé.

J’ai un début de piste sur un raté de redémarrage :

0000|[2024-02-27 19:19:21,050]INFO Main            MainThread   set_log_level() : New log level set to: WARNING
0001|[2024-02-27 19:20:17,901]INFO Main            MainThread   set_log_level() : New log level set to: WARNING
0002|[2024-02-27 19:20:20,806]INFO Main            MainThread   set_log_level() : New log level set to: WARNING
0003|[2024-02-27 19:20:20,806]ERROR Main            MainThread         prepare() : This daemon already runs! Exit 0
0004|[2024-02-27 19:21:21,078]INFO Main            MainThread   set_log_level() : New log level set to: WARNING
0005|[2024-02-27 19:22:21,410]INFO Main            MainThread   set_log_level() : New log level set to: WARNING
0006|[2024-02-27 19:22:21,410]ERROR Main            MainThread         prepare() : This daemon already runs! Exit 0
0007|[2024-02-27 19:23:21,732]INFO Main            MainThread   set_log_level() : New log level set to: WARNING
0008|[2024-02-27 19:23:21,732]ERROR Main            MainThread         prepare() : This daemon already runs! Exit 0
0009|[2024-02-27 19:24:22,093]INFO Main            MainThread   set_log_level() : New log level set to: WARNING
0010|[2024-02-27 19:24:22,093]ERROR Main            MainThread         prepare() : This daemon already runs! Exit 0
0011|[2024-02-27 19:24:36,072]ERROR JMsg.Rcv        MainThread      is_working() : Nothing has been received for 315s (max 315s), Jeedom does not want me any longer.
0012|[2024-02-27 19:25:06,519]INFO Main            MainThread   set_log_level() : New log level set to: WARNING
0013|[2024-02-27 19:25:22,611]INFO Main            MainThread   set_log_level() : New log level set to: WARNING
0014|[2024-02-27 19:25:32,927]ERROR JMsg.Rcv        MainThread      is_working() : Nothing has been received for 315s (max 315s), Jeedom does not want me any longer.
0015|[2024-02-27 19:26:22,940]INFO Main            MainThread   set_log_level() : New log level set to: WARNING
0016|[2024-02-27 19:26:22,941]ERROR Main            MainThread         prepare() : This daemon already runs! Exit 0
0017|[2024-02-27 19:26:36,096]ERROR JMsg.Rcv        MainThread      is_working() : Nothing has been received for 315s (max 315s), Jeedom does not want me any longer.
0018|[2024-02-27 19:27:22,303]INFO Main            MainThread   set_log_level() : New log level set to: WARNING
0019|[2024-02-27 19:27:22,303]ERROR Main            MainThread         prepare() : This daemon already runs! Exit 0
0020|[2024-02-27 19:28:22,602]INFO Main            MainThread   set_log_level() : New log level set to: WARNING
0021|[2024-02-27 19:28:22,602]ERROR Main            MainThread         prepare() : This daemon already runs! Exit 0
0022|[2024-02-27 19:29:22,892]INFO Main            MainThread   set_log_level() : New log level set to: WARNING
0023|[2024-02-27 19:29:22,893]ERROR Main            MainThread         prepare() : This daemon already runs! Exit 0
0024|[2024-02-27 19:30:03,996]INFO Main            MainThread   set_log_level() : New log level set to: WARNING
0025|[2024-02-27 19:30:21,581]ERROR JMsg.Rcv        MainThread      is_working() : Nothing has been received for 315s (max 315s), Jeedom does not want me any longer.
0026|[2024-02-27 19:30:22,960]INFO Main            MainThread   set_log_level() : New log level set to: WARNING
0027|[2024-02-27 19:30:37,623]ERROR JMsg.Rcv        MainThread      is_working() : Nothing has been received for 315s (max 315s), Jeedom does not want me any longer.

Et effectivement, sur le serveur :

root        1265  0.0  0.0   8248  4512 ?        SN   19:20   0:00 sudo /usr/bin/node /var/www/html/plugins/mqtt2/resources/mqtt2d/mqtt2d.js --loglevel warning --socketport 55035 --mqtt_server mqtt://XXX:1883 --username  --password  --callback http://localhost/plugins/mqtt2/core/php/jeeMqtt2.php --apikey XXX --cycle 0.3 --pid /tmp/jeedom/mqtt2/deamon.pid
root        1266  1.0  0.1 11430184 84092 ?      SNl  19:20   0:09 /usr/bin/node /var/www/html/plugins/mqtt2/resources/mqtt2d/mqtt2d.js --loglevel warning --socketport 55035 --mqtt_server mqtt://XXX:1883 --username  --password  --callback http://localhost/plugins/mqtt2/core/php/jeeMqtt2.php --apikey XXX --cycle 0.3 --pid /tmp/jeedom/mqtt2/deamon.pid
root        7050  0.2  0.0 248580 22740 ?        SNl  19:30   0:00 /var/www/html/plugins/jMQTT/resources/jmqttd/venv/bin/python3 /var/www/html/plugins/jMQTT/resources/jmqttd/jmqttd.py
root        9721  0.5  0.0 174744 22504 ?        SNl  19:35   0:00 /var/www/html/plugins/jMQTT/resources/jmqttd/venv/bin/python3 /var/www/html/plugins/jMQTT/resources/jmqttd/jmqttd.py

Après relance :

root        1265  0.0  0.0   8248  4512 ?        SN   19:20   0:00 sudo /usr/bin/node /var/www/html/plugins/mqtt2/resources/mqtt2d/mqtt2d.js --loglevel warning --socketport 55035 --mqtt_server mqtt://192.168.10.153:1883 --username  --password  --callback http://localhost/plugins/mqtt2/core/php/jeeMqtt2.php --apikey XXX --cycle 0.3 --pid /tmp/jeedom/mqtt2/deamon.pid
root        1266  0.9  0.1 11433476 86728 ?      SNl  19:20   0:11 /usr/bin/node /var/www/html/plugins/mqtt2/resources/mqtt2d/mqtt2d.js --loglevel warning --socketport 55035 --mqtt_server mqtt://XXXX:1883 --username  --password  --callback http://localhost/plugins/mqtt2/core/php/jeeMqtt2.php --apikey XXX --cycle 0.3 --pid /tmp/jeedom/mqtt2/deamon.pid
www-data   10181  1.6  0.0 839612 25096 ?        Sl   19:35   0:04 /var/www/html/plugins/jMQTT/resources/jmqttd/venv/bin/python3 /var/www/html/plugins/jMQTT/resources/jmqttd/jmqttd.py

Je dois regarder pourquoi ça boucle comme ça, en plus c’est aléatoire et en activant en mode INFO ça génère beaucoup de ligne quand on a beaucoup d’équipements.

Hello @defmy,

Tu peux désactiver les « Heartbeat » jMQTT les gèrent en interne.

Tu as 9 « Brokers » ou 9 « Equipements Broker » ?
Si tous tes équipements sont sur le même Mosquitto, pourquoi créer plusieurs « Equipements Broker », ça augmente la charge du système pour rien.

Peux-tu préciser si tu as régler le problème (2 démon jMQTT lancés en même temps) ou pas ?

Je ne comprend pas bien ce qui « boucle », si 2 démon sont lancés en même temps, l’un des 2 doit mourir. On voit bien dans les logs que le nouveau se suicide, car l’autre « marche bien », selon lui.
Je ne pense pas que tu auras ce problème à l’avenir sans activer les « Heartbeat ».

Tiens-moi au courant,
Bad

C’était activé pour tester l’autodémarrage du côté de Jeedom mais vu que le plugin jMQTT le gère aussi, je vais le désactiver pour éviter de faire doublon.

J’ai 9 équipements broker sur le même mosquitto. C’est pour découper par protocole (Zwave, Zigbee, Enocean, Rfxcom…). Ça me permet de savoir quel protocole est en échec en cas de problème, en plus j’ai le nombre d’équipements par protocole, c’est mieux que tout en vrac et que j’arrive plus à me retrouver.

Je n’ai pas réussi à reproduire le problème, jMQTT ne tombe pas tout le temps^^
Peut-être que le souci du double vérification est lié à ce problème de double processus, on verra si le problème persiste après la désactivation du check du heartbeat.

Par contre je viens de faire un test en tuant le service, je suis en gestion automatique, j’ai bien KO dans statut mais aucune relance, c’est normal ? Jeedom ne devrait pas le démarrer quand même ?

Je reste sur ça dans les logs puis plus rien :

[2024-03-01 11:06:45,011][INFO] Main            MainThread        shutdown() : Stop jMQTT python daemon
[2024-03-01 11:06:45,092][INFO] JMsg.Rcv        SockIn            _loopRcv() : Stopped
[2024-03-01 11:06:45,093][INFO] Client1577      Brk1577Th    on_disconnect() : Disconnected from broker.
[2024-03-01 11:06:45,093][INFO] Client1054      Brk1054Th    on_disconnect() : Disconnected from broker.
[2024-03-01 11:06:45,094][INFO] Client1055      Brk1055Th    on_disconnect() : Disconnected from broker.
[2024-03-01 11:06:45,095][INFO] Client1057      Brk1057Th    on_disconnect() : Disconnected from broker.
[2024-03-01 11:06:45,095][INFO] Client1058      Brk1058Th    on_disconnect() : Disconnected from broker.
[2024-03-01 11:06:45,096][INFO] Client1297      Brk1297Th    on_disconnect() : Disconnected from broker.
[2024-03-01 11:06:45,096][INFO] Client1377      Brk1377Th    on_disconnect() : Disconnected from broker.
[2024-03-01 11:06:45,097][INFO] Client1135      Brk1135Th    on_disconnect() : Disconnected from broker.
[2024-03-01 11:06:45,097][INFO] Client801       Brk801Th     on_disconnect() : Disconnected from broker.
[2024-03-01 11:06:45,145][INFO] JMsg.Snd        SockOut           _loopSnd() : Stopped

OK, je reste en attente pour le moment au cas où le problème se reproduit.

Si la gestion automatique est bien activée, le démon doit se relancer tout seul dans les 2 minutes.

C’est bien le cas chez toi ? J’ai bien laissé une grosse minute après un kill, je vais essayer de mettre un timer pour allez jusqu’à 2 minutes mais comme c’est de la production je ne peux que le faire en période calme la nuit O:-)

Voilà j’ai de nouveau le problème, pas de redémarrage automatique après un reboot :

[2024-03-16 16:45:08,603]INFO Main MainThread set_log_level() : New log level set to: DEBUG
[2024-03-16 16:45:08,603]DEBUG Main MainThread prepare() : Writing PID 1288 to /tmp/jeedom/jMQTT/jmqttd.py.pid
[2024-03-16 16:45:08,604]INFO Main MainThread prepare() : Log level : debug
[2024-03-16 16:45:08,604]INFO Main MainThread prepare() : Socket port : 0
[2024-03-16 16:45:08,604]INFO Main MainThread prepare() : Callback url: http://localhost:80/plugins/jMQTT/core/php/callback.php
[2024-03-16 16:45:08,604]INFO Main MainThread prepare() : PID file : /tmp/jeedom/jMQTT/jmqttd.py.pid
[2024-03-16 16:45:08,604]DEBUG Main MainThread prepare() : Apikey : *****
[2024-03-16 16:45:08,604]DEBUG JMsg.Rcv MainThread receiver_start() : Start requested
[2024-03-16 16:45:08,604]DEBUG JMsg.Rcv SockIn _loopRcv() : Start
[2024-03-16 16:45:08,604]INFO JMsg.Rcv MainThread receiver_start() : Started, listening on [127.0.0.1:40619]
[2024-03-16 16:45:08,612]DEBUG JMsg.Snd MainThread send_test() : Test successful
[2024-03-16 16:45:08,612]DEBUG JMsg.Snd MainThread sender_start() : Start requested
[2024-03-16 16:45:08,612]DEBUG JMsg.Snd SockOut _loopSnd() : Start
[2024-03-16 16:45:08,612]INFO JMsg.Snd MainThread sender_start() : Started
[2024-03-16 16:45:08,657]DEBUG JMsg.Snd MainThread send() : Sent TO Jeedom 1 messages handled in 44.713259ms (qToJ size 0): [{‹ cmd ›: ‹ daemonUp ›}]
[2024-03-16 16:45:08,658]DEBUG Main MainThread open_comm() : Open Comm : Sent Daemon Up signal to Jeedom, got data: «  »
[2024-03-16 16:45:53,714]DEBUG JMsg.Snd SockOut _loopSnd() : Sending a heartbeat to Jeedom, nothing sent since 45s (max 45s)
[2024-03-16 16:45:53,752]DEBUG JMsg.Snd SndNoBlkHb send() : Sent TO Jeedom 1 messages handled in 40.043592ms (qToJ size 0): [{‹ cmd ›: ‹ hb ›}]
[2024-03-16 16:46:38,765]DEBUG JMsg.Snd SockOut _loopSnd() : Sending a heartbeat to Jeedom, nothing sent since 45s (max 45s)
[2024-03-16 16:46:38,802]DEBUG JMsg.Snd SndNoBlkHb send() : Sent TO Jeedom 1 messages handled in 38.957119ms (qToJ size 0): [{‹ cmd ›: ‹ hb ›}]
[2024-03-16 16:47:23,911]DEBUG JMsg.Snd SockOut _loopSnd() : Sending a heartbeat to Jeedom, nothing sent since 45s (max 45s)
[2024-03-16 16:47:23,953]DEBUG JMsg.Snd SndNoBlkHb send() : Sent TO Jeedom 1 messages handled in 44.553518ms (qToJ size 0): [{‹ cmd ›: ‹ hb ›}]

Et ça tourne en boucle comme ça, et ce malgré le message « Started ».

Quand je regarde les processus, bizarre que ça se lance en root :

root 1288 0.3 0.0 248580 22644 ? SNl 16:45 0:00 /var/www/html/plugins/jMQTT/resources/jmqttd/venv/bin/python3 /var/www/html/plugins/jMQTT/resources/jmqttd/jmqttd.py

Si je clique moi-même sur démarrer, ça se lance sans problème.

Salut,

Petite précision peut-être importante, la gestion automatique du démon par Jeedom n’est pas immédiate après un arrêt du démon mais s’exécute toutes les 5 minutes. Il faut donc attendre 5 minutes au maximum.

Hello,

D’après ce log (jMQTTd), le daemon est OK, tu peux me donner le log jMQTT à la même période stp ?

Après recheck toute ta config, je vois que tu es en docker sur une base Ubuntu, pourquoi ce choix ?

Bad

Je suis bien sous Debian, ma base de données est sur une autre image basée sur Ubuntu.

C’est bizarre, malgré ce message, Jeedom indiquait bien KO dans la gestion des services. Par contre, je n’ai pas de log de jMQTT, juste jMQTTd.

C’est assez étrange, le test est pourtant un simple uname -a en local… Peux-tu passer cette commande dans Réglages> Système> Configuration> Onglet OS/DB> Bouton Administration Système, stp ?
image

Le plugin jMQTT est bien en Debug dans la modal de Configuration du plugin ?
image
Quelques captures plus haut, je vois bien un log jMQTT pourtant.

Sinon, peux-tu reproduire le bug en Debug ? (probablement avec un reboot ?)

Ah oui c’est peut-être parce que je remonte tout ça en syslog, donc pas de fichier en local. J’essayerais de reproduite dès que possible.

1 « J'aime »

Voici les logs que j’ai pour le client :

[2024-03-28 13:20:18][ERROR] : Impossible de lancer le démon jMQTT, vérifiez les logs de jMQTT
[2024-03-28 13:20:18][INFO] : Client MQTT déconnecté du Broker
[2024-03-28 13:20:18][DEBUG] : Nettoyage du Démon
[2024-03-28 13:20:09][WARNING] : Démon [8639:45587] : N’a pas pu être authentifié
[2024-03-28 13:20:08][INFO] : Lancement du démon jMQTT, commande shell: 'LOGLEVEL=debug CALLBACK=« http://127.0.0.1:80/plugins/jMQTT/core/php/callback.php » APIKEY=**** PIDFILE=/tmp/jeedom/jMQTT/jmqttd.py.pid /var/www/html/plugins/jMQTT/resources/jmqttd/venv/bin/python3 /var/www/html/plugins/jMQTT/resources/jmqttd/jmqttd.py >> /var/www/html/core/class/…/…/log/jMQTTd 2>&1 &

[2024-03-28 13:20:08][DEBUG] : Dépendances installées.
[2024-03-28 13:20:03][INFO] : Client MQTT déconnecté du Broker
[2024-03-28 13:20:03][INFO] : Démarrage du démon jMQTT
[2024-03-28 13:20:03][DEBUG] : Nettoyage du Démon
[2024-03-28 13:20:03][ERROR] : Attention je pense qu’il y a un soucis avec le démon que j’ai relancé plus de 3 fois consécutivement

Je peux avoir le log jMQTTd en débug stp ?