[Dovecot] Odd ownership of the dovecot-uidlist file

[Bruce]

Hi Steffen,

See my responses below,

On 04/06/14 18:52, Steffen Kaiser wrote:
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA1
>
> On Wed, 4 Jun 2014, Bruce wrote:
>
>> Please see my responses below,
> I dislike top posting anyway :-)
>
Yeah, its habit as I deal with people who top post and reply with 'Your 
email had nothing in it' if I don't say there is more below.

>> >Jun 3 11:38:51 brio dovecot: Dovecot postlogin.sh running as 
>> hamish at XXXXX
>>>> >(/mnt/spool/keepers/h/XXXXX/hamish) userid = 7053 (7053) - uidlist 
>>>> = 26624
>>>> >Jun 3 11:38:51 brio dovecot: Dovecot for hamish at XXXXX finished, 
>>>> uidlist now =
>>>> >26624
>>> who is user 26624? Is the uid valid at all? If it is invalid, are there
>>> other files owned by this uid? Maybe only one of your NFS server has 
>>> this
>>> uid in its /etc/passwd? Is user "hamish" shared to another user 
>>> somehow,
>>> either via symlinks, ACLs, ...?
>> UID 26624 is a valid user ('info' of domain14552) but under a 
>> compleltly different domain name (hamish is under domain25367). 
>> However that user has also not logged in around the time the 
>> ownership was changed. There is no relevance to the two users, except 
>> that they exist on the system and for some reason this issue happened 
>> to the hamish user.
> That means: no sharing, right ?

Correct.

>> The NFS server does not know about the UIDs, it just provides the 
>> numeric IDs which is translated on the dovecot/exim servers by NSS 
>> and Dovecotr using the replicated MySQL database. Additionally both 
>> users have existed for some time and the databases are in sync. 
>> Customers also do not have any access to the file system so there 
>> will be no symlinks in place.
>>
>> Its also not a single server that we are seeing the issue on, it 
>> maybe one Dovecot server accessing one NFS server. Then the next time 
>> its a different Dovecot server accessing a different NFS server.
> Because it's NFS, any server accessing this NFS export may alter the 
> ownership, because I still do not believe it's a Dovecot IMAP/POP 
> issue ;-)
>
But we would see this with any application and file that is on NFS, in 
this case it is only ever one particular file, and only happened after 
changing to Dovecot (Previous to that we have had this NFS set up in 
place for 7 years).

>> Nothing besides Courier being replaced by Dovecot has changed in the 
>> server setup (although I could be wrong there, but we are going 
>> through one component at a time and until this issue is resolved we 
>> are not moving onto the next), and the only file which is being 
>> modified is a file which only Dovecot maintains.
> Could there be Courier-related left-over scripts running?

Its highly unlikely, and why would a courier script want to modify the 
ownership of a Dovecot file.

>> There are hourly backups which do an rsync to another server in case 
>> of hardware failure, there are scripts which move mailboxes between 
>> NFS servers but they show up in logs. Exim has no need to touch a 
>> dovecot controlled file, and when it writes mail into the maildir its 
>> writing as the correct user.
> How does exim deliver the messages to the user storage? Via 
> Dovecot-Deliver or directly. I interprete your sentence, that the 
> messages are dropped directly.
> 00

Exim does it directly, once again no need for it to touch a file which 
Dovecot creates and maintains.

>> possibly something we have done in the config (which I posted in my 
>> first email). Is there a reliable way to run a script directly when a 
>> dovecot session starts and finishes so we could output the ownership 
>> before and after which may also help eliminate the session itself.
> Your post-login script does exactly that. That leaves the message 
> delivery, if you do so via Dovecot deliver. LMTP seems to be off.
>
I thought that's what should happen but looking at timestamps of the 
logins after the change, the permission denied always comes after the 
postlogin script completes, which means something happens after then.

Jun 3 12:56:31 gettas dovecot: pop3(celia at xxx): Mailbox init failed 
top=0 (0 b), retr=0 (0 b), messages=0 (0 b), del=0
Jun 3 12:56:32 gettas dovecot: pop3-login: Login: user=<celia at xxx>, 
method=PLAIN, rip=x.x.x.x, lip=x.x.x.x, mpid=19655, TLS, 
session=<r2qX++P6gAB6PWyl>
Jun 3 12:56:32 gettas dovecot: Dovecot postlogin.sh running as 
celia at xxx/celia) userid = 41410 (41410) - uidlist = 7903
Jun 3 12:56:32 gettas dovecot: Dovecot for celia at xxx finished, uidlist 
now = 7903 <---- POSTLOGIN.SH ENDS HERE
Jun 3 12:56:32 gettas dovecot: 
pop3(celia at xxx/celia/Maildir/dovecot-uidlist) failed: Permission denied
Jun 3 12:56:32 gettas dovecot: 
pop3(celia at xxx/celia/Maildir/dovecot-uidlist) failed: Permission denied
Jun 3 12:56:32 gettas dovecot: pop3(celia at xxx): Error: Couldn't init 
INBOX: Internal error occurred. Refer to server log for more 
information. [2014-06-03 12:56:32]
Jun 3 12:56:32 gettas dovecot: pop3(celia at xxx): Mailbox init failed 
top=0 (0 b), retr=0 (0 b), messages=0 (0 b), del=0

I could put this down to same microsecond and syslog recording in a 
different order, but its consistently in this order.

> I'm not sure if inotify works via NFS as Peter suggested, but that 
> would my next idea as well. Let inotify wait for changes on that file, 
> then fire up a script to capture "ps gaux" and maybe more.
>
> If you have SELinux running, maybe you can trigger a warning there? I 
> don't know much about SELinux.

We don't have SELinux running, and unfortunately we are talking over 
400,000 mailboxes (200,000 domains) which this could happen randomly too 
and adding inotify requires a file handle to be opened per file, which 
would make the servers unstable.


I have found a piece of code in the Dovecot source which I'm wondering 
about, so I am going to compile up a custom version and see if it 
continues to happen. Of course with it happening randomly being able to 
confirm its still happening is going to take time. So if anyone has any 
other ideas where to look I would be appreciative.

Cheers,
Bruce