duplicates with offlineimap+dovecot

duplicates with offlineimap+dovecot

[Julien Cubizolles]

I've the following setup:

Two different IMAP accounts (free.fr and gmail.com). Both are
synchronized with offlineimap and dovecot to local IMAP folders, both
accessed from Gnus with nnimap. This setup is used on 2 different
computers.

It's working fine except that I very often (almost at every
synchronization) I end up with duplicates of some messages on the local
IMAP folder, they are however not propagated to the distance IMAP
server.

It's not very inconvenient since gnus-suppress-duplicates takes care of
if but I'm confused:

+ It seems to only happen with the free.fr account, although I couldn't
  be sure since I don't have a lot of traffic on the gmail.com one
+ I never have the two computers running at the same time so there can't
  be 2 offlineimap running at the same time.

I have Gnus doing some splitting (including the detection of duplicates)
on the local IMAP folders and some spam autodetection. Since the
duplicates are not synced back to the remote server, could it be a
problem with Gnus accessing the same message a second time and thinking
it's a duplicate of the first one ? Have you ever experienced something
similar ?

Julien.

Re: duplicates with offlineimap+dovecot

[Malcolm Purvis]

>>>>> "Julien" == Julien Cubizolles <j.cubizolles@free.fr> writes:

Julien> I have Gnus doing some splitting (including the detection of
Julien> duplicates) on the local IMAP folders and some spam
Julien> autodetection. Since the duplicates are not synced back to the
Julien> remote server, could it be a problem with Gnus accessing the
Julien> same message a second time and thinking it's a duplicate of the
Julien> first one ?

I have been experiencing a related problem for some time a direct
connection to a dovecot IMAP server.  In my case Gnus performs the local
splitting but occasionally does not delete the message from the INBOX.
A second fetch splits the messages again (causing duplicates) and
generally deletes the messages from the INBOX.

This is with a month old copy of gnus from git.

Malcolm

-- 
		     Malcolm Purvis <malcolmp@xemacs.org>

Re: duplicates with offlineimap+dovecot

[Julien Cubizolles]

Malcolm Purvis <malcolmp@xemacs.org> writes:

>>>>>> "Julien" == Julien Cubizolles <j.cubizolles@free.fr> writes:
>
> Julien> I have Gnus doing some splitting (including the detection of
> Julien> duplicates) on the local IMAP folders and some spam
> Julien> autodetection. Since the duplicates are not synced back to the
> Julien> remote server, could it be a problem with Gnus accessing the
> Julien> same message a second time and thinking it's a duplicate of the
> Julien> first one ?
>
> I have been experiencing a related problem for some time a direct
> connection to a dovecot IMAP server.  In my case Gnus performs the local
> splitting but occasionally does not delete the message from the INBOX.
> A second fetch splits the messages again (causing duplicates) and
> generally deletes the messages from the INBOX.

That would explain what I'm experiencing. I'm not sure Dave's suggestion
of using mbsync instead of offlineimap would fix it but maybe the dbox
format for dovecot would do ? I'm not too eager to play with it though,
my current setup took me long enough to come up with.

> This is with a month old copy of gnus from git.

Mine might be older than that. I'll try upgrading and see if it
improves.

Thanks, I'm somewhat relieved to know I'm not alone with this problem.

Julien.

Re: duplicates with offlineimap+dovecot

[Emilio Jesús Gallego Arias]

