~migadu/alps#150: 
IMAP Error after sending mail

Reproduction:

  • Compose and send new message

Expected behaviour:

  • Returned to inbox Actual behaviour:
  • Error 500 page.
  • Clicking 'try to return to inbox' also doesn't work.
  • Seems I have to restart ALPS before it works again.
2020-11-30T22:06:00Z ERROR failed to fetch message list: Error in IMAP command FETCH: Invalid messageset (0.001 + 0.000 secs).

I'll try to debug what command is actually failing

Status
REPORTED
Submitter
~mfashby
Assigned to
No-one
Submitted
2 years ago
Updated
1 year, 4 months ago
Labels
No labels applied.

~emersion 2 years ago

Can you run alps with -debug?

~mfashby 2 years ago

Sure! Here's the output

Testing!
--c45ca1d3d95e1241471edb400a1612a217e01e3784049836d59b3e795705--

5hYANQ OK [APPENDUID 1223931916 1094] Append completed (0.051 + 0.000 + 0.050 secs).
2020-11-30T22:24:48Z method=POST, uri=/compose, status=302
6otHUQ GETMETADATA "" ("/private/vendor/alps/base.settings")
* METADATA "" (/private/vendor/alps/base.settings NIL)
6otHUQ OK Getmetadata completed (0.001 + 0.000 secs).
wXr5rQ LIST "" "*"
* LIST (\NoInferiors \UnMarked) "/" Receipts
* LIST (\NoInferiors \UnMarked) "/" Archive
* LIST (\NoInferiors \UnMarked) "/" "Archive 20130323"
* LIST (\NoInferiors \UnMarked) "/" "Archive 20170919"
* LIST (\NoInferiors \UnMarked) "/" Keys
* LIST (\NoInferiors \UnMarked) "/" "Archive 20111203"
* LIST (\NoInferiors \Drafts) "/" Drafts
* LIST (\NoInferiors \UnMarked) "/" "Archive 20110915"
* LIST (\NoInferiors \UnMarked) "/" house
* LIST (\NoInferiors \UnMarked) "/" Archives
* LIST (\NoInferiors \UnMarked) "/" Bookings
* LIST (\NoInferiors \UnMarked) "/" "Archive 20140106"
* LIST (\NoInferiors \Junk) "/" Junk
* LIST (\NoInferiors \UnMarked) "/" "Archive 20110322"
* LIST (\NoInferiors \UnMarked) "/" Spam
* LIST (\NoInferiors \Marked \Sent) "/" Sent
* LIST (\NoInferiors \Trash) "/" Trash
* LIST (\Noselect \HasChildren) "/" Shared
* LIST (\HasNoChildren \UnMarked) "/" Shared/Genealogy
* LIST (\HasNoChildren) "/" Shared/Addresses
* LIST (\HasNoChildren) "/" INBOX
wXr5rQ OK List completed (0.001 + 0.000 secs).
Oln9BA STATUS INBOX (MESSAGES UIDVALIDITY UNSEEN)
* STATUS INBOX (MESSAGES 11 UIDVALIDITY 1223931848 UNSEEN 2)
Oln9BA OK [CLIENTBUG] Status on selected mailbox completed (0.001 + 0.000 secs).
-Gs3CA GETMETADATA "" ("/private/vendor/alps/base.settings")
* METADATA "" (/private/vendor/alps/base.settings NIL)
-Gs3CA OK Getmetadata completed (0.001 + 0.000 secs).
5u6iBA FETCH 1:11 (FLAGS ENVELOPE UID BODYSTRUCTURE)
5u6iBA BAD Error in IMAP command FETCH: Invalid messageset (0.001 + 0.000 secs).
2020-11-30T22:24:48Z ERROR failed to fetch message list: Error in IMAP command FETCH: Invalid messageset (0.001 + 0.000 secs).
2020-11-30T22:24:48Z method=GET, uri=/mailbox/INBOX, status=500

It seems like that last FETCH command is problematic, but I'm not sure why

5u6iBA FETCH 1:11 (FLAGS ENVELOPE UID BODYSTRUCTURE)

~mfashby 1 year, 4 months ago

There's some kind of internal state causing this. If I restart alps, the problem goes away (and I can see the sent message) I experimented a little, and found the following change to fix the bug, but I'm not totally sure why it works:

diff --git a/plugins/base/imap.go b/plugins/base/imap.go
index 64b3164..089a374 100644
--- a/plugins/base/imap.go
+++ b/plugins/base/imap.go
@@ -151,12 +151,12 @@ func getMailboxByType(conn *imapclient.Client, mboxType mailboxType) (*MailboxIn
 }

 func ensureMailboxSelected(conn *imapclient.Client, mboxName string) error {
-       mbox := conn.Mailbox()
-       if mbox == nil || mbox.Name != mboxName {
+       // mbox := conn.Mailbox()
+       //if mbox == nil || mbox.Name != mboxName {
                if _, err := conn.Select(mboxName, false); err != nil {
                        return fmt.Errorf("failed to select mailbox: %v", err)
                }
-       }
+       //}
        return nil
 }

~emersion 1 year, 4 months ago

Ah, hm, maybe conn.Mailbox() goes out-of-sync with the server's state for some reason?

~mfashby 1 year, 4 months ago

I still haven't quite figured this out. The error message is coming from the server, which means it thinks we're sending an invalid command, I think. The command looks fine to me though,

It's worth noting this is only happening for a server running dovecot. I'm using alps on two mail servers, one with dovecot version 1:2.3.4.1-5+deb10u6 and another running maddy version v0.4.4 and this error is only occurring on the former.

If it's not very harmful for performance, I might submit a patch with this workaround. The downside will be a few more SELECT commands issued.

Register here or Log in to comment, or comment via email.