Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

somtimes hanging tests due to imap/idle/missing messages? #326

Closed
hpk42 opened this issue Aug 10, 2019 · 1 comment

Comments

@hpk42
Copy link
Contributor

commented Aug 10, 2019

In the following log-excerpt is a typical way how a send_receive tests between two live accounts fails sometimes: look down at 6.86 [imap-ac2] DC_EVENT_INFO(0,'IMAP-IDLE SPAWNING') where the imap-ac2 thread fails to notice/fetch a new message while imap-ac1 wakes up from idle (bcc-self-sent message) and successfully looks at the message. Note that this only happens sometimes, often the test also passes. Which leads me to suspect that between imap/idle and imap fetch there might be an issue -- is the imap-server maybe sending something in-between and we are missing it? (the imap-parser/client library is not a proven piece of code yet -- and was largely replaced/rewritten during the c2rust transition)

========== sending text message from ac1 to ac2 ==========
4.41 [MAIN-ac1] DC_EVENT_INFO(0,'[autocrypt] no peerstate for tmp_5445382945159463@testrun.org')
4.41 [MAIN-ac1] DC_EVENT_INFO(0,'dc_e2ee_encrypt tmp_5445382945159463@testrun.org HAS NO peerstate false')
4.42 [MAIN-ac1] DC_EVENT_INFO(0,'Interrupting SMTP-idle...')
4.42 [MAIN-ac1] DC_EVENT_MSGS_CHANGED(10,10)
4.42 [smtp-ac1] DC_EVENT_INFO(0,'SMTP-idle ended.')
4.42 [smtp-ac1] DC_EVENT_INFO(0,'SMTP-jobs started...')
4.42 [MAIN-ac1] -- waiting for event with regex: DC_EVENT_MSG_DELIVERED --
4.42 [smtp-ac1] DC_EVENT_INFO(0,'SMTP-job #3, action 5901 started...')
6.30 [imap-ac1] DC_EVENT_IMAP_CONNECTED(0,'IMAP-LOGIN as tmp_4204542017905347@testrun.org, capabilities:  LOGIN-REFERRALS LIST-EXTENDED MOVE MULTIAPPEND SASL-IR IMAP4rev1 URL-PARTIAL QRESYNC SEARCHRES CATENATE ID SORT=DISPLAY CONTEXT=SEARCH ENABLE NAMESPACE CHILDREN THREAD=REFS UNSELECT ESEARCH LITERAL+ ESORT WITHIN THREAD=ORDEREDSUBJECT THREAD=REFERENCES SPECIAL-USE LIST-STATUS BINARY UIDPLUS I18NLEVEL=1 IDLE SORT CONDSTORE')
6.30 [imap-ac1] DC_EVENT_INFO(0,'INBOX-fetch started...')
6.40 [imap-ac1] DC_EVENT_INFO(0,'lastseenuid initialized to 7 for INBOX@1565471101')
6.44 [imap-ac1] DC_EVENT_INFO(0,'0 mails read from "INBOX".')
6.44 [imap-ac1] DC_EVENT_INFO(0,'INBOX-fetch done in 24.8080 ms.')
6.44 [imap-ac1] DC_EVENT_INFO(0,'INBOX-IDLE started...')
6.44 [imap-ac1] DC_EVENT_INFO(0,'IMAP-IDLE SPAWNING')
6.72 [smtp-ac1] DC_EVENT_SMTP_MESSAGE_SENT(0,'Message was sent to SMTP server')
6.73 [smtp-ac1] DC_EVENT_MSG_DELIVERED(10,10)
6.73 [smtp-ac1] DC_EVENT_INFO(0,'SMTP-jobs ended.')
6.73 [smtp-ac1] DC_EVENT_INFO(0,'SMTP-idle started...')

========== wait for ac2 to receive message ==========
6.74 [MAIN-ac2] -- waiting for event with regex: DC_EVENT_MSGS_CHANGED --
6.76 [imap-ac2] DC_EVENT_IMAP_CONNECTED(0,'IMAP-LOGIN as tmp_5445382945159463@testrun.org, capabilities:  WITHIN SORT=DISPLAY NAMESPACE LOGIN-REFERRALS LITERAL+ ESORT THREAD=REFERENCES CONTEXT=SEARCH LIST-STATUS THREAD=ORDEREDSUBJECT ID ENABLE CHILDREN BINARY THREAD=REFS CATENATE I18NLEVEL=1 SPECIAL-USE SORT CONDSTORE IMAP4rev1 MOVE SEARCHRES UIDPLUS IDLE URL-PARTIAL UNSELECT LIST-EXTENDED QRESYNC SASL-IR MULTIAPPEND ESEARCH')
6.76 [imap-ac2] DC_EVENT_INFO(0,'INBOX-fetch started...')
6.83 [imap-ac2] DC_EVENT_INFO(0,'lastseenuid initialized to 7 for INBOX@1565471107')
6.86 [imap-ac2] DC_EVENT_INFO(0,'0 mails read from "INBOX".')
6.86 [imap-ac2] DC_EVENT_INFO(0,'INBOX-fetch done in 376.6290 ms.')
6.86 [imap-ac2] DC_EVENT_INFO(0,'INBOX-IDLE started...')
6.86 [imap-ac2] DC_EVENT_INFO(0,'IMAP-IDLE SPAWNING')
7.38 [imap-ac1] DC_EVENT_INFO(0,'IMAP-IDLE has data.')
7.38 [imap-ac1] DC_EVENT_INFO(0,'INBOX-IDLE ended.')
7.38 [imap-ac1] DC_EVENT_INFO(0,'dc_perform_imap_jobs starting.')
7.38 [imap-ac1] DC_EVENT_INFO(0,'dc_perform_imap_jobs ended.')
7.38 [imap-ac1] DC_EVENT_INFO(0,'INBOX-fetch started...')
7.44 [imap-ac1] DC_EVENT_INFO(0,'Receiving message INBOX/8...')
@hpk42

This comment has been minimized.

Copy link
Contributor Author

commented Aug 14, 2019

think it's fixed by #359

@hpk42 hpk42 closed this Aug 14, 2019

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
1 participant
You can’t perform that action at this time.