JMAP: bodyStructure blobId URLs 404 for emails with Content-Transfer-Encoding: quoted-printable

[afontenot]

Edit: after extensive debugging, I've managed to narrow the issue further as described in my comment below this question. I'm leaving this debugging information for posterity but I recommend jumping immediately to my comment: #758 (comment)

---

I have the aerc client successfully sending and receiving mail via JMAP.

When I send an email from aerc, a copy of it is placed in the "Sent Items" directory. I've also tested sending emails from one email account to another account on the same server. In either case, I can't view the message in any JMAP client that I've tested because the message blob can't be downloaded.

As part of investigating this, I even probed the API directly with the jmapc Python library. In all cases I've tried, any email that was sent from aerc can't be downloaded. Specifically, the blob URL 404s.

Nothing appears to be wrong with the blob URL itself. I can download incoming mail (e.g. sent from Gmail) just fine with aerc or any other client. Messages sent with a different client, like meli (JMAP) or neomutt (SMTP) work fine as well - can be downloaded from the sent folder and when received by another inbox.

This is probably not a bug in aerc, however, because outgoing emails are sent successfully and appear to be fine. I can read emails sent from aerc to my Gmail address, for example. Stalwart is sending JMAP which says a blob is available at a given URL, but that 404s; this probably shouldn't be happening even if the client is misbehaving.

Data from a trace level log:

aerc uploads an email:

2024-09-14T06:37:27Z TRACE HTTP request body (http.request-body) listenerId = "http", localPort = 8443, remoteIp = 127.0.0.1, remotePort = 42796, contents = "[OMITTED]", size = 411
2024-09-14T06:37:27Z TRACE Data store iteration operation (store.data-iterate) elapsed = 0ms
2024-09-14T06:37:27Z TRACE Write batch operation (store.data-write) elapsed = 0ms, total = 2
2024-09-14T06:37:27Z TRACE Blob write operation (store.blob-write) key = base64:[BASE64 HASH X], elapsed = 0ms, size = 375
2024-09-14T06:37:27Z TRACE Write batch operation (store.data-write) elapsed = 0ms, total = 1
2024-09-14T06:37:27Z TRACE HTTP response body (http.response-body) listenerId = "http", localPort = 8443, remoteIp = 127.0.0.1, remotePort = 42796, contents = "{"accountId":"x","blobId":"[BLOB ID A]","type":"application/json","size":411}", code = 200, size = 129

aerc requests sending the email, and then storing the email in inbox "e" while removing it from inbox "d" ("e" is "Sent Items")

{"using":["urn:ietf:params:jmap:mail","urn:ietf:params:jmap:submission"],"methodCalls":[["Email/import",{"accountId":"x","emails":{"aerc":{"blobId":"[BLOB ID A]","mailboxIds":{"d":true},"keywords":{"$draft":true,"$seen":true}}}},"0"],["EmailSubmission/set",{"accountId":"x","create":{"sub":{"identityId":"a","emailId":"#aerc","envelope":{"mailFrom":{"email":"myemail@mydomain.tld"},"rcptTo":[{"email":"postmaster@mydomain.tld"}]}}},"onSuccessUpdateEmail":{"#sub":{"keywords/$draft":null,"mailboxIds/d":null,"mailboxIds/e":true}}},"1"]]}

Stalwarts responds when the email is successfully sent:

{"methodResponses":[["Email/import",{"accountId":"x","oldState":"s2hqjj1oc7go02aq","newState":"s2lqjj0hwt1pn2aq","created":{"aerc":{"id":"lqaaaadv","threadId":"c2","blobId":"[OMITTED]","size":411}}},"0"],["EmailSubmission/set",{"accountId":"x","newState":"s2tqjj13wt1pn2aq","created":{"sub":{"id":"dd"}}},"1"],["Email/set",{"accountId":"x","oldState":"s2lqjj0hwt1pn2aq","newState":"s2xqjj3hwt1pn2aq","updated":{"lqaaaadv":null}},"1"]],"sessionState":"3e25b2a0"}

opening the sent box in aerc results in a request for the contents of that box:

{"using":["urn:ietf:params:jmap:mail"],"methodCalls":[["Email/query",{"accountId":"x","filter":{"inMailbox":"e"},"sort":[{"property":"receivedAt","isAscending":true}]},"0"]]}

