[Users] roughly 7-8 second delays for "Fetching message"

[George Avrunin]

I'm not at all sure this is a claws-mail problem, but I don't really know
how to interpret the logs and I'd like advice about how to settle that and
determine where the real issue is.  (General advice about solving the
problem is also welcome, of course, even if it isn't coming from
claws-mail!)

I use dovecot as the imap server on my office workstation, running Fedora
30.  When I read from home with claws (also on Fedora 30) and there are
several unread messages in a folder, every few messages (not the same
number each time), there will be a substantial delay.  (The same thing
happens, though I think with a shorter delay, on the office workstation
with claws connecting to localhost.) The delay is almost always about 7
seconds (counting one-one thousand, ..., so not a precise measurement).
While claws is saying "Fetching message", the message text window is blank
and I can't do anything else in claws. Claws-mail is 3.17.3, dovecot is
2.3.4. Authentication is "automatic", using SSL/TLS for receive, on port
993. This started a few months ago, I think, but I've finally gotten
annoyed enough (and had time) to ask for advice.

If I have the network log open, I do see gaps at about the same times, as,
e.g., the one from 12:19:04 to 12:19:12 below

[12:19:04] IMAP< * FLAGS (\Answered \Flagged \Deleted \Seen \Draft
$Forwarded NonJunk Junk) [12:19:04] IMAP< * OK [PERMANENTFLAGS (\Answered
\Flagged \Deleted \Seen \Draft $Forwarded NonJunk Junk \*)] Flags
permitted. [12:19:04] IMAP< * 12690 EXISTS [12:19:04] IMAP< * 0 RECENT 
[12:19:04] IMAP< * OK [UNSEEN 12673] First unseen. 
[12:19:04] IMAP< * OK [UIDVALIDITY 1159728275] UIDs valid 
[12:19:04] IMAP< * OK [UIDNEXT 423930] Predicted next UID 
[12:19:04] IMAP< * OK [HIGHESTMODSEQ 398701] Highest 
[12:19:04] IMAP< 25369 OK [READ-WRITE] Select completed (0.035 + 0.000 +
0.034 secs). [12:19:04] IMAP> 25370 UID FETCH 423924 BODY.PEEK[] 
[12:19:04] IMAP< [FETCH data - 4096 bytes]
[12:19:04] IMAP< [FETCH data - 1446 bytes]
[12:19:04] IMAP< [FETCH data - 4096 bytes]
[12:19:04] IMAP< [FETCH data - 1827 bytes]
[12:19:04] IMAP< [data - 51 bytes]
[12:19:12] IMAP> 25371 UID STORE 423924 +FLAGS.SILENT (\Seen) 
[12:19:12] IMAP< 25371 OK Store completed (0.111 + 0.000 + 0.110 secs). 

or from 12:30:07 to 12:30:15

[12:30:07] IMAP> 25865 UID FETCH 843 BODY.PEEK[] 
[12:30:07] IMAP< [FETCH data - 4096 bytes]
[12:30:07] IMAP< [FETCH data - 2353 bytes]
[12:30:07] IMAP< [FETCH data - 4039 bytes]
[12:30:07] IMAP< [data - 59 bytes]
[12:30:15] IMAP> 25866 UID STORE 843 +FLAGS.SILENT (\Seen) 
[12:30:15] IMAP< 25866 OK Store completed (0.003 + 0.000 + 0.002 secs). 
[12:30:33] IMAP> 25867 NOOP 
[12:30:33] IMAP< 25867 OK NOOP completed (0.008 + 0.000 + 0.007 secs). 

In between these times, the next message will open more or less
immediately.  The delays do seem to be correlated with the BODY.PEEK lines
in the network log.   But I don't know enough about the IMAP protocol or
exactly how claws uses it to interpret that.

But I can't tell where these delays are coming from.   I don't see
anything in the logs from dovecot indicating that it's doing anything
unusual at those times and searching for suggestions about dovecot delays
or latency hasn't turned up anything that seems to have any effect. The
delays don't coincide with checking for new mail. I'm not running any
filters on these folders and the filtering log is turned off.   The time
gaps are consistent enough that it seems that network latency is probably
not the issue.   

I would very much appreciate any suggestions about how to solve, or at
least reduce, this problem.  I'm happy to provide more details about my
configuration(s), if that would help.

   George

-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 228 bytes
Desc: OpenPGP digital signature
URL: <http://lists.claws-mail.org/pipermail/users/attachments/20190609/0863e07c/attachment.sig>