[-- Attachment #1: Type: text/plain, Size: 1676 bytes --]

Hi all,

Malcolm Purvis <malcolmp@xemacs.org> writes:

>>>>>> "Julien" == Julien Cubizolles <j.cubizolles@free.fr> writes:
>
> Julien> I have Gnus doing some splitting (including the detection of
> Julien> duplicates) on the local IMAP folders and some spam
> Julien> autodetection. Since the duplicates are not synced back to the
> Julien> remote server, could it be a problem with Gnus accessing the
> Julien> same message a second time and thinking it's a duplicate of the
> Julien> first one ?
>
> I have been experiencing a related problem for some time a direct
> connection to a dovecot IMAP server.  In my case Gnus performs the local
> splitting but occasionally does not delete the message from the INBOX.
> A second fetch splits the messages again (causing duplicates) and
> generally deletes the messages from the INBOX.

I am seeing exactly the same issue in my setup, very often messages get
delivered to the proper group but a copy remains in the INBOX.

On a second press of 'g', the messages get correctly split, so I end
with a duplicate in the corresponding folder.

I'm using my own mailserver with dovecot, so there is no mbsync,
etc... involved.

I'd say this bug first appeared around 3 months ago, so a bisect should
be possible, ideas on what commit to try?

Dovecot doesn't complain of anything weird. A transcript with the
gnus-log showing the problem is attached, note the double move to
folder5.

More details:

Ma Gnus v0.16
GNU Emacs 25.1.50.2 (x86_64-pc-linux-gnu, GTK+ Version 3.16.7)
 of 2016-02-08

Thanks,
Emilio

p.s: Now that gnus is in emacs trunk bisecting seems a bit more
complicated.


[-- Attachment #2: gnus-log-imap-dup.txt --]
[-- Type: text/plain, Size: 3087 bytes --]

09:00:13 [host] 5455 LIST "" "*"
09:00:14 [host] 5456 SELECT "INBOX"
09:00:14 [host] 5457 UID FETCH 1:* FLAGS
09:00:14 [host] 5458 UID FETCH 10775:10795 (UID BODY.PEEK[HEADER])
09:00:14 [host] 5459 UID MOVE 10779 "folder1"
09:00:14 [host] 5460 UID MOVE 10780 "folder2"
09:00:14 [host] 5461 UID MOVE 10791 "folder3"
09:00:14 [host] 5462 UID MOVE 10775:10777,10781:10790,10792:10794 "folder5"
09:00:14 [host] 5463 UID MOVE 10795 "folder4"
[... lots of examine]
09:00:14 [host] 5483 EXAMINE "folder5" (QRESYNC (1410936766 273))
[... end  of examine]
09:00:31 [host] 5684 LIST "" "*"
09:00:31 [host] 5685 SELECT "INBOX"
09:00:32 [host] 5686 UID FETCH 1:* FLAGS
09:00:32 [host] 5687 UID FETCH 10775:10778,10781:10790 (UID BODY.PEEK[HEADER])
09:00:32 [host] 5688 UID MOVE 10775:10777,10781:10790 "folder5"
09:00:32 [host] 5708 EXAMINE "folder5" (QRESYNC (1410936766 276))
09:00:32 [host] 5709 EXAMINE "folder6" (QRESYNC (1417814776 85))
[...]
09:00:32 [host] 5776 EXAMINE "ircam/concat" (QRESYNC (1435708727 32))
09:00:48 [host] 5796 SELECT "INBOX"
09:00:48 [host] 5797 SELECT "INBOX"
09:00:48 [host] 5798 UID FETCH 2717,2903,5925,7532,7540,9061,9806,9812,9815,9821,9824,9835:9836,9876,9879,9882,9926:9927,9932,9993,10063,10107,10189:10190,10195,10203,10210,10274,10279,10368,10408,10464,10469,10490,10563,10574,10586,10604,10607,10612,10614:10615,10618,10639,10643,10649,10651,10656,10667:10669,10674,10778 (UID RFC822.SIZE BODYSTRUCTURE BODY.PEEK[HEADER.FIELDS (Subject From Date Message-Id References In-Reply-To Xref To Newsgroups Cc)])
09:00:48 [host] 5799 SELECT "INBOX"
09:00:48 [host] 5800 UID FETCH 10778 BODY.PEEK[]
09:01:06 [host] 5801 SELECT "INBOX"
09:01:06 [host] 5802 UID SEARCH SENTBEFORE 11-JAN-2016
09:01:06 [host] 5803 UID STORE 10512:10513,10515:10517,10519,10523,10532:10534 +FLAGS.SILENT (\Deleted)
09:01:06 [host] 5804 UID EXPUNGE 10512:10513,10515:10517,10519,10523,10532:10534
09:01:06 [host] 5805 SELECT "INBOX"
09:01:06 [host] 5806 UID STORE 10778 +FLAGS.SILENT (\Seen)
09:01:07 [host] 5807 SELECT "INBOX"
09:01:07 [host] 5808 UID STORE 10778 +FLAGS.SILENT (\Flagged)
09:02:09 [host] 5809 NOOP
09:02:09 [host] 5810 NOOP
09:02:09 [host] 5811 NOOP
09:02:09 [host] 5812 NOOP
09:02:09 [host] 5813 NOOP
09:02:09 [host] 5814 NOOP
09:02:09 [host] 5815 NOOP
09:02:09 [host] 5816 NOOP
09:02:09 [host] 5817 NOOP
09:06:21 [host] 5818 SELECT "folder5"
09:06:21 [host] 5819 SELECT "folder5"
09:06:21 [host] 5820 UID FETCH 440:468 (UID RFC822.SIZE BODYSTRUCTURE BODY.PEEK[HEADER.FIELDS (Subject From Date Message-Id References In-Reply-To Xref To Newsgroups Cc)])
09:06:21 [host] 5821 SELECT "folder5"
09:06:22 [host] 5822 UID FETCH 440 BODY.PEEK[]
09:06:29 [host] 5823 SELECT "folder5"
09:06:29 [host] 5824 UID FETCH 466 BODY.PEEK[]
09:06:39 [host] 5825 SELECT "folder5"
09:06:39 [host] 5826 UID SEARCH SENTBEFORE 11-JAN-2016
09:06:39 [host] 5827 SELECT "folder5"
09:06:39 [host] 5828 UID STORE 440:441,458:468 +FLAGS.SILENT (\Seen)
09:06:39 [host] 5829 SELECT "folder5"
09:06:39 [host] 5830 UID STORE 441,458,459,460,461,462,463,464,465,466,467,468 +FLAGS.SILENT (gnus-expire)

Re: duplicates with offlineimap+dovecot

[Lars Ingebrigtsen]

gallego@cri.ensmp.fr (Emilio Jesús Gallego Arias) writes:

> 09:00:13 [host] 5455 LIST "" "*"
> 09:00:14 [host] 5456 SELECT "INBOX"
> 09:00:14 [host] 5457 UID FETCH 1:* FLAGS
> 09:00:14 [host] 5458 UID FETCH 10775:10795 (UID BODY.PEEK[HEADER])
> 09:00:14 [host] 5459 UID MOVE 10779 "folder1"
> 09:00:14 [host] 5460 UID MOVE 10780 "folder2"
> 09:00:14 [host] 5461 UID MOVE 10791 "folder3"
> 09:00:14 [host] 5462 UID MOVE 10775:10777,10781:10790,10792:10794 "folder5"
> 09:00:14 [host] 5463 UID MOVE 10795 "folder4"

So that's the splitting.  It's all MOVE, so those articles should no
longer be in INBOX...

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: duplicates with offlineimap+dovecot

[Emilio Jesús Gallego Arias]

Hi Lars,

Lars Ingebrigtsen <larsi@gnus.org> writes:

> gallego@cri.ensmp.fr (Emilio Jesús Gallego Arias) writes:
>
>> 09:00:13 [host] 5455 LIST "" "*"
>> 09:00:14 [host] 5456 SELECT "INBOX"
>> 09:00:14 [host] 5457 UID FETCH 1:* FLAGS
>> 09:00:14 [host] 5458 UID FETCH 10775:10795 (UID BODY.PEEK[HEADER])
>> 09:00:14 [host] 5459 UID MOVE 10779 "folder1"
>> 09:00:14 [host] 5460 UID MOVE 10780 "folder2"
>> 09:00:14 [host] 5461 UID MOVE 10791 "folder3"
>> 09:00:14 [host] 5462 UID MOVE 10775:10777,10781:10790,10792:10794 "folder5"
>> 09:00:14 [host] 5463 UID MOVE 10795 "folder4"
>
> So that's the splitting.  It's all MOVE, so those articles should no
> longer be in INBOX...

Indeed, that's weird, maybe the server is returning some kind of weird status?

Isn't there a way to debug even more/IMAP return status? I've tried to
gather the contents of the *nnimap host *nntpd** buffer but without success.

Thanks a lot for the help,
Emilio

p.d: I couldn't get dovecot to log in verbose mode either, investigating
this.

Re: duplicates with offlineimap+dovecot

[Lars Ingebrigtsen]

gallego@cri.ensmp.fr (Emilio Jesús Gallego Arias) writes:

> Isn't there a way to debug even more/IMAP return status? I've tried to
> gather the contents of the *nnimap host *nntpd** buffer but without success.

No, I don't think there's a way to get the IMAP results logged.  I think
perhaps the easiest thing would be to put a (debug) in the source code
right after it's issued those MOVE commands, and then have a peek in the
*nnimap ...* buffer.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: duplicates with offlineimap+dovecot

[Emilio Jesús Gallego Arias]

Hi Lars,

Lars Ingebrigtsen <larsi@gnus.org> writes:

> gallego@cri.ensmp.fr (Emilio Jesús Gallego Arias) writes:
>
>> Isn't there a way to debug even more/IMAP return status? I've tried to
>> gather the contents of the *nnimap host *nntpd** buffer but without success.
>
> No, I don't think there's a way to get the IMAP results logged.  I think
> perhaps the easiest thing would be to put a (debug) in the source code
> right after it's issued those MOVE commands, and then have a peek in the
> *nnimap ...* buffer.

The idea worked, thanks!
(I replaced "(debug)" with my own logging of the nnimap buffer)

And this is what I got:
[note the duplicated move to folder1]

21:02:58 [domain] 9014 LIST "" "*"
21:02:58 [domain] 9015 SELECT "INBOX"
21:02:58 [domain] 9016 UID FETCH 1:* FLAGS
21:02:58 [domain] 9017 UID FETCH 4062:4072 (UID BODY.PEEK[HEADER])
21:02:59 [domain] 9018 UID MOVE 4065 "unrelated1"
21:02:59 [domain] 9019 UID MOVE 4062,4066,4068 "unrelated2"
21:02:59 [domain] 9020 UID MOVE 4063:4064,4067,4069:4072 "folder1"
21:03:00 [domain] 9021 EXAMINE "unrelated1" (QRESYNC (1424475224 33))
[...] lots of stuff
21:03:07 [domain] 9248 SELECT "INBOX"
21:03:07 [domain] 9249 SELECT "INBOX"
21:03:07 [domain] 9250 UID FETCH 704,2408,2425,2447:2448,2510,2537,2571,2667,2675,3715,3777,3806,3865,3871,3989,4003,4063:4064,4067 (UID RFC822.SIZE BODYSTRUCTURE BODY.PEEK[HEADER.FIELDS (Subject From Date Message-Id References In-Reply-To Xref To Newsgroups Cc)])
21:03:08 [domain] 9251 SELECT "INBOX"
21:03:08 [domain] 9252 UID FETCH 4063 BODY.PEEK[]
21:03:12 [domain] 9253 SELECT "INBOX"
21:03:12 [domain] 9254 UID SEARCH SENTBEFORE 03-FEB-2016

--- *nnimap domain buf **
* OK [COPYUID 1424475206 4065 96] Moved UIDs.
* VANISHED 4065
* 10 RECENT
9018 OK [HIGHESTMODSEQ 5192] Move completed.
* OK [COPYUID 1424475218 4062,4066,4068 376:378] Moved UIDs.
* OK [COPYUID 1424475231 4063:4064,4067,4069:4072 26:32] Moved UIDs.
* VANISHED 4062,4066,4068:4072
* 3 RECENT
9019 OK Move completed.
9020 OK [HIGHESTMODSEQ 5193] Move completed.

--- Second press of g
21:07:20 [domain] 9303 LIST "" "*"
21:07:20 [domain] 9304 SELECT "INBOX"
21:07:20 [domain] 9305 UID FETCH 1:* FLAGS
21:07:20 [domain] 9306 UID FETCH 4063:4064,4067 (UID BODY.PEEK[HEADER])
21:07:20 [domain] 9307 UID MOVE 4063:4064,4067 "folder1"

--- *nnimap domain buf **
* OK [COPYUID 1424475231 4063:4064,4067 33:35] Moved UIDs.
* VANISHED 4063:4064,4067
9307 OK [HIGHESTMODSEQ 5194] Move completed.

I'm really puzzled by this log, dunno how to interpret it.

Best regards,
Emilio

Re: duplicates with offlineimap+dovecot

[Emilio Jesús Gallego Arias]

gallego@cri.ensmp.fr (Emilio Jesús Gallego Arias) writes:

> --- *nnimap domain buf **
> * OK [COPYUID 1424475206 4065 96] Moved UIDs.
> * VANISHED 4065
> * 10 RECENT
> 9018 OK [HIGHESTMODSEQ 5192] Move completed.
> * OK [COPYUID 1424475218 4062,4066,4068 376:378] Moved UIDs.
> * OK [COPYUID 1424475231 4063:4064,4067,4069:4072 26:32] Moved UIDs.
> * VANISHED 4062,4066,4068:4072
> * 3 RECENT
> 9019 OK Move completed.
> 9020 OK [HIGHESTMODSEQ 5193] Move completed.
>
> I'm really puzzled by this log, dunno how to interpret it.

Yeah so the only idea that came to my mind is if the pipelining of UID
MOVEs could be causing some problem...

E.

Re: duplicates with offlineimap+dovecot

[Lars Ingebrigtsen]

gallego@cri.ensmp.fr (Emilio Jes?FFFAs Gallego Arias) writes:

> gallego@cri.ensmp.fr (Emilio Jes?FFFAs Gallego Arias) writes:
>
>> --- *nnimap domain buf **
>> * OK [COPYUID 1424475206 4065 96] Moved UIDs.
>> * VANISHED 4065
>> * 10 RECENT
>> 9018 OK [HIGHESTMODSEQ 5192] Move completed.
>> * OK [COPYUID 1424475218 4062,4066,4068 376:378] Moved UIDs.
>> * OK [COPYUID 1424475231 4063:4064,4067,4069:4072 26:32] Moved UIDs.
>> * VANISHED 4062,4066,4068:4072
>> * 3 RECENT
>> 9019 OK Move completed.
>> 9020 OK [HIGHESTMODSEQ 5193] Move completed.
>>
>> I'm really puzzled by this log, dunno how to interpret it.

I think that it says "I did everything you asked".  So if these messages
remain in the original folder after the server says "Move completed",
then there's something wrong with that server...

> Yeah so the only idea that came to my mind is if the pipelining of UID
> MOVEs could be causing some problem...

Pipelining is something that all IMAP servers should handle without too
much problem.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: duplicates with offlineimap+dovecot

[Emilio Jesús Gallego Arias]

Lars Ingebrigtsen <larsi@gnus.org> writes:

>> Yeah so the only idea that came to my mind is if the pipelining of UID
>> MOVEs could be causing some problem...
>
> Pipelining is something that all IMAP servers should handle without too
> much problem.

After some more research and RFC there seems to be a catch with this,
when pipelining and using QRESYNC, mailboxes may get "conceptually out
of sync", so some operations may need to be reissued again.

Indeed, this problem of duplicates is more common when more moves are issued.

>>> * OK [COPYUID 1424475206 4065 96] Moved UIDs.
[...]
>>> I'm really puzzled by this log, dunno how to interpret it.
>
> I think that it says "I did everything you asked".  So if these messages
> remain in the original folder after the server says "Move completed",
> then there's something wrong with that server...

I'm not sure that is the right interpretation of the log (but my
knowlegde of IMAP is very limited), let me restructure the log to remove
useless stuff:

> *first press of g*
> 21:02:59 [domain] 9020 UID MOVE 4063:4064,4067,4069:4072 "folder1"
> * OK [COPYUID 1424475231 4063:4064,4067,4069:4072 26:32] Moved UIDs.
> * VANISHED 4062,4066,4068:4072
> * 3 RECENT
> 9020 OK [HIGHESTMODSEQ 5193] Move completed.

I interpret this as "only 4062,4066,4068:4072" got moved.

Indeed, then later:

> --- Second press of g
> 21:07:20 [domain] 9307 UID MOVE 4063:4064,4067 "folder1"
> * OK [COPYUID 1424475231 4063:4064,4067 33:35] Moved UIDs.
> * VANISHED 4063:4064,4067
> 9307 OK [HIGHESTMODSEQ 5194] Move completed.

Precisely the messages that were missing from the previous VANISHED.

If my interpretation of the RFC is correct, indeed this is a bug in
gnus, as it should parse VANISHED output to confirm the moves.

Thanks a lot for the help, best regards,
Emilio

Re: duplicates with offlineimap+dovecot

[Lars Ingebrigtsen]

gallego@cri.ensmp.fr (Emilio Jes?FFFAs Gallego Arias) writes:

>> *first press of g*
>> 21:02:59 [domain] 9020 UID MOVE 4063:4064,4067,4069:4072 "folder1"
>> * OK [COPYUID 1424475231 4063:4064,4067,4069:4072 26:32] Moved UIDs.
>> * VANISHED 4062,4066,4068:4072
>> * 3 RECENT
>> 9020 OK [HIGHESTMODSEQ 5193] Move completed.
>
> I interpret this as "only 4062,4066,4068:4072" got moved.

I can't find anything in the IMAP MOVE standard that says something like
that.  And it only talks about having to be careful about streaming
other commands after MOVE as a MOVE may lead to articles being
renumbered.  And the VANISHED stuff is from unrelated QRESYNC support,
if I'm reading the QRESYNC RFC correctly.

And, as you see from the VANISHED above there, most of the stuff it says
is vanished is stoff that we're not even trying to move (4062, 4066).

So I don't know what's going on on the server...

 An example:

       C: a UID MOVE 42:69 foo
       S: * OK [COPYUID 432432 42:69 1202:1229]
       S: * 22 EXPUNGE
       S: (more expunges)
       S: a OK Done

   Note that the server may send unrelated EXPUNGE responses as well, if
   any happen to have been expunged at the same time; this is normal
   IMAP operation.

   Implementers will need to read [RFC4315] to understand what UID
   EXPUNGE does, though full implementation of [RFC4315] is not
   necessary.

   Note that moving a message to the currently selected mailbox (that
   is, where the source and target mailboxes are the same) is allowed
   when copying the message to the currently selected mailbox is
   allowed.

   The server may send EXPUNGE (or VANISHED) responses before the tagged
   response, so the client cannot safely send more commands with message
   sequence number arguments while the server is processing MOVE or UID
   MOVE.

   Both MOVE and UID MOVE can be pipelined with other commands, but care
   has to be taken.  Both commands modify sequence numbers and also
   allow unrelated EXPUNGE responses.  The renumbering of other messages
   in the source mailbox following any EXPUNGE response can be
   surprising and makes it unsafe to pipeline any command that relies on
   message sequence numbers after a MOVE or UID MOVE.  Similarly, MOVE
   cannot be pipelined with a command that might cause message
   renumbering.  See [RFC3501], Section 5.5, for more information about
   ambiguities as well as handling requirements for both clients and
   servers.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: duplicates with offlineimap+dovecot

[Emilio Jesús Gallego Arias]

Hi Lars,

Lars Ingebrigtsen <larsi@gnus.org> writes:

> gallego@cri.ensmp.fr (Emilio Jes?FFFAs Gallego Arias) writes:
>
>>> *first press of g*
>>> 21:02:59 [domain] 9020 UID MOVE 4063:4064,4067,4069:4072 "folder1"
>>> * OK [COPYUID 1424475231 4063:4064,4067,4069:4072 26:32] Moved UIDs.
>>> * VANISHED 4062,4066,4068:4072
>>> * 3 RECENT
>>> 9020 OK [HIGHESTMODSEQ 5193] Move completed.
>>
>> I interpret this as "only 4062,4066,4068:4072" got moved.
>
> I can't find anything in the IMAP MOVE standard that says something like
> that.  And it only talks about having to be careful about streaming
> other commands after MOVE as a MOVE may lead to articles being
> renumbered.  And the VANISHED stuff is from unrelated QRESYNC support,
> if I'm reading the QRESYNC RFC correctly.

Note that gnus is currently streaming MOVE commands, however I'm not
sure the RFC means to allow this.

> And, as you see from the VANISHED above there, most of the stuff it says
> is vanished is stuff that we're not even trying to move (4062, 4066).

I'm sorry, I trimmed too much of the log, if you look at my previous
mail you'll see:

> 9019 UID MOVE 4062,4066,4068 "unrelated2"
> 9020 UID MOVE 4063:4064,4067,4069:4072 "folder1"
> * OK [COPYUID 1424475218 4062,4066,4068 376:378] Moved UIDs.
> * OK [COPYUID 1424475231 4063:4064,4067,4069:4072 26:32] Moved UIDs.
> * VANISHED 4062,4066,4068:4072

Thus yeah, we ordered the move of 4062, etc... and the server:

 a) confirms the move for all the messages.
 b) doesn't confirm the expunge from INBOX for all of them!

