Freron MailMate

Comments and changes to this ticket

• 

  benny July 23rd, 2015 @ 03:25 PM

  Dovecot is a very robust server so this is good news. So far I don't
  have other reports about problems with Runbox. I'll do as you suggest
  next week (I'm on vacation this week). Sorry about the delay. Let me
  know if anything changes, e.g., if this is a Runbox problem.

  (Hint: If you want to look at log files yourself in the Activity Viewer. Duplicates would only be generated by MailMate if uploading an email to
  the server fails before MailMate realizes it actually succeeded, e.g.,
  if the connection breaks (this should rarely happen). It can also happen
  when moving messages, because this is essentially a copy+delete in
  IMAP.)

• You flagged this item as spam.
  

  Josh Dick July 23rd, 2015 @ 03:42 PM

  Benny,

  It looks like the timeout scenario is the one that is indeed causing this behavior, but I'm not sure why things are timing out in the first place. Large activity log below. :)

  No worries about the delay, enjoy your vacation!

  ---

  15:29:08 Response after idling (74/863): timeout (7)
  15:29:08 C: DONE
  15:29:08 S: S65 OK Idle completed.
  15:29:08 Completed IDLE (4). Reset observed read/write timeouts: 8/8

  15:29:10 Handling reply
  15:29:10 Running action
  15:29:10 Sending request (1099)
  15:29:10 Handling request
  15:29:10 Ready to run action
  15:29:10 C: S66 NOOP
  15:29:11 S: S66 OK NOOP completed.
  15:29:11 Running IDLE (keeping a live connection)
  15:29:11 C: S67 IDLE
  15:29:11 S: + idling
  15:29:12 Trying to terminate connection...
  15:29:12 S: <<< terminated reading >>>
  15:29:12 Response after idling (900/900): other (8)
  15:29:12 C: DONE
  15:29:12 S: S67 OK Idle completed.
  15:29:12 Completed IDLE (4). Reset observed read/write timeouts: 8/8

  15:29:12 Handling reply
  15:29:12 Running action
  15:29:12 Sending request (764)
  15:29:12 Handling request
  15:29:12 Ready to run action
  15:29:12 Copying 1 message(s)
  15:29:12 C: J68 NOOP
  15:29:12 S: J68 OK NOOP completed.
  15:29:12 C: J69 NOOP
  15:29:12 S: J69 OK NOOP completed.
  15:29:12 C: J70 UID COPY 446 Archive
  15:29:28 Error: Time limit (16s) reached while trying to read data (mail.runbox.com)
  15:29:28 S:
  15:29:28 Error code: 7
  15:29:28 New timeout values (8/8): 24/24
  15:29:28 Failed action (1009). Reset observed read/write timeouts: 12/12

  15:29:28 Handling reply
  15:29:28 Running action
  15:29:28 Sending request (1101)
  15:29:28 Handling request
  15:29:28 Trying to disconnect nicely (12)...
  15:29:28 C: J71 LOGOUT
  15:29:35 S: J70 OK [COPYUID 1436442874 446 13707] Copy completed.
  15:29:35 S: * BYE Logging out
  15:29:35 S: J71 OK Logout completed.
  15:29:35 Clearing connection to mail.runbox.com
  15:29:36 Ready to run action
  15:29:36 Copying 1 message(s)
  15:29:36 Clearing connection to mail.runbox.com
  15:29:36 Trying to connect to mail.runbox.com on port 143
  15:29:37 Successful connection on socket 32.
  15:29:38 S: * OK IMAP4 ready
  15:29:38 C: J0 CAPABILITY
  15:29:38 S: * CAPABILITY IMAP4rev1 UIDPLUS CHILDREN NAMESPACE THREAD=ORDEREDSUBJECT THREAD=REFERENCES SORT QUOTA IDLE STARTTLS LOGINDISABLED
  15:29:38 S: J0 OK completed
  15:29:38 C: J1 STARTTLS
  15:29:38 S: J1 OK completed
  15:29:38 Initiating secure connection...
  15:29:38 Setup of secure connection complete (TLSv1).
  15:29:38 Cipher: DHE-RSA-AES256-SHA SSLv3 Kx=DH Au=RSA Enc=AES(256) Mac=SHA1
  15:29:38 C: J2 CAPABILITY
  15:29:38 S: * CAPABILITY IMAP4rev1 UIDPLUS CHILDREN NAMESPACE THREAD=ORDEREDSUBJECT THREAD=REFERENCES SORT QUOTA IDLE AUTH=PLAIN
  15:29:38 S: J2 OK completed
  15:29:38 Retrieving password (keychain or user request)
  15:29:38 C: J3 AUTHENTICATE PLAIN
  15:29:38 S: +
  15:29:38 C: ••••••••••
  15:29:39 S: J3 OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS SPECIAL-USE BINARY MOVE] Logged in
  15:29:39 C: J4 CAPABILITY
  15:29:39 S: * CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS SPECIAL-USE BINARY MOVE
  15:29:39 S: J4 OK Capability completed.
  15:29:39 C: J5 ID ("name" "MailMate" "version" "r5084" "vendor" "Freron Software" "contact" "mm-imap-id@freron.com")
  15:29:39 S: * ID ("name" "Dovecot")
  15:29:39 S: J5 OK ID completed.
  15:29:39 Selecting mailbox: INBOX
  15:29:39 C: J6 SELECT INBOX (CONDSTORE)
  15:29:39 S: * FLAGS (\Answered \Flagged \Deleted \Seen \Draft)
  15:29:39 S: * OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft *)] Flags permitted.
  15:29:39 S: * 59 EXISTS
  15:29:39 S: * 0 RECENT
  15:29:39 S: * OK [UNSEEN 17] First unseen.
  15:29:39 S: * OK [UIDVALIDITY 1436442875] UIDs valid
  15:29:39 S: * OK [UIDNEXT 447] Predicted next UID
  15:29:39 S: * OK [HIGHESTMODSEQ 1384] Highest
  15:29:39 S: J6 OK [READ-WRITE] Select completed (0.077 secs).
  15:29:39 C: J7 NOOP
  15:29:39 S: J7 OK NOOP completed.
  15:29:39 Performing full synchronization.
  15:29:39 C: J8 UID FETCH 1:446 (UID)
  15:29:39 S: * 1 FETCH (UID 1)
  15:29:39 S: * 2 FETCH (UID 2)
  15:29:39 S: * 3 FETCH (UID 3)
  15:29:39 S: * 4 FETCH (UID 4)
  15:29:39 S: * 5 FETCH (UID 5)
  15:29:39 S: * 6 FETCH (UID 6)
  15:29:39 S: * 7 FETCH (UID 8)
  15:29:39 S: * 8 FETCH (UID 10)
  15:29:39 S: * 9 FETCH (UID 12)
  15:29:39 S: * 10 FETCH (UID 13)
  15:29:39 S: * 11 FETCH (UID 14)
  15:29:39 S: * 12 FETCH (UID 16)
  15:29:39 S: * 13 FETCH (UID 17)
  15:29:39 S: * 14 FETCH (UID 18)
  15:29:39 S: * 15 FETCH (UID 24)
  15:29:39 S: * 16 FETCH (UID 25)
  15:29:39 S: * 17 FETCH (UID 41)
  15:29:39 S: * 18 FETCH (UID 49)
  15:29:39 S: * 19 FETCH (UID 53)
  15:29:39 S: * 20 FETCH (UID 54)
  15:29:39 S: * 21 FETCH (UID 62)
  15:29:39 S: * 22 FETCH (UID 65)
  15:29:39 S: * 23 FETCH (UID 68)
  15:29:39 S: * 24 FETCH (UID 70)
  15:29:39 S: * 25 FETCH (UID 73)
  15:29:39 S: * 26 FETCH (UID 74)
  15:29:39 S: * 27 FETCH (UID 80)
  15:29:39 S: * 28 FETCH (UID 81)
  15:29:39 S: * 29 FETCH (UID 82)
  15:29:39 S: * 30 FETCH (UID 89)
  15:29:39 S: * 31 FETCH (UID 92)
  15:29:39 S: * 32 FETCH (UID 95)
  15:29:39 S: * 33 FETCH (UID 101)
  15:29:39 S: * 34 FETCH (UID 104)
  15:29:39 S: * 35 FETCH (UID 108)
  15:29:39 S: * 36 FETCH (UID 111)
  15:29:39 S: * 37 FETCH (UID 120)
  15:29:39 S: * 38 FETCH (UID 123)
  15:29:39 S: * 39 FETCH (UID 184)
  15:29:39 S: * 40 FETCH (UID 221)
  15:29:39 S: * 41 FETCH (UID 225)
  15:29:39 S: * 42 FETCH (UID 226)
  15:29:39 S: * 43 FETCH (UID 231)
  15:29:39 S: * 44 FETCH (UID 271)
  15:29:39 S: * 45 FETCH (UID 272)
  15:29:39 S: * 46 FETCH (UID 311)
  15:29:39 S: * 47 FETCH (UID 319)
  15:29:39 S: * 48 FETCH (UID 326)
  15:29:40 S: * 49 FETCH (UID 338)
  15:29:40 S: * 50 FETCH (UID 355)
  15:29:40 S: * 51 FETCH (UID 360)
  15:29:40 S: * 52 FETCH (UID 376)
  15:29:40 S: * 53 FETCH (UID 393)
  15:29:40 S: * 54 FETCH (UID 419)
  15:29:40 S: * 55 FETCH (UID 425)
  15:29:40 S: * 56 FETCH (UID 432)
  15:29:40 S: * 57 FETCH (UID 440)
  15:29:40 S: * 58 FETCH (UID 443)
  15:29:40 S: * 59 FETCH (UID 446)
  15:29:40 S: J8 OK Fetch completed.
  15:29:40 C: J9 UID FETCH 447:* (INTERNALDATE)
  15:29:40 S: * 59 FETCH (UID 446 INTERNALDATE "23-Jul-2015 17:26:28 +0200")
  15:29:40 S: J9 OK Fetch completed.
  15:29:40 C: J10 UID FETCH 1:446 (UID FLAGS) (CHANGEDSINCE 1382)
  15:29:40 S: * 59 FETCH (UID 446 FLAGS () MODSEQ (1384))
  15:29:40 S: J10 OK Fetch completed.
  15:29:40 C: J11 NOOP
  15:29:40 S: J11 OK NOOP completed.
  15:29:40 C: J12 UID COPY 446 Archive
  15:30:02 Waited 22 seconds on read.

  15:30:02 S: J12 OK [COPYUID 1436442874 446 13708] Copy completed.
  15:30:02 Completed action (1009). Observed read/write timeouts: 22/12

  15:30:02 Handling reply
  15:30:02 Running action
  15:30:02 Sending request (768)
  15:30:02 Handling request
  15:30:02 Ready to run action
  15:30:02 C: K13 NOOP
  15:30:03 S: K13 OK NOOP completed.
  15:30:03 Deleting messages
  15:30:03 C: K14 UID STORE 446 +FLAGS.SILENT (\Deleted)
  15:30:03 S: * 59 FETCH (UID 446 MODSEQ (1385))
  15:30:03 S: K14 OK Store completed.
  15:30:03 C: K15 UID EXPUNGE 446
  15:30:03 S: * 59 EXPUNGE
  15:30:03 S: K15 OK Expunge completed.
  15:30:03 Completed action (1010). Observed read/write timeouts: 16/9

  15:30:03 Handling reply
  15:30:03 Running action
  15:30:03 Sending request (1102)
  15:30:03 Handling request
  15:30:03 Ready to run action
  15:30:03 C: S16 NOOP
  15:30:03 S: S16 OK NOOP completed.
  15:30:03 Running IDLE (keeping a live connection)
  15:30:03 C: S17 IDLE
  15:30:03 S: + idling
  15:31:53 S: * OK Still here
  15:31:53 Response after idling (900/900): data (0)
  15:33:54 S: * OK Still here
  15:33:54 Response after idling (220/790): data (0)

• 

  benny July 23rd, 2015 @ 04:48 PM

  Yes, it's a timeout issue on the COPY command, but MailMate should be
  more patient in this case due to the consequence of giving up too early
  (duplicates). I'll look into that and similar cases.

• You flagged this item as spam.
  

  Josh Dick August 27th, 2015 @ 11:03 PM

  Hi Benny,

  I'm still seeing the same issues and am wondering if you had time to look at this?

  Thanks!

• 

  benny August 28th, 2015 @ 08:01 AM

  • State changed from “new” to “fixcommitted”

  No, but I did now. Try the latest test version: Hold down ⌥ when clicking “Check Now” in the Software Update preferences pane.

• You flagged this item as spam.
  

  Josh Dick August 28th, 2015 @ 07:09 PM

  Benny,

  So far, the increased timeouts in the latest build seem to have done the trick.

  Thanks very much!

• 

  benny September 29th, 2015 @ 02:52 PM

  • State changed from “fixcommitted” to “fixreleased”

  [bulk edit]

• You flagged this item as spam.
  

  Charles Parker October 15th, 2015 @ 06:40 PM

  I should say that I was having the same problem with the IMAP connector to an Exchange server and this fixed it! Thanks!