Hello,running mbsync 1.4.4-5 (as provided by Debian) I sometimes run into timeout issues. After some debugging I think I understood the issue. The relevant logging looks from mbsync -V -DDMns as follows (with line numbers, timestamp and some debugging added over 1.4.4, I hope it's self-explanatory):
1 10:07:09 O: event_wait:801
2 10:07:09 O: event_wait:814
3 10:07:09 O: event_wait:828: fd=4
4 10:07:09 O: socket_fd_cb:1083: conn="tunnel 'ssh -W slowmap:143
login.ptx'"
5 10:07:09 O: socket_fd_cb:1109: shift timeout for "tunnel 'ssh
-W slowmap:143 login.ptx'"
6 10:07:09 O: F: * FLAGS (\Answered \Flagged \Deleted \Seen
\Draft unknown-0)
7 10:07:09 O: F: * OK [PERMANENTFLAGS (\Answered \Flagged
\Deleted \Seen \Draft unknown-0 \*)] Flags permitted.
8 10:07:09 O: F: * 75642 EXISTS
9 10:07:09 O: F: * 0 RECENT
10 10:07:09 O: F: * OK [UNSEEN 2] First unseen.
11 10:07:09 O: F: * OK [UIDVALIDITY 1590482668] UIDs valid
12 10:07:09 O: F: * OK [UIDNEXT 75756] Predicted next UID
13 10:07:09 O: F: 7 OK [READ-WRITE] Select completed (1.202 +
0.000 + 1.201 secs).
14 10:07:09 O: socket_expect_activity:809: conn="tunnel 'ssh -W
slowmap:143 login.ptx'", expect=0
15 10:07:09 O: socket_expect_activity:811
16 10:07:09 O: F: [ 5] Callback enter open_box, sts=0,
uidvalidity=1590482668
17 10:07:09 O: F: Enter prepare_load_box, opts=0xc7
18 10:07:09 O: F: Leave prepare_load_box, ret=0xc7
19 10:07:09 O: N: Enter prepare_load_box, opts=0xc7
20 10:07:09 O: N: Leave prepare_load_box, ret=0xc7
21 10:07:09 O: Loading far side box...
22 10:07:09 O: F: [ 7] Enter load_box, [1,inf] (find >= 0, paired
<= 4294967295, new > 75726)
23 10:07:09 O: F: >>> 8 UID FETCH 1:75755 (UID FLAGS)^M
24 10:07:09 O: socket_expect_activity:809: conn="tunnel 'ssh -W
slowmap:143 login.ptx'", expect=1
25 10:07:09 O: socket_expect_activity:811
26 10:07:09 O: F: [ 7] Leave load_box
27 10:07:09 O: Loading near side box...
28 10:07:09 O: N: [ 8] Enter load_box, [1,inf] (find >= 0, paired
<= 4294967295, new > 75659)
29 10:07:09 O: N: [ 8] Callback enter load_box, sts=0,
total=75635, recent=0
30 10:07:09 O: uid=1 flags=S size=0 tuid=?
31 10:07:09 O: uid=2 flags= size=0 tuid=?
32 ...
33 10:09:02 O: uid=75658 flags= size=0 tuid=?
34 10:09:02 O: uid=75659 flags= size=0 tuid=?
35 10:09:02 O: near side: 75635 messages, 0 recent
36 10:09:02 O: matching messages on near side against sync records
37 10:09:02 O: N: [ 8] Callback leave load_box
38 10:09:02 O: N: [ 8] Leave load_box
39 10:09:02 O: F: [ 5] Callback leave open_box
40 10:09:02 O: event_wait:801
41 10:09:02 O: event_wait:801
42 10:09:02 O: event_wait:801
43 10:09:02 O: F: Callback enter bad store
44 10:09:02 O: F: Enter cancel_store
45 10:09:02 O: socket_expect_activity:809: conn="(null)", expect=0
My interpretation is that some reply is expected from the far side (line
24) so a timeout (default value 20s) is setup. Then mbsync proceeds to
load the local box. With the given debugging and mailbox size this takes
longer than 20s and then the timeout timer triggers before the
connection is checked for input the next time.
Does this sound about right?I'll increase the timeout (maybe to 0) locally, but a proper fix would be very welcome.
Best regards Uwe
OpenPGP_signature
Description: OpenPGP digital signature
_______________________________________________ isync-devel mailing list isync-devel@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/isync-devel
