La commande *Ajouter* met 1 minute à rendre la main

Jeedom : 4.3.15
Plugin : 2022-10-18 01:05:11

Bonjour,

Dans un scénario, la commande Ajouter met 1 minute à rendre la main.

Le scénario de test (la commande #[Maison][Téléphone Thomas][Notification]# est juste là pour montrer que ce n’est pas elle qui ralenti l’envoi)

Les logs du scénario :

[2023-08-18 16:59:32][SCENARIO] -- Start : Scenario lance manuellement.
[2023-08-18 16:59:32][SCENARIO] - Exécution du sous-élément de type [action] : action
[2023-08-18 16:59:32][SCENARIO] Exécution de la commande  [Maison][Notification Aération Thomas][Ajouter] avec comme option(s) : {"background":"0","title":"","message":"test notif"}
[2023-08-18 17:00:36][SCENARIO] Exécution de la commande  [Maison][Téléphone Thomas][Notification] avec comme option(s) : {"background":"0","title":"","message":"test notif direct"}
[2023-08-18 17:00:36][SCENARIO] Fin correcte du scénario

La configuration de la file de notification :

Les logs du plugin

0427|[2023-08-18 16:59:32][DEBUG] : locked: Notification Aération Thomas
0428|[2023-08-18 16:59:32][INFO] : Added message 'test notif' in queue 'Notification Aération Thomas'
0429|[2023-08-18 16:59:32][DEBUG] : unlock: Notification Aération Thomas
0430|[2023-08-18 16:59:32][DEBUG] : checking queue Notification Aération Thomas
0431|[2023-08-18 16:59:32][INFO] : start sending message from queue Notification Aération Thomas
0432|[2023-08-18 16:59:32][DEBUG] : Sending message: title:''; message:'test notif'
0433|[2023-08-18 16:59:32][INFO] : Notification envoyée à [Maison][Téléphone Thomas][Notification] depuis la file [Maison][Notification Aération Thomas].
0434|[2023-08-18 16:59:32][INFO] : Notification ajoutée à l'historique
0435|[2023-08-18 17:00:10][DEBUG] : discardExpiredMessages
0436|[2023-08-18 17:00:10][DEBUG] : message queue empty
0437|[2023-08-18 17:00:10][DEBUG] : checking queue Notification Aération Sébastien
0438|[2023-08-18 17:00:10][DEBUG] : condition not true: #181#
0439|[2023-08-18 17:00:10][DEBUG] : discardExpiredMessages
0440|[2023-08-18 17:00:10][DEBUG] : message queue empty
0441|[2023-08-18 17:00:10][DEBUG] : checking queue Notification Aération Thomas
0442|[2023-08-18 17:00:10][DEBUG] : message queue empty

Quand le test est fait, il y a 0 message dans la file d’attente.

Merci :slight_smile:

Édit : la commande #[Maison][Présence][Thomas]# est une info binaire d’un virtuel

Édit 2 : ça ne le fait pas si il y a répétition :

[2023-08-18 17:17:46][SCENARIO] Exécution de la commande  [Maison][Notification Aération Thomas][Ajouter] avec comme option(s) : {"background":"0","title":"","message":"test notif"}
[2023-08-18 17:17:46][SCENARIO] Exécution de la commande  [Maison][Téléphone Thomas][Notification] avec comme option(s) : {"background":"0","title":"","message":"test notif direct"}
[2023-08-18 17:17:46][SCENARIO] Fin correcte du scénario
0470|[2023-08-18 17:17:46]DEBUG : message already in history
0471|[2023-08-18 17:17:46]DEBUG : checking queue Notification Aération Thomas
0472|[2023-08-18 17:17:46]DEBUG : message queue empty

ca c’est le log de lors de l’ajout:

0427|[2023-08-18 16:59:32][DEBUG] : locked: Notification Aération Thomas
0428|[2023-08-18 16:59:32][INFO] : Added message 'test notif' in queue 'Notification Aération Thomas'
0429|[2023-08-18 16:59:32][DEBUG] : unlock: Notification Aération Thomas
0430|[2023-08-18 16:59:32][DEBUG] : checking queue Notification Aération Thomas
0431|[2023-08-18 16:59:32][INFO] : start sending message from queue Notification Aération Thomas
0432|[2023-08-18 16:59:32][DEBUG] : Sending message: title:''; message:'test notif'
0433|[2023-08-18 16:59:32][INFO] : Notification envoyée à [Maison][Téléphone Thomas][Notification] depuis la file [Maison][Notification Aération Thomas].
0434|[2023-08-18 16:59:32][INFO] : Notification ajoutée à l'historique

ca c’est log log du cron qui check s’il faut envoyer des notifs (donc aucun rapport avec le scénario)

0435|[2023-08-18 17:00:10][DEBUG] : discardExpiredMessages
0436|[2023-08-18 17:00:10][DEBUG] : message queue empty
0437|[2023-08-18 17:00:10][DEBUG] : checking queue Notification Aération Sébastien
0438|[2023-08-18 17:00:10][DEBUG] : condition not true: #181#
0439|[2023-08-18 17:00:10][DEBUG] : discardExpiredMessages
0440|[2023-08-18 17:00:10][DEBUG] : message queue empty
0441|[2023-08-18 17:00:10][DEBUG] : checking queue Notification Aération Thomas
0442|[2023-08-18 17:00:10][DEBUG] : message queue empty

du coup après ce log: 0434|[2023-08-18 16:59:32][INFO] : Notification ajoutée à l'historique
le plugin va:

  • attendre le délai pour le speech si configuré (si c’était le cas il y aurait un log du genre sleepDuringSpeech - message ...
  • attendre le délai configuré dans « Pause entre 2 éval », 2s par défaut

et c’est tout, il a fini
donc l’ajout et l’envoi ont pris 0s, je ne vois pas ce qui fait que le scénario ne continue pas directement après
j’ai rajouté un log en debug (end sending message from queue ...) à la fin de la boucle de traitement pour en avoir le coeur net, après cette ligne de log il n’y a plus de code du plugin qui est executé

j’ai testé un scénario similaire, je ne reproduis pas:

0006|[2023-08-18 17:32:52][SCENARIO] -- Start : Scenario lance manuellement.
0007|[2023-08-18 17:32:52][SCENARIO] - Exécution du sous-élément de type [action] : action
0008|[2023-08-18 17:32:52][SCENARIO] Exécution de la commande  [notif_queue][notif_test][Ajouter] avec comme option(s) : {"background":"0","title":"test","message":"test message"}
0009|[2023-08-18 17:32:52][SCENARIO] Exécution de la commande  [communication][telegram][Mips] avec comme option(s) : {"background":"0","title":"test","message":"test"}
0010|[2023-08-18 17:32:52][SCENARIO] Fin correcte du scénario

deux tests que tu peux faire:

  • ajouter un délai du TTS pour valider que tu vois le log
  • mettre « false » en condition de ta queue pour qu’il ne rentre pas dans la boucle d’envoi et voir si ca change qlqch sur le délai du scénario
    image

de mon coté j’ai testé les 2 cas aussi et ca ne change rien (enfin j’ai 10s de délai quand le TTS est activé mais c’est normal)

Premier test :
log scénario :

[2023-08-18 17:52:04][SCENARIO] - Exécution du sous-élément de type [action] : action
[2023-08-18 17:52:04][SCENARIO] Exécution de la commande  [Maison][Notification Aération Thomas][Ajouter] avec comme option(s) : {"background":"0","title":"","message":"test notif sms 2"}
[2023-08-18 17:53:17][SCENARIO] Exécution de la commande  [Maison][Téléphone Thomas][Notification] avec comme option(s) : {"background":"0","title":"","message":"test notif direct"}
[2023-08-18 17:53:17][SCENARIO] Fin correcte du scénario

log plugin :

0453|[2023-08-18 17:52:04]DEBUG : locked: Notification Aération Thomas
0454|[2023-08-18 17:52:05]INFO : Added message 'test notif sms 2' in queue 'Notification Aération Thomas'
0455|[2023-08-18 17:52:05]DEBUG : unlock: Notification Aération Thomas
0456|[2023-08-18 17:52:05]DEBUG : checking queue Notification Aération Thomas
0457|[2023-08-18 17:52:05]INFO : start sending message from queue Notification Aération Thomas
0458|[2023-08-18 17:52:05]DEBUG : Sending message: title:''; message:'test notif sms 2'
0459|[2023-08-18 17:52:05]INFO : Notification envoyée à [Maison][SMS][Thomas] depuis la file [Maison][Notification Aération Thomas].
0460|[2023-08-18 17:52:05]INFO : Notification ajoutée à l'historique
0461|[2023-08-18 17:52:05]DEBUG : Syllables count: 4
0344|[2023-08-18 17:52:05]DEBUG : sleepDuringSpeech - message:test notif sms 2, syllables:4 => 8s

Second test (il n’y a plus la minute d’attente)

log scénario :

[2023-08-18 17:54:07][SCENARIO] - Exécution du sous-élément de type [action] : action
[2023-08-18 17:54:07][SCENARIO] Exécution de la commande  [Maison][Notification Aération Thomas][Ajouter] avec comme option(s) : {"background":"0","title":"","message":"test notif sms 3"}
[2023-08-18 17:54:07][SCENARIO] Exécution de la commande  [Maison][Téléphone Thomas][Notification] avec comme option(s) : {"background":"0","title":"","message":"test notif direct"}
[2023-08-18 17:54:07][SCENARIO] Fin correcte du scénario

log plugin :

0484|[2023-08-18 17:54:07]DEBUG : locked: Notification Aération Thomas
0485|[2023-08-18 17:54:07]INFO : Added message 'test notif sms 3' in queue 'Notification Aération Thomas'
0486|[2023-08-18 17:54:07]DEBUG : unlock: Notification Aération Thomas
0487|[2023-08-18 17:54:07]DEBUG : checking queue Notification Aération Thomas
0488|[2023-08-18 17:54:07]DEBUG : condition not true: false

J’ai essayé aussi en changeant la commande de notification (sms au lieu de jeedomconnect) et le résultat est le même

J’ai ajouté des logs dans la fonction sendAllMessages à la fin :

                        log::add('notificationqueue','debug',"Before wait queue");
                        notificationqueue::wait($condition, $sleep);
                        log::add('notificationqueue','debug',"After wait queue");

et tu peux voir dans les logs que c’est la ligne notificationqueue::wait($condition, $sleep); qui prend du temps

0482|[2023-08-18 18:13:19]DEBUG : locked: Notification Aération Thomas
0483|[2023-08-18 18:13:19]INFO : Added message 'test notif sms 7' in queue 'Notification Aération Thomas'
0484|[2023-08-18 18:13:19]DEBUG : unlock: Notification Aération Thomas
0485|[2023-08-18 18:13:19]DEBUG : checking queue Notification Aération Thomas
0486|[2023-08-18 18:13:19]INFO : start sending message from queue Notification Aération Thomas
0487|[2023-08-18 18:13:19]DEBUG : Sending message: title:''; message:'test notif sms 7'
0488|[2023-08-18 18:13:19]INFO : Notification envoyée à [Maison][Téléphone Thomas][Notification] depuis la file [Maison][Notification Aération Thomas].
0489|[2023-08-18 18:13:19]INFO : Notification ajoutée à l'historique
0490|[2023-08-18 18:13:19]DEBUG : Before wait queue
0491|[2023-08-18 18:14:03]DEBUG : discardExpiredMessages
0492|[2023-08-18 18:14:03]DEBUG : message queue empty
0493|[2023-08-18 18:14:03]DEBUG : checking queue Notification Aération Sébastien
0494|[2023-08-18 18:14:03]DEBUG : condition not true: #181#
0495|[2023-08-18 18:14:03]DEBUG : discardExpiredMessages
0496|[2023-08-18 18:14:03]DEBUG : message queue empty
0497|[2023-08-18 18:14:03]DEBUG : checking queue Notification Aération Thomas
0498|[2023-08-18 18:14:03]DEBUG : message queue empty
0499|[2023-08-18 18:14:23]DEBUG : After wait queue

Ok. J’ai trouvé.

Si dans la configuration, dans Envoi automatique SI, je ne mets que #[Maison][Présence][Thomas]#, alors la ligne $result = jeedom::evaluateExpression($condition); de la fonction wait retourne false et donc on itère 30 fois 2 secondes (1 minutes :wink: )

Si dans Envoi automatique SI, je mets #[Maison][Présence][Thomas]#==1 alors l’expression est évaluée à true et la fonction wait prend 2 secondes.

Ce sujet a été automatiquement fermé après 24 heures suivant le dernier commentaire. Aucune réponse n’est permise dorénavant.