Le démon ne trouve pas le mail contenant le code 2FA - OTP cannot be retrieved

Xav-74 · Décembre 7, 2020, 7:42

Bon j’ai finalement craqué sur des Arlo Pro 3 2K pendant le black friday
J’ai installé ton plugin hier et suivi toute la procédure qui s’est bien passée côté Arlo. J’ai ensuite rencontré un souci avec le démon. Je pense que c’est lié à la double authentification et l’accès à ma boite mail Free Jeedom. Je ne sais pas pourquoi au bout d’un moment cela est passé. La synchronisation a pu se faire et j’ai retrouvé mes matériels (base + caméras)

Mais ce matin, rebelote, le démon est en carafe.
Jeedom v4.1.16b
Buster uptodate

Voici les logs :

[2020-12-07 07:33:04][INFO] : MainThread : Start daemon
[2020-12-07 07:33:04][INFO] : MainThread : Log level : debug
[2020-12-07 07:33:04][DEBUG] : MainThread : Socket port : 55064
[2020-12-07 07:33:04][DEBUG] : MainThread : Socket host : localhost
[2020-12-07 07:33:04][DEBUG] : MainThread : PID file : /tmp/jeedom/arlo/deamon.pid
[2020-12-07 07:33:04][DEBUG] : MainThread : Writing PID 2877 to /tmp/jeedom/arlo/deamon.pid
[2020-12-07 07:33:04][DEBUG] : MainThread : Init request module v2.21.0
[2020-12-07 07:33:04][DEBUG] : MainThread : Starting new HTTP connection (1): 127.0.0.1:80
[2020-12-07 07:33:04][DEBUG] : MainThread : http://127.0.0.1:80 "GET /plugins/arlo/core/php/jeeArlo.php?test=1&apikey=FdKL2NfsMu9vHqa5OurgRVdgjyiidDm7 HTTP/1.1" 200 2
[2020-12-07 07:33:04][INFO] : MainThread : ffmpeg loglevel:debug->debug
[2020-12-07 07:33:04][INFO] : MainThread : Start listening
[2020-12-07 07:33:04][DEBUG] : ConnectionThread : Starting new HTTPS connection (1): ocapi-app.arlo.com:443
[2020-12-07 07:33:04][DEBUG] : MainThread : Socket interface started
[2020-12-07 07:33:04][DEBUG] : Thread-2  : LoopNetServer Thread started
[2020-12-07 07:33:04][DEBUG] : Thread-2  : Listening on: [localhost:55064]
[2020-12-07 07:33:04][DEBUG] : ConnectionThread : https://ocapi-app.arlo.com:443 "POST /api/auth HTTP/1.1" 200 None
[2020-12-07 07:33:04][DEBUG] : ConnectionThread : https://ocapi-app.arlo.com:443 "GET /api/getFactors?data%20=%201607326383 HTTP/1.1" 200 None
[2020-12-07 07:33:05][DEBUG] : ConnectionThread : https://ocapi-app.arlo.com:443 "POST /api/startAuth HTTP/1.1" 200 None
[2020-12-07 07:33:05][DEBUG] : ConnectionThread : pivot date:2020-12-07 07:32:05.045753
[2020-12-07 07:33:05][DEBUG] : ConnectionThread : login OK : [b'[CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE NOTIFY SPECIAL-USE QUOTA] Logged in']
[2020-12-07 07:33:05][INFO] : ConnectionThread : Processing inbox...
[2020-12-07 07:33:10][DEBUG] : ConnectionThread : login OK : [b'[CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE NOTIFY SPECIAL-USE QUOTA] Logged in']
[2020-12-07 07:33:10][INFO] : ConnectionThread : Processing inbox...
[2020-12-07 07:33:16][DEBUG] : ConnectionThread : login OK : [b'[CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE NOTIFY SPECIAL-USE QUOTA] Logged in']
[2020-12-07 07:33:16][INFO] : ConnectionThread : Processing inbox...
[2020-12-07 07:33:21][DEBUG] : ConnectionThread : login OK : [b'[CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE NOTIFY SPECIAL-USE QUOTA] Logged in']
[2020-12-07 07:33:21][INFO] : ConnectionThread : Processing inbox...
[2020-12-07 07:33:27][DEBUG] : ConnectionThread : login OK : [b'[CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE NOTIFY SPECIAL-USE QUOTA] Logged in']
[2020-12-07 07:33:27][INFO] : ConnectionThread : Processing inbox...
[2020-12-07 07:33:32][DEBUG] : ConnectionThread : login OK : [b'[CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE NOTIFY SPECIAL-USE QUOTA] Logged in']
[2020-12-07 07:33:32][INFO] : ConnectionThread : Processing inbox...
[2020-12-07 07:33:38][DEBUG] : ConnectionThread : login OK : [b'[CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE NOTIFY SPECIAL-USE QUOTA] Logged in']
[2020-12-07 07:33:38][INFO] : ConnectionThread : Processing inbox...
[2020-12-07 07:33:43][DEBUG] : ConnectionThread : login OK : [b'[CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE NOTIFY SPECIAL-USE QUOTA] Logged in']
[2020-12-07 07:33:43][INFO] : ConnectionThread : Processing inbox...
[2020-12-07 07:33:49][DEBUG] : ConnectionThread : login OK : [b'[CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE NOTIFY SPECIAL-USE QUOTA] Logged in']
[2020-12-07 07:33:49][INFO] : ConnectionThread : Processing inbox...
[2020-12-07 07:33:54][DEBUG] : ConnectionThread : login OK : [b'[CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE NOTIFY SPECIAL-USE QUOTA] Logged in']
[2020-12-07 07:33:54][INFO] : ConnectionThread : Processing inbox...
[2020-12-07 07:34:00][DEBUG] : ConnectionThread : login OK : [b'[CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE NOTIFY SPECIAL-USE QUOTA] Logged in']
[2020-12-07 07:34:00][INFO] : ConnectionThread : Processing inbox...
[2020-12-07 07:34:02][DEBUG] : MainThread : Signal 15 caught, exiting...
[2020-12-07 07:34:02][INFO] : MainThread : Shuting down
[2020-12-07 07:34:02][DEBUG] : MainThread : Removing PID file /tmp/jeedom/arlo/deamon.pid