Thus, it is clear that 4063 was moved but not expunged from the mailbox;
hence the duplicated msg...

> So I don't know what's going on on the server...

I have no clue either but the server is a 100% vanilla Debian Dovecot. I
have this problem with several other servers not administered by me so
if there's a server problem here is not only on my server.

After some more experiments, I believe the bug can be reproduced as
follows: install a Debian stable with Dovecot, then have Gnus to issue
multiple (pipelined) MOVE commands with QRESYNC enabled.

I'd be happy to get in touch with dovecot upstream if we deem it OK.

Regarding the log, note that the RFC says:

   Because a MOVE applies to a set of messages, it might fail partway
   through the set.  Regardless of whether the command is successful in
   moving the entire set, each individual message SHOULD either be moved
   or unaffected.  The server MUST leave each message in a state where
                              ^^^^
   it is in at least one of the source or target mailboxes (no message
   can be lost or orphaned).  The server SHOULD NOT leave any message in
                                         ^^^^^^^^^^
   both mailboxes (it would be bad for a partial failure to result in a
   bunch of duplicate messages).  This is true even if the server
   returns a tagged NO response to the command.

So Dovecot here appears to be violating the "SHOULD NOT"; it effectively
leaves the message in the two mailboxes (even if it notifies us that it
was not VANISHED from INBOX). However:

