Hello,
Today while looking at a different issue (one user couldn't retrieve mail; DNS issue) I set 'mail_debug=yes' then ran `dovecot reload` on our mail server. After running the reload, dovecot started complaning about permission issues with the dict file, and preceded to try to kill it's self. The self reload didn't seem to work, and since this is a production system, I was forced to restart the dovecot service. After the restart of the service, everything seemed to go back to normal. Dovecot is currently working as expected, no other permission errors in the logs.

Dovecot Version: 2.0.9 (3582271a897e) running on Fedora 14 running with a mySQL setup including dict tables (quota, expire). The virtual user's mail has a local user and group id of 1000.

Below is the expert from the log:

Jan 25 18:00:01 milly postfix/smtpd[9418]: connect from 
odin.example.com[174.143.172.159]
Jan 25 18:00:01 milly postfix/smtpd[9418]: disconnect from 
odin.example.com[174.143.172.159]
Jan 25 18:01:05 milly dovecot: dict: mysql: Connected to localhost (postfix)
Jan 25 18:01:17 milly dovecot: master: Warning: SIGHUP received - reloading 
configuration
Jan 25 18:01:27 milly postfix/anvil[6470]: statistics: max connection rate 
2/60s for (submission:192.168.10.12) at Jan 25 17:57:19
Jan 25 18:01:27 milly postfix/anvil[6470]: statistics: max connection count 1 
for (smtp:168.100.1.4) at Jan 25 17:52:25
Jan 25 18:01:27 milly postfix/anvil[6470]: statistics: max cache size 3 at Jan 
25 17:55:23
Jan 25 18:01:59 milly dovecot: imap(matt): Error: 
net_connect_unix(/usr/var/run/dovecot/dict) failed: Permission denied 
(euid=1000(virtualmail) egid=1000(virtualmail) missing +r perm: 
/usr/var/run/dovecot/dict, euid is not dir owner)
Jan 25 18:01:59 milly dovecot: imap(matt): Error: Internal quota calculation 
error
Jan 25 18:02:02 milly dovecot: imap(matt): Error: 
net_connect_unix(/usr/var/run/dovecot/dict) failed: Permission denied 
(euid=1000(virtualmail) egid=1000(virtualmail) missing +r perm: 
/usr/var/run/dovecot/dict, euid is not dir owner)
Jan 25 18:02:02 milly dovecot: imap(matt): Error: Internal quota calculation 
error
Jan 25 18:02:14 milly dovecot: imap(matt): Error: 
net_connect_unix(/usr/var/run/dovecot/dict) failed: Permission denied 
(euid=1000(virtualmail) egid=1000(virtualmail) missing +r perm: 
/usr/var/run/dovecot/dict, euid is not dir owner)
Jan 25 18:02:14 milly dovecot: imap(matt): Error: 
net_connect_unix(/usr/var/run/dovecot/dict) failed: Permission denied 
(euid=1000(virtualmail) egid=1000(virtualmail) missing +r perm: 
/usr/var/run/dovecot/dict, euid is not dir owner)
Jan 25 18:02:14 milly dovecot: imap(matt): Error: 
net_connect_unix(/usr/var/run/dovecot/dict) failed: Permission denied 
(euid=1000(virtualmail) egid=1000(virtualmail) missing +r perm: 
/usr/var/run/dovecot/dict, euid is not dir owner)
Jan 25 18:02:14 milly dovecot: imap(matt): Error: 
net_connect_unix(/usr/var/run/dovecot/dict) failed: Permission denied 
(euid=1000(virtualmail) egid=1000(virtualmail) missing +r perm: 
/usr/var/run/dovecot/dict, euid is not dir owner)
Jan 25 18:02:17 milly dovecot: master: Warning: Processes aren't dying after 
reload, sending SIGTERM.
Jan 25 18:02:17 milly dovecot: imap: Warning: Killed with signal 15 (by 
pid=5922 uid=0 code=kill)
Jan 25 18:02:17 milly dovecot: imap: Server shutting down. bytes=73545/124557
Jan 25 18:02:17 milly dovecot: imap: Warning: Killed with signal 15 (by 
pid=5922 uid=0 code=kill)
Jan 25 18:02:17 milly dovecot: imap: Server shutting down. bytes=9609/127653
Jan 25 18:02:17 milly dovecot: imap: Warning: Killed with signal 15 (by 
pid=5922 uid=0 code=kill)
Jan 25 18:02:17 milly dovecot: imap: Warning: Killed with signal 15 (by 
pid=5922 uid=0 code=kill)
Jan 25 18:02:17 milly dovecot: imap: Server shutting down. bytes=2836/8394
Jan 25 18:02:17 milly dovecot: imap: Server shutting down. bytes=9335/53756
Jan 25 18:02:17 milly dovecot: imap: Warning: Killed with signal 15 (by 
pid=5922 uid=0 code=kill)
Jan 25 18:02:17 milly dovecot: imap: Server shutting down. bytes=2449/6084
Jan 25 18:02:17 milly dovecot: imap: Warning: Killed with signal 15 (by 
pid=5922 uid=0 code=kill)
Jan 25 18:02:17 milly dovecot: imap: Server shutting down. bytes=1000/2416
Jan 25 18:02:17 milly dovecot: imap: Warning: Killed with signal 15 (by 
pid=5922 uid=0 code=kill)
Jan 25 18:02:17 milly dovecot: imap: Warning: Killed with signal 15 (by 
pid=5922 uid=0 code=kill)
Jan 25 18:02:17 milly dovecot: imap: Server shutting down. bytes=52000/12276
Jan 25 18:02:17 milly dovecot: imap: Server shutting down. bytes=3796/86595
Jan 25 18:02:17 milly dovecot: imap: Warning: Killed with signal 15 (by 
pid=5922 uid=0 code=kill)
Jan 25 18:02:17 milly dovecot: imap: Server shutting down. bytes=557/2333
Jan 25 18:02:17 milly dovecot: imap: Warning: Killed with signal 15 (by 
pid=5922 uid=0 code=kill)
Jan 25 18:02:17 milly dovecot: imap: Server shutting down. bytes=2003/6833
Jan 25 18:02:17 milly dovecot: imap: Warning: Killed with signal 15 (by 
pid=5922 uid=0 code=kill)
Jan 25 18:02:17 milly dovecot: imap: Server shutting down. bytes=60624/207831
Jan 25 18:02:17 milly dovecot: imap: Warning: Killed with signal 15 (by 
pid=5922 uid=0 code=kill)
Jan 25 18:02:17 milly dovecot: imap: Server shutting down. bytes=103883/195056
Jan 25 18:02:17 milly dovecot: imap: Warning: Killed with signal 15 (by 
pid=5922 uid=0 code=kill)
Jan 25 18:02:17 milly dovecot: imap: Server shutting down. bytes=68919/371893
Jan 25 18:02:17 milly dovecot: config: Warning: Killed with signal 15 (by 
pid=5922 uid=0 code=kill)
Jan 25 18:02:17 milly dovecot: dict: Warning: Killed with signal 15 (by 
pid=5922 uid=0 code=kill)

( I manually restarted the dovecot service )

Jan 25 18:03:09 milly dovecot: lda: Debug: Loading modules from directory: 
/usr/lib/dovecot/
Jan 25 18:03:09 milly dovecot: lda: Debug: Module loaded: 
/usr/lib/dovecot//lib10_quota_plugin.so
Jan 25 18:03:09 milly dovecot: lda: Debug: Module loaded: 
/usr/lib/dovecot//lib20_expire_plugin.so
Jan 25 18:03:09 milly dovecot: lda: Debug: Module loaded: 
/usr/lib/dovecot//lib90_sieve_plugin.so
Jan 25 18:03:09 milly dovecot: auth: mysql: Connected to localhost (postfix)
Jan 25 18:03:09 milly dovecot: lda: Debug: auth input: lists maildir=lists 
uid=1000 gid=1000 home=/var/spool/virtualmailboxes/lists 
quota_rule=*:storage=4194304 mail=mdbox:/var/spool/virtualmailboxes/lists
Jan 25 18:03:09 milly dovecot: lda: Debug: changed username to lists
Jan 25 18:03:09 milly dovecot: lda: Debug: Added userdb setting: 
plugin/maildir=lists
Jan 25 18:03:09 milly dovecot: lda: Debug: Added userdb setting: 
plugin/quota_rule=*:storage=4194304
Jan 25 18:03:09 milly dovecot: lda: Debug: Added userdb setting: 
mail=mdbox:/var/spool/virtualmailboxes/lists
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: Effective uid=1000, gid=1000, 
home=/var/spool/virtualmailboxes/lists
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: Quota root: name=User quota 
backend=dict args=:proxy::quota
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: Quota rule: root=User quota 
mailbox=* bytes=4294967296 messages=0
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: Quota rule: root=User quota 
mailbox=Trash bytes=+858993459 (20%) messages=0
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: Quota rule: root=User quota 
mailbox=Junk bytes=+858993459 (20%) messages=0
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: dict quota: user=lists, 
uri=proxy::quota, noenforcing=0
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: Namespace : type=private, 
prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes 
location=mdbox:/var/spool/virtualmailboxes/lists
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: fs: 
root=/var/spool/virtualmailboxes/lists, index=, control=, inbox=
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: Namespace : Using permissions 
from /var/spool/virtualmailboxes/lists: mode=0700 gid=-1
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: Namespace : type=shared, 
prefix=shared/%u/, sep=/, inbox=no, hidden=no, list=children, subscriptions=no 
location=maildir:%h/
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: shared: 
root=/usr/var/run/dovecot, index=, control=, inbox=
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: Namespace : type=public, 
prefix=Public/, sep=/, inbox=no, hidden=no, list=yes, subscriptions=yes 
location=mdbox:/var/spool/virtualmailboxes//public
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: fs: 
root=/var/spool/virtualmailboxes//public, index=, control=, inbox=
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: Namespace Public/: Using 
permissions from /var/spool/virtualmailboxes//public: mode=0700 gid=-1
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: Quota root: name=User quota 
backend=dict args=:proxy::quota
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: Quota rule: root=User quota 
mailbox=* bytes=1073741824 messages=100000
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: Quota rule: root=User quota 
mailbox=Trash bytes=+214748364 (20%) messages=0
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: Quota rule: root=User quota 
mailbox=Junk bytes=+214748364 (20%) messages=0
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: dict quota: 
user=li...@example.com, uri=proxy::quota, noenforcing=0
Jan 25 18:03:09 milly dovecot: lda(lists): Debug: none: root=, index=, 
control=, inbox=

I can provide my doveconf -n output and any other info you may need.

Thanks
-Matt



Attachment: smime.p7s
Description: S/MIME Cryptographic Signature

Reply via email to