[Dovecot] Index cache errors worse with 2.2.x

[Alexander 'Leo' Bergolth]

On 05/13/2014 12:43 PM, Axel Luttgens wrote:
> Le 8 mai 2014 à 11:59, Alexander 'Leo' Bergolth a écrit :
>> [...]
>> I am using a single server, mbox, local disks (/home and /var is XFS on
>> HP SmartArray).
>>
>> I tried dovecot 2.2.7, 2.2.10 and 2.2.12. All of them produce tha same
>> errors. ("Cached message size smaller than expected", sometimes followed
>> by "read... Invalid argument".)
>>
>> 2.1.1 seems to only produce "Cached message size smaller than expected"
>> without the read errors.
>>
>> Cheers,
>> --leo
>>
>> [...]
>> mbox_write_locks = fcntl
>> [...]
> 
> Hello Alexander,
> 
> Your error messages seem to be related to the user's INBOX.

They appear with different users and are not always related to inboxes. I've also encountered those messages with other mailboxes, like /home/$USER/mail/Trash.

"doveadm force-resync" doesn't fix them.

> On the other hand, your config doesn't make appear lda nor lmtp (or I missed it, in which case, well... sorry).
> Who puts the incoming messages into the mboxes?

Mail is delivered via maildrop (maildrop-2.5.0-13.el6.x86_64).

I don't think that it is a mailbox lock problem between LDA and dovecot, since

- the errors occur with mailboxes other than INBOX
- there is no mail delivery logged between the last imap logout and the error:

-------------------- 8< --------------------
May 13 10:16:46 samba dovecot: imap-login: Login: user=<USERX>, method=PLAIN, rip=172.23.60.1, lip=172.23.60.3, mpid=6875, secured, session=<leNZr0P5NQCsFzwB>
May 13 10:18:06 samba dovecot: imap(USERX): Disconnected: Logged out in=507 out=4607
May 13 10:19:56 samba dovecot: imap-login: Login: user=<USERX>, method=PLAIN, rip=172.23.60.1, lip=172.23.60.3, mpid=7686, secured, session=<NAaoukP5OQCsFzwB>
May 13 10:37:05 samba dovecot: imap-login: Login: user=<USERX>, method=PLAIN, rip=172.23.60.1, lip=172.23.60.3, mpid=12234, secured, session=<tQX990P5aACsFzwB>
May 13 10:38:04 samba dovecot: imap-login: Login: user=<USERX>, method=PLAIN, rip=172.23.60.1, lip=172.23.60.3, mpid=12483, secured, session=<dzKD+0P5awCsFzwB>
May 13 10:38:05 samba dovecot: imap-login: Login: user=<USERX>, method=PLAIN, rip=172.23.60.1, lip=172.23.60.3, mpid=12495, secured, session=<UxmR+0P5bACsFzwB>
May 13 10:38:06 samba dovecot: imap-login: Login: user=<USERX>, method=PLAIN, rip=172.23.60.1, lip=172.23.60.3, mpid=12498, secured, session=<epWg+0P5bQCsFzwB>
May 13 10:38:06 samba dovecot: imap(USERX): Connection closed in=16 out=405
May 13 10:38:07 samba dovecot: imap-login: Login: user=<USERX>, method=PLAIN, rip=172.23.60.1, lip=172.23.60.3, mpid=12503, secured, session=<LMyp+0P5bgCsFzwB>
May 13 10:38:08 samba dovecot: imap(USERX): Error: Cached message size smaller than expected (68196 < 68197)
May 13 10:38:08 samba dovecot: imap(USERX): Error: Corrupted index cache file /home/USERX/mail/.imap/INBOX/dovecot.index.cache: Broken physical size for mail UID 1835
May 13 10:38:08 samba dovecot: imap(USERX): Error: read(/var/mail/USERX) failed: Invalid argument (uid=1835)
May 13 10:38:08 samba dovecot: imap(USERX): Disconnected: Internal error occurred. Refer to server log for more information. [2014-05-13 10:38:07] in=794 out=264037
May 13 10:38:08 samba dovecot: imap-login: Login: user=<USERX>, method=PLAIN, rip=172.23.60.1, lip=172.23.60.3, mpid=12513, secured, session=<RGXF+0P5bwCsFzwB>
-------------------- 8< --------------------

However I do often see multiple imap logins before the errors.
Maybe it's a dovecot internal cache locking issue?

Cheers,
--leo
-- 
e-mail   ::: Leo.Bergolth (at) wu.ac.at   
fax      ::: +43-1-31336-906050
location ::: IT-Services | Vienna University of Economics | Austria