need help debugging deleted mails

Vu Ngoc VU vvu at mcra.fr
Thu Aug 13 07:45:37 UTC 2015


hello,

one of our users complained about the fact that he doesn't receive some messages (randomly) that his teamates have.

Grepping for the message-ID in the mail.log, I can see lmtp says it is saved :

Aug 12 15:23:23 imap-01 dovecot: lmtp(4943, johndoe at example.net): fFuCO09Hy1VPEwAA2t/0+w: sieve: vsize= msgid=<037e01d0d502$0e3687d0$2aa39770$@example.net>: stored mail into mailbox 'INBOX'

The only difference with others recipients is the 'sieve:... stored mail' instead of 'saved mail to' when there is no sieve.

But when he asked me, the message was no more in his maildir (I checked with doveadm search).

As we have checked and disabled all the filters in his MUA and on the server (sieve) and this issue still continue, I did mkdir a dovecot.rawlog inside his home.

With the help of rawlog, I can see that the message can be found in a .out file (by grepping the Message-ID).
And by reading this .out log raw log, the entire message were sent to the client. So I guess that :
* the message was written to disk
* it was sent to the MUA

But I need your help because I don't get how this message disappear from his maildir.
My assumptions was that the client must do some commands like :
* STORE the \Deleted flag to this message UID
* and then, later do EXPUNGE

but I did : 
* grep -i expunge * 20150812* => no match
* grep -iE '\+flags .*\\deleted' => a few matches but not with the appropriate UID


snippet from the 20150812-133858-13317.in file: 
8nk1 UID FETCH 208209 (UID FLAGS RFC822.SIZE BODY.PEEK[HEADER] INTERNALDATE)
p7uv IDLE
DONE
6yk3 NOOP
83g6 IDLE
DONE
yhbd UID FETCH 208209 (UID FLAGS BODY.PEEK[])
fy16 IDLE
DONE

snippet from the 20150812-133858-13317.out file:
* 56295 FETCH (UID 208209)
wn2p OK Fetch completed.
* 56295 FETCH (UID 208209 FLAGS (\Deleted \Seen \Recent) RFC822.SIZE 17138 INTERNALDATE "12-Aug-2015 15:23:22 +0200" BODY[HEADER] {2836}


Considering these points:
* I cannot find any match with 208209 early in raw logs
* I don't see any expunge for the whole day
* I've grepped for \Deleted (insensitive) and didn't find matching like a interval of messages UID.

What did I miss to find out how/when the message got \Deleted flag and was removed from his maildir?


A few about my setup :
* system is ubuntu 14.04 inside OpenVZ containers (Proxmox)
* dovecot version is 2.2.9 from Ubuntu packages
* 2 director with Internet and local ip addresses
* 2 backends with only local addresses
* these dovecot access storage servers by NFSv3 (that's why we have director)
* imap/lmtp are proxied

Thanks a lot for reading, I'm really disappointed about this problem.
For the moment, I'll delete his script even if all rules are disabled (via roundcube, and I checked the rule is commented in the file).
And also I'll try to watch what happens with inotify on the storage server.


More information about the dovecot mailing list