Re: nnimap slowness

[Simon Josefsson <jas@extundo.com>]

David Abrahams <dave@boost-consulting.com> writes:

>> For small data, the cause is much more likely to be server slowness or
>> network latency, so please send try sending a 5MB attachment or
>> something.
>
> OK, here:

Function Name                       Call Count  Elapsed Time  Average Time
==================================  ==========  ============  ============
gnus-summary-reselect-current-group      1           8.132         8.132
gnus-summary-rescan-group                1           8.132         8.132
nnimap-request-group                     2           6.43          3.215
imap-send-command-wait                  14          6.339         0.4527857142
imap-wait-for-tag                       14          6.339         0.4527857142
nnimap-request-update-info-internal      2           6.2989999999  3.1494999999
imap-search                             11          5.927         0.5388181818
gnus-group-get-new-news-this-group       1           4.055         4.055
gnus-summary-read-group                  1           3.586         3.586
gnus-group-read-group                    1           3.586         3.586
gnus-summary-read-group-1                1           3.586         3.586
gnus-select-newsgroup                    1           3.526         3.526
gnus-activate-group                      1           3.465         3.465
gnus-request-group                       1           2.965         2.965
gnus-retrieve-headers                    2           0.58          0.29
...

It seems the IMAP SEARCH command is causing the delay (most of the
nnimap related delay is in imap-search), suggesting that the server
opens large messages when the SEARCH command is invoked.  This is
unnecessary, since Gnus only searches for flags (unseen, seen, ticked,
etc).  Perhaps you could forward this observation (after verifying it
in the source) to the IMAP server administrator/developers to have
them improve searches for flags.

> But I still think the fact that I get the "imap read: ..." dance
> counting up to 27K *twice* when I do `M-G' and receive no messages is
> highly suspicious.

I don't think so -- that is displayed when imap.el waits for feedback
from the server.  M-g causes many commands to be sent to the server,
several of which are SEARCH commands (see *imap-log*), so if more than
one command takes time, that message is displayed.

>> To find out what causes slowness for small data, you must tcpdump or
>> ethereal the stream to see which side is delaying the transfer, or if
>> it is the network that has high latency.  ELP data isn't that useful
>> in this case.
>
> I got myself a copy of Ethereal and captured packets from a `M-G', but
> I have no clue yet as to how to get any useful information from what
> I'm seeing...
>
> ...I hate to keep harping on this, but it really has the look/feel of
> some inefficiency in what GNUs is doing.
>
> Looking at the packets one more time it sure looks very much as though
> GNUs is receiving the same sequence of packets (about 27K worth) twice
> from the IMAP server, though it's pretty hard for me to tell
> anything, especially peering through SSL encoding.

Right, you need to get a protocol dump with timestamps of the IMAP
connection.

Gnus do send several SEARCH commands, and this is quite inefficient,
but I believe fixing this would require changing the Gnus backend
interface, and that means work.  Several servers implement flag
searching without opening all articles though, so many people don't
have this problem.