Note que j’utilise également le plugin MailListener avec cette boite en imap sans souci.
Merci d’avance pour ton aide,

Xav

Mips · Décembre 7, 2020, 7:51

Salut,

Je peux voir le log « arlo » à la même heure?
je me demande s’il n’y a pas une ligne du genre [INFO] : Heartbeat: restarting daemon vers 7:34
parce que il me semble que le mail prend vraiment du temps à arriver

Xav-74 · Décembre 7, 2020, 7:55

Yes bien vu :

[2020-12-07 07:34:02][INFO] : Heartbeat: restarting daemon
[2020-12-07 07:34:03][INFO] : Lancement démon
[2020-12-07 07:34:03][DEBUG] : test from daemon

J’ai également checker dans ma boite mail :

A priori, le mail arrive bien

Xav-74 · Décembre 7, 2020, 8:06

Alors coïncidence ou pas, j’ai viré tous les mails de ma boite et à l’arrivée du suivant, le démon est reparti. Est-ce que si plusieurs mails provenant de l’adresse do_not_reply@arlo.com il ne prendrait pas le mauvais ?

Mips · Décembre 7, 2020, 8:20

Il prend le plus récent dans lequel il trouve un code (il log le code en debug) donc de ce coté ca devrait être ok et si pas on devrait voir le code, l’authentification serait refusé et il se relancerait donc au pire la fois suivante c’est bon.
J’avais testé avec quelques provider d’email et ca prenait plus ou mois de temps, genre 2 ou 3 essais de login max avant de voir le mail arriver mais chez toi on en voit plus de 10 et il n’a toujours pas trouvé de mail, autrement dit le mail n’est pas disponible dans la boite (quand il trouve un il indique check email:xxx avec le sujet, qui est normalement « Votre code d’authentification provisoire Arlo » et ensuite il log le code si trouvé);

je vais arranger le heartbeat pour qu’il ne coupe pas le démon tant que le login n’est pas fini; c’est ce qu’il se passe ici.
c’est vrai que je n’ai pas revu ce process depuis le 2fa et ca peut prendre plus de temps qu’avant…

Xav-74 · Décembre 7, 2020, 8:23

