Quoting Guilhem Moulin (2019-11-07 00:45:48)
> On Wed, 06 Nov 2019 at 12:44:08 +0100, Jonas Smedegaard wrote:
> > When I switched, I removed the local folder and had interimap 
> > syncronize it from scratch.  Or at least that is my belief: Does 
> > your forensics analysis above imply that I failed at that, and the 
> > local copy cannot have been initialized by interimap?

...and I since then did this:

  interimap --config hb --delete --target=database,local INBOX
  interimap --config hb

...which seemingly succeeded in throwing away local copy of INBOX and 
re-fetching it from remote INBOX, but then fails similarly with Drafts.

So I can now read my INBOX again, and we can continue debugging Drafts 
which are less crucial for me to have syncronized. :-)

...because surprisingly to me, attempting to throw away local copy of 
_Drafts_ failed:

jonas@auryn:~$ interimap --config hb --delete --target=database,local Drafts
jo...@jawa.homebase.dk's password: 
local: IMAP traffic (bytes): recv 571 sent 46
remote: IMAP traffic (bytes): recv 625 (compr. 594, factor 0.95) sent 71 
(compr. 80, factor 1.13)
jonas@auryn:~$ interimap --config hb Drafts
jo...@jawa.homebase.dk's password: 
remote: ERROR: UIDVALIDITY changed! (1571588832 != 1154884797)  Need to 
invalidate the UID cache.
local: IMAP traffic (bytes): recv 630 sent 109
remote: IMAP traffic (bytes): recv 684 (compr. 650, factor 0.95) sent 134 
(compr. 141, factor 1.05)

Am I perhaps misunderstanding and UIDVALIDITY is tied to whole account, 
not each mailbox?  But if that's the case then it confuses me that now 
sync'ing _only_ INBOX succeeds (it didn't previously).

Here is the above, repeated with --debug:

jonas@auryn:~$ interimap --config hb --debug Drafts
>>> interimap 0.4
local: S: * PREAUTH [CAPABILITY IMAP4rev1 SASL-IR LOGIN-REFERRALS ID ENABLE 
IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT 
MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS 
LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN 
CONTEXT=SEARCH LIST-STATUS BINARY MOVE SNIPPET=FUZZY PREVIEW=FUZZY LITERAL+ 
NOTIFY SPECIAL-USE] Logged in as jonas
local: C: 000000 ENABLE QRESYNC
local: S: * ENABLED QRESYNC
local: S: 000000 OK Enabled (0.001 + 0.000 secs).
jo...@jawa.homebase.dk's password: 
remote: S: * PREAUTH [CAPABILITY IMAP4rev1 SASL-IR LOGIN-REFERRALS ID ENABLE 
IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT 
MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS 
LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN 
CONTEXT=SEARCH LIST-STATUS BINARY MOVE SNIPPET=FUZZY LITERAL+ NOTIFY 
SPECIAL-USE COMPRESS=DEFLATE] Logged in as jonas
remote: C: 000000 COMPRESS DEFLATE
remote: S: 000000 OK Begin compression (0.001 + 0.000 secs).
remote: C: 000001 ENABLE QRESYNC
remote: S: * ENABLED QRESYNC
remote: S: 000001 OK Enabled (0.001 + 0.000 secs).
local: C: 000001 LIST "" Drafts RETURN (SUBSCRIBED STATUS (UIDVALIDITY UIDNEXT 
HIGHESTMODSEQ))
local: S: * LIST (\Subscribed \UnMarked) "." Drafts
local: S: * STATUS Drafts (UIDNEXT 962 UIDVALIDITY 1571588832 HIGHESTMODSEQ 4)
local: S: 000001 OK List completed (0.006 + 0.000 + 0.005 secs).
remote: C: 000002 LIST "" Drafts RETURN (SUBSCRIBED STATUS (UIDVALIDITY UIDNEXT 
HIGHESTMODSEQ))
remote: S: * LIST (\Subscribed \UnMarked) "." Drafts
remote: S: * STATUS Drafts (UIDNEXT 962 UIDVALIDITY 1571588832 HIGHESTMODSEQ 4)
remote: S: 000002 OK List completed (0.015 + 0.000 + 0.014 secs).
local: Update last clean state for Drafts: (UIDVALIDITY 1571588832 
HIGHESTMODSEQ 1 UIDNEXT 1)
remote: ERROR: UIDVALIDITY changed! (1571588832 != 1154884797)  Need to 
invalidate the UID cache.
local: IMAP traffic (bytes): recv 630 sent 109
remote: IMAP traffic (bytes): recv 684 (compr. 652, factor 0.95) sent 134 
(compr. 141, factor 1.05)
Cleaning up...
jonas@auryn:~$ interimap --config hb --delete --target=database,local Drafts
jo...@jawa.homebase.dk's password: 
remote: IMAP traffic (bytes): recv 625 (compr. 594, factor 0.95) sent 71 
(compr. 80, factor 1.13)
local: IMAP traffic (bytes): recv 571 sent 46
jonas@auryn:~$ interimap --config hb --debug Drafts
>>> interimap 0.4
local: S: * PREAUTH [CAPABILITY IMAP4rev1 SASL-IR LOGIN-REFERRALS ID ENABLE 
IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT 
MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS 
LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN 
CONTEXT=SEARCH LIST-STATUS BINARY MOVE SNIPPET=FUZZY PREVIEW=FUZZY LITERAL+ 
NOTIFY SPECIAL-USE] Logged in as jonas
local: C: 000000 ENABLE QRESYNC
local: S: * ENABLED QRESYNC
local: S: 000000 OK Enabled (0.001 + 0.000 secs).
jo...@jawa.homebase.dk's password: 
remote: S: * PREAUTH [CAPABILITY IMAP4rev1 SASL-IR LOGIN-REFERRALS ID ENABLE 
IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT 
MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS 
LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN 
CONTEXT=SEARCH LIST-STATUS BINARY MOVE SNIPPET=FUZZY LITERAL+ NOTIFY 
SPECIAL-USE COMPRESS=DEFLATE] Logged in as jonas
remote: C: 000000 COMPRESS DEFLATE
remote: S: 000000 OK Begin compression (0.001 + 0.000 secs).
remote: C: 000001 ENABLE QRESYNC
remote: S: * ENABLED QRESYNC
remote: S: 000001 OK Enabled (0.001 + 0.000 secs).
local: C: 000001 LIST "" Drafts RETURN (SUBSCRIBED STATUS (UIDVALIDITY UIDNEXT 
HIGHESTMODSEQ))
local: S: * LIST (\Subscribed \UnMarked) "." Drafts
local: S: * STATUS Drafts (UIDNEXT 962 UIDVALIDITY 1571588832 HIGHESTMODSEQ 4)
local: S: 000001 OK List completed (0.006 + 0.000 + 0.005 secs).
remote: C: 000002 LIST "" Drafts RETURN (SUBSCRIBED STATUS (UIDVALIDITY UIDNEXT 
HIGHESTMODSEQ))
remote: S: * LIST (\Subscribed \UnMarked) "." Drafts
remote: S: * STATUS Drafts (UIDNEXT 962 UIDVALIDITY 1571588832 HIGHESTMODSEQ 4)
remote: S: 000002 OK List completed (0.007 + 0.000 + 0.006 secs).
local: Update last clean state for Drafts: (UIDNEXT 1 HIGHESTMODSEQ 1 
UIDVALIDITY 1571588832)
remote: ERROR: UIDVALIDITY changed! (1571588832 != 1154884797)  Need to 
invalidate the UID cache.
local: IMAP traffic (bytes): recv 630 sent 109
remote: IMAP traffic (bytes): recv 684 (compr. 650, factor 0.95) sent 134 
(compr. 141, factor 1.05)
Cleaning up...


> I'd be interested to know the last good remote state, could you please
> run:
> 
>     sqlite3 /path/to/interimap/database.db -header <<-EOF
>                 SELECT l.UIDVALIDITY AS lUIDVALIDITY, l.UIDNEXT AS lUIDNEXT, 
> l.HIGHESTMODSEQ AS lHIGHESTMODSEQ,
>                        r.UIDVALIDITY AS rUIDVALIDITY, r.UIDNEXT AS rUIDNEXT, 
> r.HIGHESTMODSEQ AS rHIGHESTMODSEQ
>                  FROM mailboxes m JOIN local l ON m.idx = l.idx JOIN remote r 
> ON m.idx = r.idx
>                 WHERE mailbox = 'INBOX';
> 
>                 SELECT COUNT(*) AS messages
>                  FROM mailboxes NATURAL JOIN mapping
>                 WHERE mailbox = 'INBOX';
>         EOF
> 
> and paste the output?  (The database file can normally be found under
> ‘${XDG_SHARE_HOME:-~/.local/share}/interimap’, and the default filename
> is the hostname of your remote server.)