> RFC6851:

> The server may send EXPUNGE (or VANISHED) responses before the tagged
> response, so the client cannot safely send more commands with message
> sequence number arguments while the server is processing MOVE or UID
> MOVE.

Doesn't that mean that gnus should not stream the two MOVES?

Thanks again for the help!
Regards,
E.

Re: duplicates with offlineimap+dovecot

[Lars Ingebrigtsen]

gallego@cri.ensmp.fr (Emilio Jes?FFFAs Gallego Arias) writes:

>> The server may send EXPUNGE (or VANISHED) responses before the tagged
>> response, so the client cannot safely send more commands with message
>> sequence number arguments while the server is processing MOVE or UID
>> MOVE.
>
> Doesn't that mean that gnus should not stream the two MOVES?

I interpret that to mean that the client shouldn't send other non-MOVE
commands that depend on those MOVEs having been done (when streaming).

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: duplicates with offlineimap+dovecot

[Emilio Jesús Gallego Arias]

Lars Ingebrigtsen <larsi@gnus.org> writes:

> gallego@cri.ensmp.fr (Emilio Jes?FFFAs Gallego Arias) writes:
>
>>> The server may send EXPUNGE (or VANISHED) responses before the tagged
>>> response, so the client cannot safely send more commands with message
>>> sequence number arguments while the server is processing MOVE or UID
>>> MOVE.
>>
>> Doesn't that mean that gnus should not stream the two MOVES?
>
> I interpret that to mean that the client shouldn't send other non-MOVE
> commands that depend on those MOVEs having been done (when streaming).

