The definition of insanity...
Reported by Bill Cole | June 30th, 2016 @ 05:58 PM
MailMate Version 1.9.4 (5234) on Yosemite (talking to Dovecot
2.2.22 and CGP 6.1.6 and Office365, so it's not server-dependent)
occasionally gets stuck synching one mailbox per account, with an
activity spinner marking the place it's stuck. Usually I just quit
& restart but today I noticed that it was apparently working so
hard at whatever it was doing that it was messing up GUI updates.
So I looked into the Activity Monitor to see what was actually
happening and found a whole lot of this:
17:08:15 Handling reply
17:08:15 Running action
17:08:15 Sending request (12094)
17:08:15 Handling request
17:08:15 Ready to run action (retry count: 0)
17:08:15 C: H38856 NOOP
17:08:15 S: H38856 OK NOOP completed.
17:08:15 Storing flags
17:08:15 C: H38857 UID FETCH 6279 (FLAGS)
17:08:15 S: * 1644 FETCH (UID 6279 FLAGS (\Seen \Recent $Junk))
17:08:15 S: H38857 OK Fetch completed (0.001 + 0.000 secs).
17:08:15 Completed action (1007). Observed read/write timeouts: 8/8
17:08:15 Handling reply
17:08:15 Running action
17:08:15 Sending request (8622)
17:08:15 Handling request
17:08:15 Ready to run action (retry count: 0)
17:08:15 C: H38858 NOOP
17:08:15 S: H38858 OK NOOP completed.
17:08:15 Storing flags
17:08:15 C: H38859 UID FETCH 6279 (FLAGS)
17:08:15 S: * 1644 FETCH (UID 6279 FLAGS (\Seen \Recent $Junk))
17:08:15 S: H38859 OK Fetch completed (0.001 + 0.000 secs).
17:08:15 Completed action (1007). Observed read/write timeouts: 8/8
17:08:15 Handling reply
17:08:15 Running action
17:08:15 Sending request (12095)
17:08:15 Handling request
17:08:15 Ready to run action (retry count: 0)
17:08:15 C: H38860 NOOP
17:08:15 S: H38860 OK NOOP completed.
17:08:15 Storing flags
17:08:15 C: H38861 UID FETCH 6279 (FLAGS)
17:08:15 S: * 1644 FETCH (UID 6279 FLAGS (\Seen \Recent $Junk))
17:08:15 S: H38861 OK Fetch completed (0.001 + 0.000 secs).
17:08:15 Completed action (1007). Observed read/write timeouts: 8/8
MailMate was doing exactly the same thing ~500 times per second,
claiming to be storing flags when actually fetching them, with a
NOOP tossed in for no particular reason.
I expect this is not an intended behavior :)
Comments and changes to this ticket
-
benny July 1st, 2016 @ 09:30 AM
That's certainly not expected behavior. There's a known issue (possibly only with Gmail accounts) which I haven't been able to track down yet, but this looks different since no flags are stored at all.
Does it still happen after relaunching MailMate? If it does, could you try the latest test release of MailMate as well (hold down ⌥ when clicking “Check Now”).
I suspect that an issue like this is triggered by the state of a single message (UID 6279). Somehow MailMate thinks something needs to be updated, but it never realizes that this is incorrect. I wouldn't be surprised if this is related to the
\Recent
flag which MailMate has some issues with. -
Bill Cole August 8th, 2016 @ 10:20 PM
More data points:
Still happens with r5049 and r6044 on El Capitan.
Seems to only happen to mailboxes where rules are routinely applied automatically to many (in some cases all) new messages.
Could involve "\Recent" handling, as I have a smart mailbox that I thought would assure that nothing would keep the flag, but it seems not to work:{ countKey = "all"; filter = "(#flags ~ '\\Recent' and #date < 2 days ago)"; name = "Recent-NOT"; parentUUID = "MAILBOXES"; partitioningHeader = "#source.path"; rules = ( { actions = ( { disable = ( "\\Recent" ); type = "changeFlags"; }, ); description = "KillRecent"; filter = "from ~ '@'"; }, ); set = { operator = "Any"; subSets = ( "ALL_MESSAGES", "DRAFTS", "JUNK" ); }; showAccounts = :true; uuid = "5A001477-413E-41D2-B0F8-13B9D330937D"; }
-
Santosh Angadi October 20th, 2016 @ 06:54 PM
Sent a crash report for this persistent spinning and throttling
-
Bill Cole October 8th, 2017 @ 06:08 PM
I FINALLY was able to catch the start of this loop in an activity log. See attachment.
The summary of the action:
- There are 2 new messages in "AbuseMail" which have just been moved there by automation in another IMAP client from another (non-INBOX) mailbox in the same account. MailMate had not seen the messages in the original mailbox.
-
MM attempts to synchronize "AbuseMail" by opening a new connection and using these commands:
- SELECT AbuseMail
- NOOP (why?)
- UID FETCH 1:* (UID)
- UID FETCH 1391:* (INTERNALDATE) (1391 is the first new UID)
- UID FETCH 1:1390 (UID FLAGS) (CHANGEDSINCE 2414) (empty response)
- 2 second gap, blank line in log, switch from 'D' to 'G' command prefix
- NOOP (why?)
- UID FETCH 1391:1392 (UID BODY.PEEK[] RFC822.SIZE)
- UID FETCH 1391:1392 (FLAGS) (response shows both with only \Recent)
- no time gap, blank line in log, switch from 'G' to 'H' command prefix
- NOOP (why?)
- UID FETCH 1392 (FLAGS) (WHY? You JUST saw \Recent and since you're still in the same SELECT session, it still is \Recent)
- no time gap, blank line in log, still using 'H' command prefix
- Verbatim repeat of NOOP, UID FETCH 1392 (FLAGS), and blank line, up to 20 times per second.
-
The repeating NOOP & UID FETCH cycle only broke when I took the AbuseMail mailbox offline. Since \Recent is only valid for the life of a SELECT session in a mailbox, the offline/online cycle clears it.
Because this loop of commands executes so fast on both the server and client side, it is enough to make everything else MM does slow down, e.g. selecting a different mailbox in the UI results in a multi-second delay in the message list changing.
-
benny October 9th, 2017 @ 09:39 AM
- Tag cleared.
My guess is that this is a bug in MailMate where it continues to think that it hasn't completed some change to the flags of the message. Obviously the
\Recent
flag is somehow involved. The fact that it doesn't really try to set anything kind of confirms this since it is handled in a way which could trigger something like this -- but it should only happen once and not busy-loop.I tried to reproduce this, but it apparently requires some specific order of events. Do you have any rules setup which changes the flags of the incoming message? Or do you interact with the mailbox shortly after these messages are fetched?
(I've tried to set my local copy of MailMate to emulate that all messages report
\Recent
for myINBOX
messages, but so far it has not triggered any busy looping.)All the NOOPs and the explicit checking of FLAGS are workarounds for various buggy IMAP servers. Ideally, this shouldn't be done unless MailMate detects a problem, but this is something I shouldn't touch before making a complete rewrite of the IMAP code.
The prefixed letters change based on the type of action done (in this case, initial sync, fetching an email, and updating flags). Beyond that, the letters do not have any explicit meaning.
-
Bill Cole January 21st, 2018 @ 06:28 PM
I've managed to find a reproducible case of this problem that I've been able to reduce to a small low-noise set of logs. Unfortunately, I can't upload the logs because Lighthouse says:
Upload Quota Reached
Please notify the account owner.
I get the infinite loop on this one (read-only) mailbox on imap.ietf.org, an open-access public archive of IETF mailing lists. If I quit and restart MM, the looping resumes. This is the only case where i've seen that, and my theory is that it is due to the fact that MM can't actually update flags on the server side, while the server perversely keeps presenting the latest 2 messages as \Recent.
-
Bill Cole January 21st, 2018 @ 06:37 PM
Oops, I forgot to mention that the mailbox which persists in this behavior is imap://anonymous@imap.ietf.org/Shared Folders/rfc-dist
You can log in with your email address as the password.Interesting quirks:
1. The sequence numbers in the mailbox perfectly match the UIDs 2. MM seems to think it has no UID info for the 2 most recent messages
I've sent the log set to the mm-feedback address.
Please Sign in or create a free account to add a new ticket.
With your very own profile, you can contribute to projects, track your activity, watch tickets, receive and update tickets through your email and much more.
Create your profile
Help contribute to this project by taking a few moments to create your personal profile. Create your profile ยป
Mac OS X email client.
Attachments
Referenced by
- 1584 Activity Viewer Broken in 1.9.6 (r5307) The context of encountering this was a plague of looping ...