Above command(s), adapted for Drafts mailbox:

jonas@auryn:~$ sqlite3 ~/.local/share/interimap/hb.db -header <<-EOF
SELECT l.UIDVALIDITY AS lUIDVALIDITY, l.UIDNEXT AS lUIDNEXT, l.HIGHESTMODSEQ AS 
lHIGHESTMODSEQ, r.UIDVALIDITY AS rUIDVALIDITY, r.UIDNEXT AS rUIDNEXT, 
r.HIGHESTMODSEQ AS rHIGHESTMODSEQ
FROM mailboxes m JOIN local l ON m.idx = l.idx JOIN remote r ON m.idx = r.idx
WHERE mailbox = 'Drafts';
SELECT COUNT(*) AS messages FROM mailboxes NATURAL JOIN mapping WHERE mailbox = 
'Drafts';
> bash: advarsel: here-document ved linje 1754 er adskilt af slut-på-linje 
> (ønskede "EOF")
lUIDVALIDITY|lUIDNEXT|lHIGHESTMODSEQ|rUIDVALIDITY|rUIDNEXT|rHIGHESTMODSEQ
1571588832|1|1|1154884797|962|4
messages
0


> We already know the values of lUIDVALIDITY, lUIDNEXT, lHIGHESTMODSEQ
> and rUIDVALIDITY: respectively 1571588814, 9598, 165 and 1571588814.
> I'm interested in rUIDNEXT and rHIGHESTMODSEQ though.  I'd also like to
> see the output of
> 
>     doveadm mailbox status "messages uidnext uidvalidity highestmodseq 
> firstsaved" INBOX
> 
> both locally and remotely.

Locally (adapted for Drafts mailbox and custom location):

jonas@auryn:~$ doveadm -o mail_location=maildir:~/Maildir/hb mailbox status 
"messages uidnext uidvalidity highestmodseq firstsaved" Drafts
doveadm(jonas): Error: net_connect_unix() failed: Connection refused
Drafts messages=0 uidnext=962 uidvalidity=1571588832 highestmodseq=4 
firstsaved=18446744073709551615

Remote (adapted for Drafts mailbox):

jonas@auryn:~$ ssh mail.homebase.dk doveadm mailbox status "messages uidnext 
uidvalidity highestmodseq firstsaved" Drafts
jo...@mail.homebase.dk's password: 
doveadm(jonas): Error: net_connect_unix() failed: Connection refused
Drafts messages=0


> I was asking if you run dsync(1) *after* interimap because it does 
> indeed mess around with the index files (unlike interimap and other 
> IMAP solutions, it works at a lower level and does mirror mailbox 
> states incl. UIDVALIDITY, UIDNEXT values as well as UIDs).  I'm even 
> able able to reproduce a similar conflict in a test harness:
[...]
> However the messages appear to be duplicated, with counts going from 
> 66 to 132, so maybe it's not what you're seeing.

I have triple-checked, and am preeetty sure that I completely stopped 
using dsync after I engaged with interimap.  Cannot verify for certain 
e.g. by examining .bash_history because I use a local wrapper script, 
but all lines in that wrapper script which previously called dsync was 
commented out before I initially ran interimap (and that commenting out 
is what I triple-checked).


