Re: Slow nnimap expiry with expiry-target

[Simon Josefsson <jas@extundo.com>]

Bjørn Mork <bmork@dod.no> writes:

> I'm using total-expire to archive old messages from some of my nnimap
> folders, using another nnimap folder as expiry-target.  This is
> incredibly slow, often using several minutes to move just a few small
> messages from one folder to another on the same imap server.
>
> Turning on imap-log gave me an idea of why.  Expiring 19 messages
> resulted in a 5 MB imap-log!  Shouldn't this be just one search, one
> copy, one flag update and one expunge?  How come it adds up to a 5 MB
> log?

Ouch.

> Well, what Gnus does:
>
> Searching for messages to expire:
> 1397 UID SEARCH UID ... NOT SINCE 29-Aug-2003
>
> Processing first message:
> 1398 UID FETCH 33156 BODY.PEEK[]
> 1399 SELECT "INBOX.lest"
> 1400 UID SEARCH UNSEEN UNDELETED
> 1401 UID SEARCH SEEN
> 1402 UID SEARCH FLAGGED
> 1403 UID SEARCH ANSWERED
> 1404 UID SEARCH RECENT
> 1405 FETCH 1,* UID
> 1406 SELECT "INBOX"
> 1407 UID COPY 33156 "INBOX.lest"
> 1408 EXAMINE "INBOX.lest"
> 1409 UID FETCH * UID
> 1410 SELECT "INBOX"
> 1411 SELECT "INBOX.lest"
> 1412 UID SEARCH UNSEEN UNDELETED
> 1413 UID SEARCH SEEN
> 1414 UID SEARCH FLAGGED
> 1415 UID SEARCH ANSWERED
> 1416 UID SEARCH RECENT
> 1417 FETCH 1,* UID
> 1418 UID STORE 1:5175 +FLAGS (\Seen)
>
> Processing second message:
> 1419 SELECT "INBOX"
> 1420 UID FETCH 33158 BODY.PEEK[]
> 1421 SELECT "INBOX.lest"
> 1422 UID SEARCH UNSEEN UNDELETED
> 1423 UID SEARCH SEEN
> etc like above for all 19 messages.
>
> Deleting:
> 1815 SELECT "INBOX"
> 1816 UID STORE 33156,33158,33170,33173,33183,33188,33193,33198,33222,33237:33238,33244,33248,33367,33382,33385:33387,33399 +FLAGS (\Deleted)
> 1817 STATUS "INBOX" (unseen)
> 1818 EXPUNGE
>
>
> The problems I can spot are
>
> 1) fetching the messages from the server.  I can't see any reason for
>    this.  We have the list of UIDs to move.  We are using imap copy on
>    the server.  There is no need to download the messages.  This is
>    of course extra annoying when reading mail on a slow link and some
>    message with a large attachment suddenly is up for expiration...

I think the problem may be because the Gnus backend interface doesn't
include a 'move' command.  It only has retrieve + append.  Nnimap at
least optimize the append operation into copy, but it cannot optimize
away the retrieve.

> 2) repeatedly fetching all flags for all messages in the folder we are
>    moving to.  If there is any point in this at all, there certainly
>    can't be any point in repeating it 38 times to move 19 messages?
>    Some of the returned lists of UIDs are very long (#\Seen is
>    typically identical to #messages in the folder, #\Answered is also
>    often a long list).  Flags are cached by Gnus, are they not?

Yes.  Most likely the copying code is doing the equivalent of 'M-g' or
'RET' on a group.  I doubt this is needed, at least it is not needed
after each article.  But it is probably done at different API levels,
so may be tricky to optimize away without rewriting something.

> 3) "UID STORE ... +FLAGS (\Seen)" results in as many lines of response
>    from the imap server as there are messages in the folder.  And
>    it seems totally unecessary.  According to RFC 2060 flags SHOULD be
>    preserved in the copy.  And why repeat this for every moved message
>    even if it should prove necessary?

I think there are two problems here:

* Setting the article flags is done since Gnus doesn't have a 'move'
  command, only a retrieve + append.  So it doesn't know the COPY
  command preserved the flags.

* The 'UID STORE 1:5175 +FLAGS (\Seen)' command actually seems to be a
  bug, it should never send a command like that after copying one
  article.

> I am sure there are reasons I can't see for some or all of these, but
> there must be *something* that can be done to speed up nnimap expiry.

Fixing it would be nice.  Too bad I keep buying faster machines,
otherwise I probably would be inclined to work on it.