But isn't a MOVE "a command with message sequence number arguments" ?

Thanks for the help!
E.

Re: duplicates with offlineimap+dovecot

[Lars Ingebrigtsen]

gallego@cri.ensmp.fr (Emilio Jes?FFFAs Gallego Arias) writes:

> Lars Ingebrigtsen <larsi@gnus.org> writes:
>
>> gallego@cri.ensmp.fr (Emilio Jes?FFFAs Gallego Arias) writes:
>>
>>>> The server may send EXPUNGE (or VANISHED) responses before the tagged
>>>> response, so the client cannot safely send more commands with message
>>>> sequence number arguments while the server is processing MOVE or UID
>>>> MOVE.
>>>
>>> Doesn't that mean that gnus should not stream the two MOVES?
>>
>> I interpret that to mean that the client shouldn't send other non-MOVE
>> commands that depend on those MOVEs having been done (when streaming).
>
> But isn't a MOVE "a command with message sequence number arguments" ?

That's a possible interpretation, but then the MOVE RFC should just have
said "MOVEs can't be streamed".  I can't see that it does that.  And the
VANISH stuff comes from the QRESYNC support, which is a separate
feature.  If MOVE fails, it should have said so, and it doesn't:

21:02:59 [domain] 9019 UID MOVE 4062,4066,4068 "unrelated2"
21:02:59 [domain] 9020 UID MOVE 4063:4064,4067,4069:4072 "folder1"

