[Dovecot] fstat() errors on /srv/mail/<username>/dovecot.index.log

[Zach La Celle]

On 10/17/2013 09:23 AM, Zach La Celle wrote:
> On 10/17/2013 05:25 AM, Noel Butler wrote:
>> On 17/10/2013 00:08, Zach La Celle wrote:
>>> Dovecot version 2.1.7
>>> Ubuntu 12.04.3 LTS
>>> Kernel 3.2.0-35-generic x86_64
>>>
>>> I'm not sure exactly when this started occurring, but sporatically users
>>> report issues receiving email, having email saved to "Sent," etc.
>>> Looking in dovecot.log, I see the following errors:
>>>
>>> 2013-10-16 09:53:20 imap-login: Info: Login: user=<user1>, method=PLAIN,
>>> rip=127.0.0.1, lip=127.0.0.1, mpid=27434, secured,
>>> session=<PnoiBtzoBgB/AAAB>
>>> 2013-10-16 09:53:20 imap(user1): Info: Disconnected: Logged out in=93
>>> out=846
>>> 2013-10-16 09:53:21 imap(user2): Info: Disconnected: Logged out in=3616
>>> out=495
>>> 2013-10-16 09:53:24 imap-login: Info: Login: user=<user3>, method=PLAIN,
>>> rip=127.0.0.1, lip=127.0.0.1, mpid=27436, secured,
>>> session=<jE5kBtzoBwB/AAAB>
>>> 2013-10-16 09:53:24 imap(user3): Info: Disconnected: Logged out in=93
>>> out=819
>>> 2013-10-16 09:53:33 imap(user4): Error: fstat() failed with file
>>> /srv/mail/user4/dovecot.index.log: No such file or directory
>>> 2013-10-16 09:53:33 imap(user4): Error: fstat() failed with file
>>> /srv/mail/user4/dovecot.index.log: No such file or directory
>>> 2013-10-16 09:53:33 imap(user4): Error: fstat() failed with file
>>> /srv/mail/user4/dovecot.index.log: No such file or directory
>>> 2013-10-16 09:53:33 imap(user4): Error: fstat() failed with file
>>> /srv/mail/user4/dovecot.index.log: No such file or directory
>>> 2013-10-16 09:53:33 imap(user4): Error: fstat() failed with file
>>> /srv/mail/user4/dovecot.index.log: No such file or directory
>>> 2013-10-16 09:53:33 imap(user4): Error: fstat() failed with file
>>> /srv/mail/user4/dovecot.index.log: No such file or directory
>>> 2013-10-16 09:53:41 imap-login: Info: Login: user=<user3>, method=PLAIN,
>>> rip=127.0.0.1, lip=127.0.0.1, mpid=27438, secured,
>>> session=<UDJlB9zoCAB/AAAB>
>>> 2013-10-16 09:53:41 imap(user3): Info: Disconnected: Logged out in=93
>>> out=819
>>> 2013-10-16 09:54:12 imap-login: Info: Login: user=<user1>, method=PLAIN,
>>> rip=127.0.0.1, lip=127.0.0.1, mpid=27440, secured,
>>> session=<6bI5CdzoCQB/AAAB>
>>> 2013-10-16 09:54:12 imap(user1): Info: Disconnected: Logged out in=93
>>> out=846
>>> 2013-10-16 09:54:12 imap(user5): Info: Disconnected: Logged out in=736
>>> out=7064
>>> 2013-10-16 09:54:15 imap-login: Info: Login: user=<user6>, method=PLAIN,
>>> rip=127.0.0.1, lip=127.0.0.1, mpid=27442, secured,
>>> session=<t+FnCdzoCgB/AAAB>
>>> 2013-10-16 09:54:15 imap(user6): Info: Disconnected: Logged out in=95
>>> out=902
>>> 2013-10-16 09:54:20 imap-login: Info: Login: user=<user1>, method=PLAIN,
>>> rip=127.0.0.1, lip=127.0.0.1, mpid=27444, secured,
>>> session=<c/q1CdzoCwB/AAAB>
>>> 2013-10-16 09:54:20 imap(user1): Info: Disconnected: Logged out in=93
>>> out=846
>>> 2013-10-16 09:54:24 imap-login: Info: Login: user=<user3>, method=PLAIN,
>>> rip=127.0.0.1, lip=127.0.0.1, mpid=27446, secured,
>>> session=<nOb3CdzoDAB/AAAB>
>>> 2013-10-16 09:54:24 imap(user3): Info: Disconnected: Logged out in=93
>>> out=819
>>>
>>> These errors are not confined to a single user, and do not occur with
>>> the same frequency.
>>>
>>
>> This isnt per chance on a NAS/SAN/DAS is it?
>>
> No, it is not on a SAN.  I saw that thread a while back, but this
> doesn't seem to be related.
>>> I originally was running the Dovecot shipped with the default Ubuntu
>>> repositories (don't remember which version, but it was 1.*) and used a
>>> backport to upgrade to 2.1.7 to see if that fixed it.  It did not.
>>>
>>> Any ideas why this is happening?
>> gawd knows what debian (thats all ubuntu is, same package maintainers
>> 99% of time) do to things, wouldnt be the first time they put out a
>> package that was kaput from get go, so doveconf -n  output will likely
>> be required
>>
> I can provide "dovecot -n" output if this doesn't answer the question,
> but it might be an apparmor issue.  We recently enabled apparmor
> protection, and it seems that it generated an ungodly amount of profiles
> in complain mode.  So many, that it was causing issues with usage of the
> openssl library.
>
> Putting it in to enforce mode seems like it might fix the problem.  I'll
> post more information once this is confirmed or denied.
I'm replying to this post for completeness.  This was definitely a
problem with AppArmor in complain mode breaking IMAP.  It was generating
an incredible amount of logging information, and ended up blocking
access to the OpenSSL .so files every once in a while.

Putting AppArmor into enforce mode (after checking all of the rules and
verifying functionality) worked.  No more fstat() errors.