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

mujmap sync => Error encountered in the status line: timed out reading response #37

Open
teto opened this issue Jul 2, 2022 · 5 comments
Labels
bug Something isn't working
Milestone

Comments

@teto
Copy link
Contributor

teto commented Jul 2, 2022

My initial sync worked well, I now tried to change tags and reran mujmap sync and I hit:
Error encountered in the status line: timed out reading response
I wonder if its due to the size of the request, I've got sthg like 11000mails and I get in the log a seemingly long request with lines of

"keywords/$answered": Null, "keywords/$forwarded": Null, "keywords/$draft": Null, "keywords/$phishing": Null, "keywords/$seen": Bool(true), "keywords/$flagged": Null, "mailboxIds": Object({"86a2d9f5-c010-45a0-82ac-67c2e55da6d3": Bool(true), "a0b0232f-b611-4eaf-b185-6ed047a97c96": Bool(true), "e33b24e7-4faf-46e9-83fd-d3c97ce02868": Bool(true)})}, Id("Maa48c356ce4142cfb28d5c97"): {"keywords/$forwarded": Null, "keywords/$answered": Null, "keywords/$phishing": Null, "mailboxIds": Object({"24e4de2e-a4e2-4cd9-822e-08efbf5efab9": Bool(true), "a0b0232f-b611-4eaf-b185-6ed047a97c96": Bool(true)}), "keywords/$flagged": Null, "keywords/$seen": Bool(true), "

This is the end of the log

24e4de2e-a4e2-4cd9-822e-08efbf5efab9": Bool(true), "a0b0232f-b611-4eaf-b185-6ed047a97c96": Bool(true)}), "keywords/$forwarded": Null, "keywords/$seen": Bool(true), "keywords/$draft": Null, "keywords/$answered": Null, "keywords/$phishing": Null, "keywords/$flagged": Null}, Id("M672a30cce2ed0a77ea870958"): {"keywords/$phishing": Null, "mailboxIds": Object({"24e4de2e-a4e2-4cd9-822e-08efbf5efab9": Bool(true), "a0b0232f-b611-4eaf-b185-6ed047a97c96": Bool(true)}), "keywords/$seen": Bool(true), "keywords/$flagged": Null, "keywords/$answered": Null, "keywords/$forwarded": Null, "keywords/$draft": Null}}
[2022-07-02T20:11:32Z DEBUG ureq::stream] connecting to jmap.fastmail.com:443 at 66.111.4.141:443
[2022-07-02T20:11:32Z DEBUG rustls::client::hs] Resuming session
[2022-07-02T20:11:32Z DEBUG rustls::client::hs] Using ciphersuite Tls13(Tls13CipherSuite { suite: TLS13_AES_256_GCM_SHA384, bulk: Aes256Gcm })
[2022-07-02T20:11:32Z DEBUG rustls::client::tls13] Resuming using PSK
[2022-07-02T20:11:32Z DEBUG rustls::client::tls13] TLS1.3 encrypted extensions: [ServerNameAck]
[2022-07-02T20:11:32Z DEBUG rustls::client::hs] ALPN protocol is None
[2022-07-02T20:11:32Z DEBUG ureq::stream] created stream: TcpStream { addr: 192.168.1.13:36722, peer: 66.111.4.141:443, fd: 9 }
[2022-07-02T20:11:32Z DEBUG ureq::unit] sending request POST https://jmap.fastmail.com/api/
[2022-07-02T20:11:32Z DEBUG ureq::unit] writing prelude: POST /api/ HTTP/1.1
    Host: jmap.fastmail.com
    User-Agent: ureq/2.4.0
    Accept: */*
    Authorization: ***
    Content-Type: application/json
    accept-encoding: gzip
    Content-Length: 1288766
[2022-07-02T20:11:33Z DEBUG rustls::client::tls13] Ticket saved
[2022-07-02T20:11:37Z DEBUG ureq::stream] dropping stream: TcpStream { addr: 192.168.1.13:36722, peer: 66.111.4.141:443, fd: 9 }
error: Could not sync mail: Could not push changes to JMAP server: Could not complete API request: https://jmap.fastmail.com/api/: Network Error: Network Error: Error encountered in a header: timed out reading response

the funny thing is that the tag I changed was successfully sent to fastmail as I can now see it in the UI, which is fantastic , it means mujmap has been solving my single biggest issue in my setup so thanks for that. Let me know how I can help (testing etc)

@elizagamedev elizagamedev added the bug Something isn't working label Jul 5, 2022
@elizagamedev
Copy link
Owner

Yeah, I'm guessing it's because massive tag changes like that result in massive requests. To solve this, we should add a new config option to optionally hard-cap the number of messages to update in a request for flaky servers or connections.

@elizagamedev elizagamedev added this to the v0.2.1 milestone Jul 5, 2022
@teto
Copy link
Contributor Author

teto commented Jul 5, 2022

It passed for the first time now:

➜ mujmap sync
Retrieving metadata... (9945 possibly changed)
Downloading new mail...
█████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████ 11/11
Applying changes to notmuch database... (11 new, 9945 changed, 0 destroyed)
Applying changes to JMAP server... (10419 changed)
~/maildir/fastmail took 25s 
➜ mujmap sync
Retrieving metadata... (10420 possibly changed)
Applying changes to notmuch database... (0 new, 10420 changed, 0 destroyed)
Applying changes to JMAP server... (509 changed)

The funny thing is that the server times out instantaneously, it's not like it tries to process my request, the timeout on fastmail side must be low. I dont know if this should be configurable (at least userfacing) but the ability to split a big request into several small ones would be nice. Maybe even the server could return a hint about the size of the request.

@elizagamedev
Copy link
Owner

The server does return a hint about the request size, and we do respect it, but it doesn't seem like it can be fully trusted given the behavior you're encountering 😔

@georgyo
Copy link

georgyo commented Mar 4, 2023

Also running into this problem, while trying to sync 14k changes do to changing a tag.

Not the most elegant of solutions, but as a band-aid, this worked for me.

diff --git a/src/remote.rs b/src/remote.rs
index 7829255..74abac1 100644
--- a/src/remote.rs
+++ b/src/remote.rs
@@ -994,7 +994,7 @@ impl Remote {
         // Send it off into cyberspace~
         const SET_METHOD_ID: &str = "0";
 
-        let chunk_size = self.session.capabilities.core.max_objects_in_set as usize;
+        let chunk_size = 50 as usize;
 
         for chunk in &updates.into_iter().chunks(chunk_size) {
             let account_id = &self.session.primary_accounts.mail;

@vbmithr
Copy link

vbmithr commented Aug 6, 2023

Same issue here, does not work well on massive changes.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

4 participants