[...]

9019 OK Move completed.
9020 OK [HIGHESTMODSEQ 5193] Move completed.

Both commands completed with OK.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: duplicates with offlineimap+dovecot

[Emilio Jesús Gallego Arias]

Lars Ingebrigtsen <larsi@gnus.org> writes:

> That's a possible interpretation, but then the MOVE RFC should just have
> said "MOVEs can't be streamed".  I can't see that it does that.

The RFC states that MOVE is exactly equivalent to COPY + STORE +
EXPUNGE, and defer streaming to ambiguity rules.

IMO it is not very clear what should this mean, I've asked on dovecot
and imap mailing lists.

After a quick look to Dovecot's source code, I think I got a small
intuition on what is going on.

Dovecot will only check the success of the move to issue the "OK Move
completed" response. There is no check for expunge failing.

[see cmd-copy.c: + mail-storage.c:mailbox_move()]

> And the VANISH stuff comes from the QRESYNC support, which is a
> separate feature.  If MOVE fails, it should have said so, and it
> doesn't:
>
> 21:02:59 [domain] 9019 UID MOVE 4062,4066,4068 "unrelated2"
> 21:02:59 [domain] 9020 UID MOVE 4063:4064,4067,4069:4072 "folder1"
>
> [...]
>
> 9019 OK Move completed.
> 9020 OK [HIGHESTMODSEQ 5193] Move completed.
>
> Both commands completed with OK.