ok je vais regarder ca de plus près à la prochaine déconnexion. Je te tiens au jus !
Merci

Xav-74 · Décembre 7, 2020, 11:05

Bon cela a de nouveau lâché à 10h30.
Je me demande si le pb n’est pas au contraire que le mail arrive trop vite ? J’ai regardé au moment du démarrage du démon et le mail arrive en moins d’une sec avant même les logs sur l’écoute de la boite :

[2020-12-07 11:02:54][INFO] : ConnectionThread : Processing inbox...
[2020-12-07 11:03:00][DEBUG] : ConnectionThread : login OK : [b'[CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE NOTIFY SPECIAL-USE QUOTA] Logged in']

J’ai eu le cas sur mon plugin Verisure ou j’ai du mettre un sleep de 5s sur ma commande de refresh car le mail arrivait avant la fin de la commande précédant ce refresh.
Peut-être à creuser.

Xav

Mips · Décembre 7, 2020, 5:23

Je ne pense pas, je regarde tous les mails non vu reçu de do_not_reply@arlo.com à partir de 1 minute avant la demande de login et le mail ne peut pas arriver avant que le plugin ai demandé le code 2FA

mais ca serait plus facile avec le log complet, par exemple la date de référence est log mais vu l’extrait… on ne voit même pas d’erreur là.

En beta demain il y aura une version dans laquelle je pense avoir réglé le problème dont je parlais plus haut.

Xav-74 · Décembre 7, 2020, 5:28

Ah oui en effet 1 min ca devrait aller !

Voici les logs :
arlo.txt (56,8 Ko)
arlo_daemon.txt (165,9 Ko)

Impossible de redémarrer le démon depuis ce matin. J’ai fait pas mal de tests mais tu as au moins les logs sur les 2 dernières heures.

Je vais passer en béta ce soir et je testerai demain matin
Merci pour ton aide !

Mips · Décembre 7, 2020, 5:35

En voyant le log complet je me dis que tu as quand même peut-être un autre problème.
Clairement il y a eu le cas comme ce matin avec le heartbeat, donc mon « fix » est de toute façon bienvenu mais il y a quand même d’autres cas où cela devrait passer…

La boite mail est réservé au plugin ou pas?
Il n’y aurait pas un client mail qui noterait le mail comme vu? parce que le plugin ne va chercher que dans les mails non vu

Xav-74 · Décembre 7, 2020, 7:09

Ne cherche pas plus loin ! Comme mentionné dans mon premier message, j’utilise également le plugin MailListener pour mon plugin Verisure afin de traiter les notifications envoyées uniquement par mail. Et à chaque réception, il passe le mail en lu !
Mon mail est dédié à Jeedom pas uniquement à Arlo.
Je vais donc regarder comment contourner ce pb !

Merci pour ton diag

Xav

Xav-74 · Décembre 8, 2020, 9:38

Solution de contournement trouvée
Ajout d’un bloc code à la fin de mon scénario de vérification de mail Verisure :

$inbox = imap_open("{imap.free.fr:993/imap/ssl/novalidate-cert}INBOX", "username", "password");

$count = imap_num_msg($inbox);
$scenario->setLog($count);

$flag = imap_clearflag_full($inbox,$count,"\\Seen");	//passe le dernier message en non lu
$scenario->setLog($flag);								//si action réussie = 1

imap_close($inbox, CL_EXPUNGE);

Il repasse le dernier mail en non lu après l’avoir analysé, et le plugin Arlo peut donc checker le code provisoire
Merci encore pour ton aide,

Xav

Mips · Décembre 8, 2020, 9:50

Super,
le point des « mails non lus » était abordé dans la doc mais je vais reformuler cette partie dans la documentation pour que ca soit plus clair que le plugin se base la dessus pour trouver le bon mail en espérant que ca soit utile pour un autre.

ps: je me permet de modifier le titre du sujet aussi pour que cela soit plus visible via ce lien :https://community.jeedom.com/tag/plugin-arlo pour les suivants

Xav-74 · Décembre 8, 2020, 10:16

Je viens de relire la doc, parce que je l’avais parcouru avec beaucoup d’attention. Et en effet je suis passé à côté de cette notion de mail non lus !
A voir pour le passer en gras !

system · Décembre 9, 2020, 10:16

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