Log Alexaapi_node se remplit de Remote WS-MQTT Close 1006


Informations Jeedom Delta

Debian 11.11
Core : 4.4.18 (master)
DNS Jeedom Delta : non

Plugin : Alexa - API
Version : 2024-09-27 01:03:51 (beta)
Statut Démon : Démarré - (2024-10-05 10:40:04)

Bonjour

Le 5 Octobre dernier j’ai du régénérer le cookie qui avait sauté et de ce fait redémarré le demon Alexa-api.
Depuis tout fonctionne bien, si ce n’est que j’ai remarqué que les logs se remplissaient régulièrement avec la même erreur:

0280|[10/5/2024, 10:32:12 AM] INFO  : {API}    ╔═══════[Lancement  /updateallalarms sur G0922H0724530U80
0281|[10/5/2024, 10:32:12 AM] DEBUG  : {Remote} ║     Envoi ►►► : {"host":"alexa.amazon.fr","path":"/api/notifications?cached=true&_=1728117132517","method":"GET","timeout":10000,"headers":{}}
0282|[10/5/2024, 10:32:12 AM] DEBUG  : {Remote} ║ ◄◄◄ Réception : {"notifications":[{"alarmLabel":null,"alarmTime":0,"assigner":null,"automationId":null,"createdDate":1712781968709,"deferredAtTime":null,"deliveryMetadata":null,"deliveryType":null,"deviceName":null,"deviceSerialNumber":"G0922H0724530U80","deviceType":"A4ZXE0RM7LQ7A","extensibleAttribute":null,"followUpMetadata":null,"geoLocationTriggerData":null,"id":"A4ZXE0RM7LQ7A-G0922H0724530U80-202c1e36-4235-304e-8257-ffa5a0ea469a","lastOccurrenceTimeInMilli":0,"lastTriggerTimeInUtc":null,"lastUpdatedDate":1712813351334,"loopCount":null,"mrmGroupContext":null,"musicAlarmId":null,"musicEntity":null,"notificationIndex":"202c1e36-4235-304e-8257-ffa5a0ea469a","originalDate":"2024-04-11","originalDurationInMillis":0,"originalTime":"07:30:00.000","personProfile":null,"primaryDeviceState":null,"provider":null,"rRuleData":null,"recurrenceEligibility":false,"recurringPattern":null,"remainingTime":0,"reminderAppLabel":null,"reminderLabel":null,"reminderSubLabel":null,"showDeregisteredWarning":null,"skillInfo":null,"sleepTrackingAlarmProperties":{"sleepTrackingEnabled":false},"snoozedToTime":null,"sound":{"displayName":"Simple Alarm","folder":null,"id":"system_alerts_melodic_01","isChildDirected":false,"numAssets":0,"pricing":null,"providerId":"ECHO","sampleUrl":"https://s3.amazonaws.com/deeappservice.prod.notificationtones/system_alerts_melodic_01.mp3","sampleVideoUrl":null,"skillUrl":null},"status":"OFF","targetPersonProfiles":null,"taskMetadata":null,"timeZoneId":null,"timerLabel":null,"tmwNotificationProperties":null,"triggerTime":0,"type":"Alarm","version":"9"},{"alarmLabel":null,"alarmTime":0,"assigner":null,"automationId":null,"createdDate":1638380946932,"deferredAtTime":null,"deliveryMetadata":null,"deliveryType":null,"deviceName":null,"deviceSerialNumber":"G091EV08118404XC","deviceType":"A2U21SRK4QGSE1","extensibleAttribute":null,"followUpMetadata":null,"geoLocationTriggerData":null,"id":"A2U21SRK4QGSE1-G091EV08118404XC-e97bf180-f71c-30cf-a1f3-580da3e13197","lastOccurrenceTimeInMilli":0,"lastTriggerTimeInUtc":null,"lastUpdatedDate":1638380956364,"loopCount":null,"mrmGroupContext":null,"musicAlarmId":null,"musicEntity":null,"notificationIndex":"e97bf180-f71c-30cf-a1f3-580da3e13197","originalDate":"2021-12-02","originalDurationInMillis":0,"originalTime":"00:00:00.000","personProfile":null,"primaryDeviceState":null,"provider":null,"rRuleData":null,"recurrenceEligibility":false,"recurringPattern":null,"remainingTime":0,"reminderAppLabel":null,"reminderLabel":null,"reminderSubLabel":null,"showDeregisteredWarning":null,"skillInfo":null,"sleepTrackingAlarmProperties":{"sleepTrackingEnabled":false},"snoozedToTime":null,"sound":{"displayName":"Simple Alarm","folder":null,"id":"system_alerts_melodic_01","isChildDirected":false,"numAssets":0,"pricing":null,"providerId":"ECHO","sampleUrl":"https://s3.amazonaws.com/deeappservice.prod.notificationtones/system_alerts_melodic_01.mp3","sampleVideoUrl":null,"skillUrl":null},"status":"OFF","targetPersonProfiles":null,"taskMetadata":null,"timeZoneId":null,"timerLabel":null,"tmwNotificationProperties":null,"triggerTime":0,"type":"Alarm","version":"4"},{"alarmLabel":null,"alarmTime":0,"assigner":null,"automationId":null,"createdDate":1701191261633,"deferredAtTime":null,"deliveryMetadata":null,"deliveryType":null,"deviceName":null,"deviceSerialNumber":"G091EV08118404XC","deviceType":"A2U21SRK4QGSE1","extensibleAttribute":null,"followUpMetadata":null,"geoLocationTriggerData":null,"id":"A2U21SRK4QGSE1-G091EV08118404XC-7ed2048e-1322-3dba-a13a-9ee2d92dd15a","lastOccurrenceTimeInMilli":0,"lastTriggerTimeInUtc":null,"lastUpdatedDate":1701325842598,"loopCount":null,"mrmGroupContext":null,"musicAlarmId":null,"musicEntity":null,"notificationIndex":"7ed2048e-1322-3dba-a13a-9ee2d92dd15a","originalDate":"2023-11-30","originalDurationInMillis":0,"originalTime":"07:30:00.000","personProfile":null,"primaryDeviceState":null,"provider":null,"rRuleData":null,"recurrenceEligibility":false,"recurringPattern":null,"remainingTime":0,"reminderAppLabel":null,"reminderLabel":null,"reminderSubLabel":null,"showDeregisteredWarning":null,"skillInfo":null,"sleepTrackingAlarmProperties":{"sleepTrackingEnabled":false},"snoozedToTime":null,"sound":{"displayName":"Simple Alarm","folder":null,"id":"system_alerts_melodic_01","isChildDirected":false,"numAssets":0,"pricing":null,"providerId":"ECHO","sampleUrl":"https://s3.amazonaws.com/deeappservice.prod.notificationtones/system_alerts_melodic_01.mp3","sampleVideoUrl":null,"skillUrl":null},"status":"OFF","targetPersonProfiles":null,"taskMetadata":null,"timeZoneId":null,"timerLabel":null,"tmwNotificationProperties":null,"triggerTime":0,"type":"Alarm","version":"7"}]}
0283|[10/5/2024, 10:32:12 AM] DEBUG  : {Remote} ╠════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════════
0284|[10/5/2024, 10:32:16 AM] INFO  : {MQTT}   ║ Send Ping
0285|[10/5/2024, 10:32:16 AM] DEBUG  : {MQTT}   ║ Incoming RAW message: 4d5347000000652df5a25b66000000010d42b5ce0000003d504f4e000000005bcedaee5bcedaee000000070052006500670075006c0061007246414245
0286|[10/5/2024, 10:32:16 AM] INFO  : {MQTT}   ║ Incoming message: {"service":"FABE","messageType":"MSG","channel":101,"messageId":771072603,"moreFlag":1711276032,"seq":1,"checksum":222475726,"content":{"messageType":"PON","payloadData":{"type":"Buffer","data":[0,0,0,91,206,218,238,91,206,218,238,0,0,0,7,0,82,0,101,0,103,0,117,0,108,0,97,0,114]}}}
0287|[10/5/2024, 10:32:16 AM] INFO  : {MQTT}   ║ ◄◄◄  MQTT Pong
0288|[10/5/2024, 10:35:16 AM] INFO  : {MQTT}   ║ Send Ping
0289|[10/5/2024, 10:35:16 AM] DEBUG  : {MQTT}   ║ Incoming RAW message: 4d5347000000652dda5d406600000001f77c08cd0000003d504f4e000000005bd19a255bd19a25000000070052006500670075006c0061007246414245
0290|[10/5/2024, 10:35:16 AM] INFO  : {MQTT}   ║ Incoming message: {"service":"FABE","messageType":"MSG","channel":101,"messageId":769285440,"moreFlag":1711276032,"seq":1,"checksum":4152101069,"content":{"messageType":"PON","payloadData":{"type":"Buffer","data":[0,0,0,91,209,154,37,91,209,154,37,0,0,0,7,0,82,0,101,0,103,0,117,0,108,0,97,0,114]}}}
0291|[10/5/2024, 10:35:16 AM] INFO  : {MQTT}   ║ ◄◄◄  MQTT Pong
0292|[10/6/2024, 3:30:10 PM][] : {API}: Restart
0293|[10/6/2024, 3:30:10 PM][] : {API}: ******************************************************************
0294|[10/6/2024, 3:30:10 PM][] : {API}: *****************************Relance forcée du Serveur*************
0295|[10/6/2024, 3:30:10 PM][] : {API}: ******************************************************************
0296|[10/6/2024, 3:30:15 PM][] : Alexa-Remote WS-MQTT: Close: 1006:
0297|[10/6/2024, 3:30:25 PM][] : Alexa-Remote WS-MQTT: Close: 1006:
0298|[10/6/2024, 3:30:36 PM][] : Alexa-Remote WS-MQTT: Close: 1006:
0299|[10/6/2024, 3:30:51 PM][] : Alexa-Remote WS-MQTT: Close: 1006:
.....
Lignes manuellement supprimées car trop nombreuses et toutes identiques
.....
0564|[10/9/2024, 4:25:42 PM][] : Alexa-Remote WS-MQTT: Close: 1006:
0565|[10/9/2024, 4:26:42 PM][] : Alexa-Remote WS-MQTT: Close: 1006:
0566|[10/9/2024, 4:27:42 PM][] : Alexa-Remote WS-MQTT: Close: 1006:
0567|[10/9/2024, 4:28:43 PM][] : Alexa-Remote WS-MQTT: Close: 1006:
0568|[10/9/2024, 4:29:43 PM][] : Alexa-Remote WS-MQTT: Close: 1006:
0569|[10/9/2024, 4:30:44 PM][] : Alexa-Remote WS-MQTT: Close: 1006:
0570|[10/9/2024, 4:31:44 PM][] : Alexa-Remote WS-MQTT: Close: 1006:
0571|[10/9/2024, 4:32:45 PM][] : Alexa-Remote WS-MQTT: Close: 1006:
0572|[10/9/2024, 4:33:45 PM][] : Alexa-Remote WS-MQTT: Close: 1006:

A en croire le log, cette erreur apparait suite à une relance forcée du serveur

0293|[10/6/2024, 3:30:10 PM][] : {API}: ******************************************************************
0294|[10/6/2024, 3:30:10 PM][] : {API}: *****************************Relance forcée du Serveur*************
0295|[10/6/2024, 3:30:10 PM][] : {API}: ******************************************************************

Relance qui n’est pas de mon fait, ni liée à un redémarrage de Jeedom.

Sur le forum on trouve trace de cette erreur dans ce topic de Janvier 2023:

A priori ce problème n’a jamais été solutionné par les différentes versions du plugin ?

Cela ne gêne en rien au fonctionnement, mais c’est juste désagrable de voir des logs se remplir inutilement, on peut passer à coté d’une info importante.
Si toutefois cela pouvait être corrigé, ce serait bien

Merci

Bonjour

Suite de mes constats…

Après une série lignes dans le log, cela s’est arrête dès que ce message est apparu :

0499|[10/10/2024, 1:39:01 PM][] : Alexa-Remote WS-MQTT: Close: 4016: Server shutting down

Là encore sans intervention manuelle ou rédémarrage du plugin ou de Jeedom.

Du coup les logs sont plus lisibles depuis et m’ont permis de voir que ce matin le démon était encore passé NOK :frowning:

0000|[2024-10-11 11:05:04] ERROR  : Attention je pense qu'il y a un soucis avec le démon que j'ai relancé plus de 3 fois consécutivement
0001|[2024-10-11 11:08:10] ERROR  : Attention je pense qu'il y a un soucis avec le démon que j'ai relancé plus de 3 fois consécutivement

Comme d’habitude c’est encore le cookie qui a sauté

0520|[10/11/2024, 11:05:11 AM] ERROR  : {API}    ╠════════════════════════════════════════════════════════════════════════════════════════
0521|[10/11/2024, 11:05:11 AM] ERROR  : {API}    ║   Souci dans l'initiatlisation du serveur Error:  La génération automatique n'a pas fonctionné (ce qui est normal lors d'une génération manuelle), vérifiez toutefois que cette adresse est bien une adresse locale de votre réseau :undefined et que le port utilisé est bien 3457 :35873, sinon vérifiez la configuration réseau de Jeedom (Réglages/Système/Configuration/Réseau/Accès interne) et assurez vous d'avoir jeedom sur le port 80 et d'être connecté sur le même réseau local (pas à distance).
0522|[10/11/2024, 11:05:11 AM] ERROR  : {API}    ║   ou le serveur alexa.amazon.fr n'est pas joignable
0523|[10/11/2024, 11:05:11 AM] ERROR  : {API}    ╚════════════════════════════════════════════════════════════════════════════════════════

Régénération manuelle du cookie, redémarrage du démon et tout est reparti. Mais pour combien de temps ?

Dans le dernier log, il y a une information qui m’interroge :

vérifiez toutefois que cette adresse est bien une adresse locale de votre réseau :undefined et que le port utilisé est bien 3457

A quoi fait référence cette adresse non définie ? Serait-ce quelque chose qui manque au niveau de la configuration ou qui se volatilise ?
Le dernier message d’erreur est de 11:05 et j’ai régénéré le cookie manuellement à 11:07, il est donc peu probable que ce soit le serveur alexa.amazon.fr qui soit down d’autant plus qu’il répond bien au ping.

Cette fois-ci le cookie a tenu 6 jours, mais auparavant il tenait des mois sans aucune intervention.
Est-un souci coté Jeedom ? Plugin ? Amazon ?

C’est reparti ce jour à 15h30 après une relance forcée du serveur.
Relance de quel serveur ? Car cela ne semble pas concerner le démon du plugin qui n’a pas changé de date

image

0500|[10/13/2024, 3:30:08 PM][] : {API}: Restart
0501|[10/13/2024, 3:30:09 PM][] : {API}: ******************************************************************
0502|[10/13/2024, 3:30:09 PM][] : {API}: *****************************Relance forcée du Serveur*************
0503|[10/13/2024, 3:30:09 PM][] : {API}: ******************************************************************
0504|[10/13/2024, 3:30:14 PM][] : Alexa-Remote WS-MQTT: Close: 1006:
0505|[10/13/2024, 3:30:25 PM][] : Alexa-Remote WS-MQTT: Close: 1006:
etc etc

Et ce toutes les minutes, voire même plus fréquement parfois.

Vu que l’heure est la même à chaque fois et également la même que celle constatée dans le post cité en référence, cela doit bien être dû à une tâche interne au plugin lancée à ce moment non ?
Cela ne fait pas passer le démon en NOK heureusement, mais ça flood pour rien.

Une petite idée pour éviter ça ?

Merci

slt a tout hasard, tu aurais pas utilisé mon astuce de scénario, pour remonter les volumes info ?

Bonjour

Non pas du tout