Yeah this means that the copy part of the move didn't fail, but not all
messages (form the second copy) where expunged from the INBOX.

Thanks for the help,
E.

Re: duplicates with offlineimap+dovecot

[Lars Ingebrigtsen]

gallego@cri.ensmp.fr (Emilio Jesús Gallego Arias) writes:

> The RFC states that MOVE is exactly equivalent to COPY + STORE +
> EXPUNGE, and defer streaming to ambiguity rules.
>
> IMO it is not very clear what should this mean, I've asked on dovecot
> and imap mailing lists.

If you can't stream the MOVEs, then surely streaming COPY/EXPUNGE will
be faster, and we can just remove the support for MOVE.  But I suspect
that this is probably a bug in Dovecot.  We could add a quirk to disable
MOVE on Dovecot...

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: duplicates with offlineimap+dovecot

[Steinar Bang]

>>>>> Lars Ingebrigtsen <larsi@gnus.org>:

> If you can't stream the MOVEs, then surely streaming COPY/EXPUNGE will
> be faster, and we can just remove the support for MOVE.  But I suspect
> that this is probably a bug in Dovecot.  We could add a quirk to disable
> MOVE on Dovecot...

Dovecot is the IMAP server that sees the most action, both in use and
development.

So you probably shouldn't disable something on Dovecot, until you find
out which version(s) of Dovecot has the problem.  If recent versions
have the problem, a Dovcot bug should be reported (ideally by the people
seeing the problem).

If old versions of Dovecot has the problem, people should be told to
upgrade, rather than crippling the Gnus/Dovecot interaction.

(I use Gnus with Dovecot, so Gnus/Dovecot interaction is important to
me. I use the Dovecot on debian "jessie", which currently is Dovecot
2.2.13)

Re: duplicates with offlineimap+dovecot

[Lars Ingebrigtsen]

Steinar Bang <sb@dod.no> writes:

> So you probably shouldn't disable something on Dovecot, until you find
> out which version(s) of Dovecot has the problem.  If recent versions
> have the problem, a Dovcot bug should be reported (ideally by the people
> seeing the problem).
>
> If old versions of Dovecot has the problem, people should be told to
> upgrade, rather than crippling the Gnus/Dovecot interaction.

True.  The Dovecot server I'm talking to (I think it's from Debian
Stale) doesn't seem to support MOVE at all...

I guess we'll have to wait and see what the Dovecot developers say...

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: duplicates with offlineimap+dovecot

[Steinar Bang]

>>>>> Lars Ingebrigtsen <larsi@gnus.org>:

> True.  The Dovecot server I'm talking to (I think it's from Debian
> Stale) doesn't seem to support MOVE at all...

Debian stable, "jessie", has version 2.2.13
 https://packages.debian.org/jessie/dovecot-imapd

Testing and unstable both have 2.2.18
 https://packages.debian.org/stretch/dovecot-imapd
 https://packages.debian.org/sid/dovecot-imapd

The latest release of dovecot is 2.2.21: http://www.dovecot.org/

(The page http://www.dovecot.org/download.html lists debian stable
backports as a source for a 2.2.21 package, but jessie-backports is
covered by the packages.debian.org, and that page didn't show up any
newer matches for jessie than the 2.2.13 I already have)

Hm... looks like there is an autobuild for jessie here:
 http://wiki2.dovecot.org/PrebuiltBinaries#Automatically_Built_Packages
but personally I'm fine with whatever's on stable...

Re: duplicates with offlineimap+dovecot

[Emilio Jesús Gallego Arias]

Lars Ingebrigtsen <larsi@gnus.org> writes:

> True.  The Dovecot server I'm talking to (I think it's from Debian
> Stale) doesn't seem to support MOVE at all...
>
> I guess we'll have to wait and see what the Dovecot developers say...

Update: this has been fixed upstream:

http://www.dovecot.org/list/dovecot/2016-February/103205.html

E.

Re: duplicates with offlineimap+dovecot

[Lars Ingebrigtsen]

gallego@cri.ensmp.fr (Emilio Jesús Gallego Arias) writes:

> Update: this has been fixed upstream:
>
> http://www.dovecot.org/list/dovecot/2016-February/103205.html

Perhaps we should add a quirk to nnimap to disable MOVE for the Dovecot
versions affected?  What versions are those?

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: duplicates with offlineimap+dovecot

[Emilio Jesús Gallego Arias]

Lars Ingebrigtsen <larsi@gnus.org> writes:

> gallego@cri.ensmp.fr (Emilio Jesús Gallego Arias) writes:
>
>> Update: this has been fixed upstream:
>>
>> http://www.dovecot.org/list/dovecot/2016-February/103205.html
>
> Perhaps we should add a quirk to nnimap to disable MOVE for the Dovecot
> versions affected?  What versions are those?