> >> Now, how to fix this?  The easiest is to remove the database entry 
> >> for that mailbox: `interimap --target=database delete INBOX` (this 
> >> won't touch your mails, just the database) and then try to sync 
> >> again. However every message in the local INBOX will be copied 
> >> remotely and vice-versa, so if you have a lot of messages in both 
> >> mailboxes this will create a lot of duplicates :-( This won't cause 
> >> any data loss though.
> > 
> > That sounds like the least scary approach.  And then afterwards try do a 
> > "doveadm deduplicate".
> 
> Oh, I wasn't aware of `doveadm deduplicate`, thanks for the hint!  I
> added a pointer in the documentation.  Note however that deduplication
> by message GUIDs won't work, because interimap (like any IMAP client) is
> not GUID-aware and dovecot will assign a new GUID on APPEND.

Yes, I am aware (but thanks for mentioning anyway!) - that's the reason 
I didn't post the actual command I was intending to use: I remembered 
that it wasn't _simply_ calling the deduplicate subcommand but needed 
some extra option to more aggressively strip duplicates.  Or maybe I 
remember wrongly and there is no such extra option, and what I in fact 
did last time was give up on "doveadm deduplicate" and instead use 
interactive deduplication tricks for mutt (which again, as I recall, in 
some approaches fail to recognize mails as duplicates).

> Removing duplicates based on Message-Id values (flag ‘-m’) does work, 
> but is less reliable as two different might share the same Message-Id.

Right - that sounds like what I learned back when I found that "doveadm 
deduplicate" (and mutt) approach(es).


> Unfortunately doveadm-deduplicate(1) doesn't have a flag to deduplicate
> by message RFC 5322 content, but for simple mail stores like Maildir it
> can be done manually at the file-system level:
> 
>     find /path/to/Maildir/{cur,new,tmp} -type f -print0 \
>     | xargs -r0 sha256sum -z \
>     | sort -z \
>     | uniq -zd -w64 \
>     | cut -z -b1-66 --complement >/tmp/duplicates
> 
> Use `xargs -r0 -a/tmp/duplicates rm -vf --` to remove duplicates (only
> one per group, repeat until there are no duplicates left to remove).
> Next time interimap runs it'll receive a “VANISHED (EARLIER)” response
> from that server, and remove matching messages on the other one.

Interesting!  Please consider adding that trick somewhere too, for 
posterity :-)


> >> Another thing which seems to suggest that there is a lower-level 
> >> synchronization running and causing cache corruption, is the huge 
> >> spike between the local INBOX's current state and the one from the 
> >> database (ie the last successful sync): UIDNEXT=9598 / 
> >> HIGHESTMODSEQ=165 vs. UIDNEXT=290008 / HIGHESTMODSEQ=71671.  While 
> >> sudden heavy-traffic mailboxes are certainly possible, it's still a 
> >> bit suspicious.
> > 
> > Sorry, I don't understand what you are saying here.
> 
> I hope the above wall of text helps clarify this. :-)

Helps, yes, but still confusing :-/


> > Could that perhaps be explained by my _previous_ use of dsync and 
> > then resyncing from scratch with interimap?  I mean, I guess that 
> > would show as high counts remote and low counts locally.
> 
> By restarting from scratch I guess you nuked the local mailbox?

Correct, I did (the equivalent in Midnight Commander of) this:

  $ rm -rf ~/Maildir/hb/

(and also nuked interimap database from an older failed test run)

> > I suspect the corruption is caused by my use of notmuch with the 
> > synchronize_flags=true setting.
> 
> Do you also use notmuch remotely?  (It's the *remote* UIDVALIDITY 
> value that changed, not the local one) Or more exactly, do you ever 
> access the remote mailstore directly, not through the IMAPd?

No, I use notmuch only locally.

Remotely my mailboxes are in Maildir accessed only through Dovecot.

Possibly related sidenote: I noticed suspecious interimap summary notes 
about bandwidth consumption that seemed flipped around (new messages 
transfered from remote to local, but interimap saying that remote 
received far more than sending, and local received far less than 
sending).  Possible local/remote mixup in interimap code somewhere? 
Sidenote only here - if I notice again I will report separately!


> Also for Maildir [0] Dovecot keeps the mapping between UID and 
> filenames in a ‘dovecot-uidlist’ inside each mailbox directory, and 
> the UIDVALIDITY value can be found in the header of that file.  
> notmuch and others MUA have no business in this file, and I do hope 
> they just ignore it.  Also I doubt the fact that the local and remote 
> UIDVALIDITY are now identical is a coincidence.  My gut feeling is 
> that either Dovecot's internal file (‘dovecot-uidlist’) was copied as 
> is, or the tool that caused the corruption is able to parse it.


 - Jonas

-- 
 * Jonas Smedegaard - idealist & Internet-arkitekt
 * Tlf.: +45 40843136  Website: http://dr.jones.dk/

 [x] quote me freely  [ ] ask before reusing  [ ] keep private

Attachment: signature.asc
Description: signature

Reply via email to