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)