I dunno when the bug was introduced, but it didn't hurt too many people
it seems.

Maybe adding an entry to the FAQ/QUIRKS file instructing to remove
"MOVE" from nnimap-capabilities may be better than polluting the code.

E.

Re: duplicates with offlineimap+dovecot

[Dan Christensen]

On Feb 23, 2016, gallego@cri.ensmp.fr (Emilio Jesús Gallego Arias) wrote:

> Lars Ingebrigtsen <larsi@gnus.org> writes:
>
>> gallego@cri.ensmp.fr (Emilio Jesús Gallego Arias) writes:
>>
>>> Update: this has been fixed upstream:
>>>
>>> http://www.dovecot.org/list/dovecot/2016-February/103205.html
>>
>> Perhaps we should add a quirk to nnimap to disable MOVE for the Dovecot
>> versions affected?  What versions are those?
>
> I dunno when the bug was introduced, but it didn't hurt too many people
> it seems.
>
> Maybe adding an entry to the FAQ/QUIRKS file instructing to remove
> "MOVE" from nnimap-capabilities may be better than polluting the code.

I have only skimmed this thread, but isn't it *streaming* moves that
are the problem?  If so, maybe it would be better to have Gnus do an
expunge (or whatever is needed) between moves?  Or does Gnus need to
adjust it's internal article numbering between moves?

I'm also curious about which versions of dovecot are affected.  I'm
using 1:2.2.9-1ubuntu2.1 from Ubuntu 14.04, and I occasionally see a
problem that might be related, but I'm not sure.

Dan

Re: duplicates with offlineimap+dovecot

[Lars Ingebrigtsen]

Dan Christensen <jdc@uwo.ca> writes:

> I have only skimmed this thread, but isn't it *streaming* moves that
> are the problem?  If so, maybe it would be better to have Gnus do an
> expunge (or whatever is needed) between moves?  Or does Gnus need to
> adjust it's internal article numbering between moves?

If Gnus can't stream the MOVEs, it's better not to use MOVE at all.  If
MOVE isn't supported, it streams COPYs and EXPUNGEs, and that works just
fine.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: duplicates with offlineimap+dovecot

[Lars Ingebrigtsen]

gallego@cri.ensmp.fr (Emilio Jesús Gallego Arias) writes:

> I dunno when the bug was introduced, but it didn't hurt too many people
> it seems.

Could you ask the Dovecot people?

> Maybe adding an entry to the FAQ/QUIRKS file instructing to remove
> "MOVE" from nnimap-capabilities may be better than polluting the code.

No, this should work out of the box without any configuration from the
user.

-- 
(domestic pets only, the antidote for overdose, milk.)
   bloggy blog: http://lars.ingebrigtsen.no

Re: duplicates with offlineimap+dovecot

[Emilio Jesús Gallego Arias]

Hi Lars,

Lars Ingebrigtsen <larsi@gnus.org> writes:

> gallego@cri.ensmp.fr (Emilio Jesús Gallego Arias) writes:
>
>> I dunno when the bug was introduced, but it didn't hurt too many people
>> it seems.
>
> Could you ask the Dovecot people?
>
>> Maybe adding an entry to the FAQ/QUIRKS file instructing to remove
>> "MOVE" from nnimap-capabilities may be better than polluting the code.
>
> No, this should work out of the box without any configuration from the
> user.

I've asked, a couple of additional thoughts wrt adding a workaround:

+ Workarounding missing expunges seems not very convenient, serializing
  everything may be a bit excessive?

+ Detecting affected servers will be hard, imagine that this patch gets
  pushed to Debian stable (which IMO should be), how would you detect
  it?

E.

Re: duplicates with offlineimap+dovecot

[Dave Abrahams]

on Mon Feb 01 2016, Julien Cubizolles <j.cubizolles-AT-free.fr> wrote:

Some unsolicited hints...

> I've the following setup:
>
> Two different IMAP accounts (free.fr and gmail.com). Both are
> synchronized with offlineimap

Hint: mbsync (a.k.a. isync) > offlineimap.

I've tried both extensively; just saying.

> and dovecot 

Hint: use dovecot's mdbox format; it's super efficient on-disk.

> to local IMAP folders, both accessed from Gnus with nnimap. This setup
> is used on 2 different computers.
>
> It's working fine except that I very often (almost at every
> synchronization) I end up with duplicates of some messages on the
> local IMAP folder, they are however not propagated to the distance
> IMAP server.
>
> It's not very inconvenient since gnus-suppress-duplicates takes care of
> if but I'm confused:
>
> + It seems to only happen with the free.fr account, although I couldn't
>   be sure since I don't have a lot of traffic on the gmail.com one
> + I never have the two computers running at the same time so there can't
>   be 2 offlineimap running at the same time.

You might have better luck with mbsync here.

> I have Gnus doing some splitting (including the detection of duplicates)
> on the local IMAP folders and some spam autodetection. Since the
> duplicates are not synced back to the remote server, could it be a
> problem with Gnus accessing the same message a second time and thinking
> it's a duplicate of the first one ? Have you ever experienced something
> similar ?
>
> Julien.

-- 
-Dave