Stalwart responds with a list of email IDs (omitted).

I open the sent email in aerc, triggering a request for that email:

{"using":["urn:ietf:params:jmap:mail"],"methodCalls":[["Email/get",{"accountId":"x","ids":["lqaaaadv"],"properties":["id","blobId","mailboxIds","keywords","size","receivedAt","headers","messageId","inReplyTo","references","from","to","cc","bcc","replyTo","subject","bodyStructure"]},"0"]]}

and a response from Stalwart:

{"methodResponses":[["Email/get",{"accountId":"x","state":"s2xqjj3hwt1pn2aq","list":[{"id":"lqaaaadv","blobId":"[OMITTED]","mailboxIds":{"e":true},"keywords":{"$seen":true},"size":411,"receivedAt":"2024-09-14T06:37:27Z","headers":[{"name":"MIME-Version","value":" 1.0"},{"name":"Content-Transfer-Encoding","value":" quoted-printable"},{"name":"Content-Type","value":" text/plain; charset=UTF-8"},{"name":"Date","value":" Sat, 14 Sep 2024 02:37:27 -0400"},{"name":"Message-ID","value":" <[MID]@mydomain.tld>"},{"name":"Subject","value":" test message, trace is on"},{"name":"From","value":" \\"Full Name\\" <myemail@mydomain.tld>"},{"name":"To","value":" <postmaster@mydomain.tld>"},{"name":"X-Mailer","value":" aerc 0.18.2-0-ge037c095a049"}],"messageId":["[MID]@mydomain.tld"],"inReplyTo":null,"references":null,"from":[{"name":"Full Name","email":"myemail@mydomain.tld"}],"to":[{"name":null,"email":"postmaster@mydomain.tld"}],"cc":null,"bcc":null,"replyTo":null,"subject":"test message, trace is on","bodyStructure":{"partId":"0","blobId":"[OMITTED]","size":61,"name":null,"type":"text/plain","charset":"UTF-8","disposition":null,"cid":null,"language":null,"location":null}}],"notFound":[]},"0"]],"sessionState":"3e25b2a0"}

aerc requests the bodyStructure blobId:

2024-09-14T06:38:27Z DEBUG HTTP request URL (http.request-url) listenerId = "http", localPort = 8443, remoteIp = 127.0.0.1, remotePort = 47860, remoteIp = [IP ADDRESS], url = "/jmap/download/x/[BLOB ID]/filename?accept=application/octet-stream"
2024-09-14T06:38:27Z TRACE Expression evaluation result (eval.result) listenerId = "http", localPort = 8443, remoteIp = 127.0.0.1, remotePort = 47860, id = "server.http.allowed-endpoint", result = "Integer(200)"
2024-09-14T06:38:27Z TRACE Write batch operation (store.data-write) elapsed = 0ms, total = 2
2024-09-14T06:38:27Z TRACE Blob read operation (store.blob-read) key = base64:[BASE64 HASH X], elapsed = 0ms, size = 375
2024-09-14T06:38:27Z DEBUG Resource not found (resource.not-found) listenerId = "http", localPort = 8443, remoteIp = 127.0.0.1, remotePort = 47860
2024-09-14T06:38:27Z TRACE HTTP response body (http.response-body) listenerId = "http", localPort = 8443, remoteIp = 127.0.0.1, remotePort = 47860, contents = "{"type":"about:blank","status":404,"title":"Not Found","detail":"The requested resource does not exist on this server."}", code = 404, size = 120

And it's not found.

Important note: if I request the blobId of the email manually, I get a blob with its contents. The problem is when I, or my client, requests the blobId of the bodyStructure. That 404s.

The two IDs are very similar; the email blobId is cb[LONG STRING]u, the bodyStructure blobId is cj[LONG STRING]xpaepi, where the string is identical between them. I don't know if that's significant in any way, I'm just including the fact in case it is.

[afontenot]

Digging further:

This applies to all clients and all emails, including incoming. I've narrowed the issue down to the following:

If an email is single-parted and uses the Content-Transfer-Encoding: quoted-printable, then attempting to download the blobId URL in the bodyStructure field will result in a 404 error in any JMAP client.

[afontenot]

I tracked down the source of this issue and have a PR for it here: #766

It also fixes another issue where the downloaded message also sometimes includes the message headers, confusing some clients.