[Dovecot] deliver stopped working
vwc72283 at voicenet.com
vwc72283 at voicenet.com
Sun Oct 4 05:45:04 EEST 2009
Hi:
I have been using Dovecot for well over a year now and it has always worked with few
problems. The mail setup is not simple...
Postfix+MailScanner+ClamAV+Docvecot+MySql+postfix.admin... just to mention the major
things. The system is CentOS 5.3 on VMware. The maildir is on an NFS share, index and
control is local.
About a month ago I thought I upgraded from 1.1.x to 1.2.x. by doing an rpmbuild and
deploying. I say thought because today I determined the binaries were still 1.1x. Today
a reboot was done after a kernel upgrade (2.6.18-128.x -> 2.6.18-164). The mail system
never came back up. My assumption is that the working binaries were in memory but the
images on disk were changed.
Anyway, the problem is with deliver writing to the mail dir. The error is:
Oct 3 21:33:58 myserver dovecot: auth(default): master in: USER 1
myaccount at mydomain.net service=deliver
Oct 3 21:33:58 myserver dovecot: auth(default): prefetch(myaccount at mydomain.net):
passdb didn't return userdb entries, trying the next userdb
Oct 3 21:33:58 myserver dovecot: auth-worker(default): sql(myaccount at mydomain.net):
SELECT '/home/vmail/mydomain.net/myaccount' as home,
'maildir:/home/vmail/mydomain.net/myaccount:INDEX=/var/indexes/mydomain.net/myaccount:CONTROL=/var/indexes/mydomain.net/myaccount'
as mail, 5000 AS uid, 5000 AS gid, concat('dirsize:storage=', quota) AS quota FROM
mailbox WHERE username = 'myaccount at mydomain.net' AND active = '1' Oct 3 21:33:58
myserver dovecot: auth(default): master out: USER 1 myaccount at mydomain.net
home=/home/vmail/mydomain.net/myaccount
mail=maildir:/home/vmail/mydomain.net/myaccount:INDEX=/var/indexes/mydomain.net/myaccount:CONTROL=/var/indexes/mydomain.net/myaccount
uid=5000 gid=5000 quota=dirsize:storage=0
Oct 3 21:33:58 myserver dovecot: deliver(myaccount at mydomain.net): auth input:
home=/home/vmail/mydomain.net/myaccount
Oct 3 21:33:58 myserver dovecot: deliver(myaccount at mydomain.net): auth input:
mail=maildir:/home/vmail/mydomain.net/myaccount:INDEX=/var/indexes/mydomain.net/myaccount:CONTROL=/var/indexes/mydomain.net/myaccount
Oct 3 21:33:58 myserver dovecot: deliver(myaccount at mydomain.net): auth input: uid=5000
Oct 3 21:33:58 myserver dovecot: deliver(myaccount at mydomain.net): auth input: gid=5000
Oct 3 21:33:58 myserver dovecot: deliver(myaccount at mydomain.net): auth input:
quota=dirsize:storage=0
Oct 3 21:33:58 myserver dovecot: deliver(myaccount at mydomain.net): maildir:
data=/home/vmail/mydomain.net/myaccount:INDEX=/var/indexes/mydomain.net/myaccount:CONTROL=/var/indexes/mydomain.net/myaccount
Oct 3 21:33:58 myserver dovecot: deliver(myaccount at mydomain.net): maildir++:
root=/home/vmail/mydomain.net/myaccount, index=/var/indexes/mydomain.net/myaccount,
control=/var/indexes/mydomain.net/myaccount, inbox=/home/vmail/mydomain.net/myaccount
Oct 3 21:33:58 myserver dovecot: deliver(myaccount at mydomain.net): Namespace : Using
permissions from /home/vmail/mydomain.net/myaccount: mode=0770 gid=-1 Oct 3 21:33:58
myserver dovecot: deliver(myaccount at mydomain.net):
open(/home/vmail/mydomain.net/myaccount/tmp/1254620038.M241510P27678.myserver.mydomain.net)
failed: Permission denied
Oct 3 21:33:58 myserver dovecot: deliver(myaccount at mydomain.net):
msgid=<200910040116.n941GjtJ001913 at nm2srvp01.mydomain.net>: save failed to INBOX:
Internal error occurred. Refer to server log for more information. [2009-10-03 21:33:58]
Oct 3 21:33:58 myserver postfix/pipe[27677]: 89A24914CB: to=<myaccount at mydomain.net>,
orig_to=<server.ops at mydomain.net>, relay=dovecot, delay=1033, delays=1032/0.16/0/0.31,
dsn=4.3.0, status=deferred (temporary failure)
The files are being created:
(root at myserver:/home/vmail/mydomain.net/myaccount/tmp)# ls -la
total 156
drwxrwx--- 2 vmail vmail 4096 Oct 3 21:49 .
drwxrwx--- 9 vmail vmail 4096 Oct 3 20:19 ..
---------- 1 vmail vmail 0 Nov 30 1970 1254620038.M241510P27678.myserver.mydomain.net
The user does have permission:
(root at myserver:/home/vmail/mydomain.net/myaccount/tmp)# su - vmail -bash-3.2$ pwd
/home/vmail/mydomain.net/myaccount/tmp
-bash-3.2$ ls -la
total 160
drwxrwx--- 2 vmail vmail 4096 Oct 3 21:54 .
drwxrwx--- 9 vmail vmail 4096 Oct 3 20:19 ..
---------- 1 vmail vmail 0 Nov 30 1970
1254620038.M241510P27678.myserver.mydomain.net -bash-3.2$ rm
1254620038.M241510P27678.myserver.mydomain.net
rm: remove write-protected regular empty file
`1254620038.M241510P27678.myserver.mydomain.net'? y
-bash-3.2$ echo this > 1254620038.M241510P27678.myserver.mydomain.net -bash-3.2$ ls -la
1254620038.M241510P27678.myserver.mydomain.net
-rw-r--r-- 1 vmail vmail 5 Oct 3 21:58 1254620038.M241510P27678.myserver.mydomain.net
-bash-3.2$ cat 1254620038.M241510P27678.myserver.mydomain.net
this
-bash-3.2$ rm 1254620038.M241510P27678.myserver.mydomain.net
-bash-3.2$
If you delete the directory it does get recreated. I upgraded to 1.2.5 but it did not
help. There were a lot of errors in the audit.log, however SELinux was already in
permissive mode and switching it to disabled did no good. I created the following policy
to get rid of all of the errors in the audit log:
module local_postfix 1.0;
require {
type postfix_etc_t;
type home_root_t;
type apmd_t;
type setrans_t;
type port_t;
type etc_mail_t;
type snmpd_t;
type tmp_t;
type dovecot_deliver_t;
type postfix_smtp_t;
type nfs_t;
type var_run_t;
type usr_t;
type httpd_t;
type audisp_t;
type postfix_cleanup_t;
type inetd_t;
type portmap_t;
type postfix_pickup_t;
type hald_t;
type getty_t;
type avahi_t;
type etc_t;
type sysctl_kernel_t;
type unconfined_t;
type init_t;
type auditd_t;
type lib_t;
type dovecot_auth_t;
type syslogd_t;
type hostname_exec_t;
type postfix_smtpd_t;
type var_spool_t;
type system_dbusd_t;
type mysqld_etc_t;
type initrc_t;
type proc_t;
type restorecond_t;
type etc_runtime_t;
type postfix_bounce_t;
type ntpd_t;
type kernel_t;
type postfix_master_t;
type rpcd_t;
type dovecot_t;
type klogd_t;
type udev_t;
type clamd_t;
type mysqld_port_t;
type initrc_var_run_t;
type var_t;
type postfix_qmgr_t;
type postfix_pipe_t;
type crond_t;
class process ptrace;
class unix_stream_socket connectto;
class tcp_socket { name_bind name_connect };
class file { rename execute read lock create ioctl execute_no_trans write getattr link
unlink };
class sock_file { setattr create write getattr unlink };
class lnk_file { read getattr };
class dir { search setattr read create write getattr remove_name add_name };
}
#============= clamd_t ==============
allow clamd_t proc_t:file { read getattr };
allow clamd_t sysctl_kernel_t:dir search;
allow clamd_t sysctl_kernel_t:file read;
allow clamd_t var_t:dir read;
allow clamd_t var_t:file { read getattr };
#============= dovecot_auth_t ==============
allow dovecot_auth_t mysqld_etc_t:file { read getattr };
allow dovecot_auth_t mysqld_port_t:tcp_socket name_connect;
allow dovecot_auth_t var_run_t:dir { write remove_name add_name }; allow dovecot_auth_t
var_run_t:sock_file { write create unlink setattr };
#============= dovecot_deliver_t ==============
allow dovecot_deliver_t nfs_t:dir { write search add_name create getattr }; allow
dovecot_deliver_t nfs_t:file create;
allow dovecot_deliver_t postfix_master_t:file read;
allow dovecot_deliver_t postfix_pipe_t:file read;
allow dovecot_deliver_t var_run_t:sock_file write;
allow dovecot_deliver_t var_t:file { read write getattr lock };
#============= dovecot_t ==============
allow dovecot_t initrc_var_run_t:file read;
allow dovecot_t lib_t:dir { write create add_name };
allow dovecot_t lib_t:file create;
allow dovecot_t nfs_t:dir { write search read remove_name create add_name }; allow
dovecot_t nfs_t:file { read rename getattr unlink link };
allow dovecot_t var_run_t:sock_file { write getattr unlink create setattr }; allow
dovecot_t var_t:dir { write remove_name add_name setattr };
allow dovecot_t var_t:file { rename write getattr read lock create unlink };
#============= httpd_t ==============
allow httpd_t apmd_t:dir { getattr search };
allow httpd_t apmd_t:file read;
allow httpd_t audisp_t:dir { getattr search };
allow httpd_t audisp_t:file read;
allow httpd_t auditd_t:dir { getattr search };
allow httpd_t auditd_t:file read;
allow httpd_t avahi_t:dir { getattr search };
allow httpd_t avahi_t:file read;
allow httpd_t clamd_t:dir { getattr search };
allow httpd_t clamd_t:file read;
allow httpd_t crond_t:dir { getattr search };
allow httpd_t crond_t:file read;
allow httpd_t dovecot_auth_t:dir { getattr search };
allow httpd_t dovecot_auth_t:file read;
allow httpd_t dovecot_t:dir { getattr search };
allow httpd_t dovecot_t:file read;
allow httpd_t etc_mail_t:dir { read search getattr };
allow httpd_t etc_mail_t:file { read getattr ioctl };
allow httpd_t etc_mail_t:lnk_file read;
allow httpd_t etc_runtime_t:file { write rename unlink };
allow httpd_t etc_t:dir { write remove_name add_name };
allow httpd_t getty_t:dir { getattr search };
allow httpd_t getty_t:file read;
allow httpd_t hald_t:dir { getattr search };
allow httpd_t hald_t:file read;
allow httpd_t hostname_exec_t:file { read getattr execute execute_no_trans }; allow
httpd_t inetd_t:dir { getattr search };
allow httpd_t inetd_t:file read;
allow httpd_t init_t:dir { getattr search };
allow httpd_t init_t:file read;
allow httpd_t initrc_t:dir { getattr search };
allow httpd_t initrc_t:file read;
allow httpd_t kernel_t:dir { getattr search };
allow httpd_t kernel_t:file read;
allow httpd_t klogd_t:dir { getattr search };
allow httpd_t klogd_t:file read;
allow httpd_t mysqld_port_t:tcp_socket name_connect;
allow httpd_t ntpd_t:dir { getattr search };
allow httpd_t ntpd_t:file read;
allow httpd_t port_t:tcp_socket name_bind;
allow httpd_t portmap_t:dir { getattr search };
allow httpd_t portmap_t:file read;
allow httpd_t postfix_bounce_t:dir { getattr search };
allow httpd_t postfix_bounce_t:file read;
allow httpd_t postfix_cleanup_t:dir { getattr search };
allow httpd_t postfix_cleanup_t:file read;
allow httpd_t postfix_master_t:dir { getattr search };
allow httpd_t postfix_master_t:file read;
allow httpd_t postfix_pickup_t:dir { getattr search };
allow httpd_t postfix_pickup_t:file read;
allow httpd_t postfix_pipe_t:dir { getattr search };
allow httpd_t postfix_pipe_t:file read;
allow httpd_t postfix_qmgr_t:dir { getattr search };
allow httpd_t postfix_qmgr_t:file read;
allow httpd_t postfix_smtp_t:dir { getattr search };
allow httpd_t postfix_smtp_t:file read;
allow httpd_t postfix_smtpd_t:dir { getattr search };
allow httpd_t postfix_smtpd_t:file read;
allow httpd_t restorecond_t:dir { getattr search };
allow httpd_t restorecond_t:file read;
allow httpd_t rpcd_t:dir { getattr search };
allow httpd_t rpcd_t:file read;
allow httpd_t self:process ptrace;
allow httpd_t setrans_t:dir { getattr search };
allow httpd_t setrans_t:file read;
allow httpd_t snmpd_t:dir { getattr search };
allow httpd_t snmpd_t:file read;
allow httpd_t syslogd_t:dir { getattr search };
allow httpd_t syslogd_t:file read;
allow httpd_t system_dbusd_t:dir { getattr search };
allow httpd_t system_dbusd_t:file read;
allow httpd_t udev_t:dir { getattr search };
allow httpd_t udev_t:file read;
allow httpd_t unconfined_t:dir { getattr search };
allow httpd_t unconfined_t:file read;
allow httpd_t var_spool_t:dir { read write remove_name };
allow httpd_t var_spool_t:file { read getattr unlink ioctl };
allow httpd_t var_t:file { read write getattr lock };
#============= postfix_master_t ==============
allow postfix_master_t postfix_etc_t:lnk_file getattr;
#============= postfix_pipe_t ==============
allow postfix_pipe_t home_root_t:dir search;
allow postfix_pipe_t initrc_t:unix_stream_socket connectto;
allow postfix_pipe_t nfs_t:dir { write search add_name create getattr }; allow
postfix_pipe_t nfs_t:file create;
allow postfix_pipe_t tmp_t:dir search;
allow postfix_pipe_t usr_t:file { read execute execute_no_trans }; allow postfix_pipe_t
var_run_t:sock_file write;
allow postfix_pipe_t var_t:file { read write getattr lock };
#============= postfix_smtpd_t ==============
allow postfix_smtpd_t initrc_t:unix_stream_socket connectto;
...so now the audit.log is clean but no matter what I've tried I can't get deliver to
deliver messages to the inboxes.
Some of the system details:
(root at myserver:/etc/dovecot)# dovecot -c /etc/dovecot/dovecot.conf -n # 1.2.5:
/etc/dovecot/dovecot.conf
# OS: Linux 2.6.18-164.el5 i686 CentOS release 5.3 (Final)
base_dir: /var/run/dovecot/
log_timestamp: ¦%Y-%m-%d %H:%M:%S ¦
listen: 127.0.0.1:143
ssl_listen: *:993
ssl_ca_file: /etc/pki/mydomain/mailserver/certs/class3.crt
ssl_cert_file: /etc/pki/mydomain/mailserver/certs/myserver.mydomain.net.crt
ssl_key_file: /etc/pki/mydomain/mailserver/private/myserver.mydomain.net.key
verbose_ssl: yes
login_dir: /var/run/dovecot//login
login_executable: /usr/libexec/dovecot/imap-login
verbose_proctitle: yes
first_valid_uid: 5000
last_valid_uid: 5000
mail_access_groups: vmail
mail_location: maildir:/var/vmail/%d/%u:INDEX=/var/indexes/%d/%n
mail_debug: yes
mail_nfs_storage: yes
mbox_read_locks: dotlock
mbox_write_locks: dotlock
mail_executable: /usr/libexec/dovecot/imap
imap_client_workarounds: outlook-idle, tb-extra-mailbox-sep
lda:
postmaster_address: postmaster at mydomain.net
sendmail_path: /usr/lib/sendmail
auth_socket_path: /var/run/dovecot/auth-master
auth_executable: /usr/libexec/dovecot/dovecot-auth
auth default:
user: nobody
verbose: yes
debug: yes
passdb:
driver: sql
args: /etc/dovecot/dovecot-sql.conf
userdb:
driver: prefetch
userdb:
driver: sql
args: /etc/dovecot/dovecot-sql.conf
socket:
type: listen
client:
path: /var/spool/postfix/private/auth
mode: 432
user: postfix
group: postfix
master:
path: /var/run/dovecot/auth-master
mode: 432
user: vmail
group: vmail
(root at myserver:/etc/dovecot)# grep -v '^ *\(#.*\)\?$' dovecot-sql.conf driver = mysql
connect = host=mydatabaseserver.mydomain.net dbname=mydatabasename user=mydovecotuser
password=**********
default_pass_scheme = MD5
user_query = SELECT '/home/vmail/%d/%n' as home,
'maildir:/home/vmail/%d/%n:INDEX=/var/indexes/%d/%n:CONTROL=/var/indexes/%d/%n' as mail,
5000 AS uid, 5000 AS gid, concat('dirsize:storage=', quota) AS quota FROM mailbox WHERE
username = '%u' AND active = '1'
password_query = SELECT password FROM mailbox WHERE username = '%u' AND active = '1'
(root at ms1srvp01:/etc/dovecot)# ps -ef
UID PID PPID C STIME TTY TIME CMD
clamav 2138 1 0 12:49 ? 00:00:06 clamd
root 26744 1 0 21:03 ? 00:00:00 /usr/sbin/dovecot -c
/etc/dovecot/dovecot.conf
nobody 26745 26744 0 21:03 ? 00:00:00 dovecot-auth
nobody 26747 26744 0 21:03 ? 00:00:00 dovecot-auth -w
dovecot 26748 26744 0 21:03 ? 00:00:00 imap-login
dovecot 26749 26744 0 21:03 ? 00:00:00 imap-login
dovecot 26750 26744 0 21:03 ? 00:00:00 imap-login
root 26888 1 0 21:03 ? 00:00:00 /usr/libexec/postfix/master postfix
26889 26888 0 21:03 ? 00:00:00 qmgr -l -t fifo -u postfix 26890 26888 0 21:03
? 00:00:00 pickup -l -t fifo -u postfix 26910 1 0 21:03 ? 00:00:00
MailScanner: master waiting for children, sleeping
postfix 26911 26910 0 21:03 ? 00:00:03 MailScanner: waiting for messages
postfix 26915 1 0 21:03 ? 00:00:00 MailWatch SQL
postfix 26918 26910 0 21:03 ? 00:00:03 MailScanner: waiting for messages
postfix 26923 26910 0 21:04 ? 00:00:03 MailScanner: waiting for messages
postfix 26934 26910 0 21:04 ? 00:00:03 MailScanner: waiting for messages
postfix 26939 26910 0 21:04 ? 00:00:03 MailScanner: waiting for messages
postfix 26950 26888 0 21:04 ? 00:00:00 tlsmgr -l -t unix -u nobody 27002
26744 0 21:08 ? 00:00:00 dovecot-auth -w
vmail 27035 26744 0 21:09 ? 00:00:01 imap [myaccount at mydomain.net
192.168.2.151] vmail 27036 26744 0 21:09 ? 00:00:01 imap
[myotheraccount1 at myotherdomain.com 192.168.2.151]
vmail 27037 26744 0 21:09 ? 00:00:01 imap [myaccount at mydomain.com
192.168.2.151] dovecot 27038 26744 0 21:09 ? 00:00:00 imap-login
dovecot 27039 26744 0 21:09 ? 00:00:00 imap-login
dovecot 27040 26744 0 21:09 ? 00:00:00 imap-login
dovecot 27041 26744 0 21:09 ? 00:00:00 imap-login
dovecot 27042 26744 0 21:09 ? 00:00:00 imap-login
dovecot 27043 26744 0 21:09 ? 00:00:00 imap-login
vmail 27044 26744 0 21:09 ? 00:00:01 imap [myotheraccount2 at myotherdomain.com
192.168.2.151]
nobody 28288 26744 0 22:09 ? 00:00:00 dovecot-auth -w
nobody 28292 26744 0 22:09 ? 00:00:00 dovecot-auth -w
postfix 28938 26888 0 22:19 ? 00:00:00 pipe -n dovecot -t unix flags=DRhu
user=vmail vmail argv=/usr/libexec/dovecot/deliver -c /etc/dovecot/dovecot.conf -f
${sender} -d ${recipient}
postfix 28672 26888 0 22:19 ? 00:00:00 bounce -z -n defer -t unix -u
ONLY RELEVENT ENTRIES
(root at ms1srvp01:~)# lsof | grep 28938
pipe 28938 postfix cwd DIR 253,0 4096 425985
/var/spool/postfix pipe 28938 postfix rtd DIR 253,0 4096
2 / pipe 28938 postfix txt REG 253,0 241092 589991
/usr/libexec/postfix/pipe
pipe 28938 postfix mem REG 253,0 99028 210032
/usr/lib/libsasl2.so.2.0.22
pipe 28938 postfix mem REG 253,0 46680 394117
/lib/libnss_files-2.5.so
pipe 28938 postfix mem REG 253,0 33680 210024
/usr/lib/libkrb5support.so.0.1
pipe 28938 postfix mem REG 253,0 190712 210027
/usr/lib/libgssapi_krb5.so.2.2
pipe 28938 postfix mem REG 253,0 610836 210026
/usr/lib/libkrb5.so.3.3
pipe 28938 postfix mem REG 253,0 157304 210025
/usr/lib/libk5crypto.so.3.1
pipe 28938 postfix mem REG 253,0 1009712 395616
/lib/libdb-4.3.so pipe 28938 postfix mem REG 253,0 1452412
492061 /usr/lib/mysql/libmysqlclient.so.15.0.0
pipe 28938 postfix mem REG 253,0 53756 207273
/usr/lib/liblber-2.3.so.0.2.31
pipe 28938 postfix mem REG 253,0 1296900 393267
/lib/libcrypto.so.0.9.8e
pipe 28938 postfix mem REG 253,0 286748 393429
/lib/libssl.so.0.9.8e
pipe 28938 postfix mem REG 253,0 240584 203611
/usr/lib/libldap-2.3.so.0.2.31
pipe 28938 postfix mem REG 253,0 125736 393228 /lib/ld-2.5.so
pipe 28938 postfix mem REG 253,0 1606812 394139 /lib/libc-2.5.so
pipe 28938 postfix mem REG 253,0 16428 394142
/lib/libdl-2.5.so pipe 28938 postfix mem REG 253,0 242880
394174 /lib/libsepol.so.1 pipe 28938 postfix mem REG 253,0 93508
394176 /lib/libselinux.so.1
pipe 28938 postfix mem REG 253,0 125612 394153
/lib/libpthread-2.5.so
pipe 28938 postfix mem REG 253,0 208352 394166 /lib/libm-2.5.so
pipe 28938 postfix mem REG 253,0 75028 210017
/usr/lib/libz.so.1.2.3
pipe 28938 postfix mem REG 253,0 45288 394144
/lib/libcrypt-2.5.so
pipe 28938 postfix mem REG 253,0 101404 395613
/lib/libnsl-2.5.so pipe 28938 postfix mem REG 253,0 76400
395609 /lib/libresolv-2.5.so
pipe 28938 postfix mem REG 253,0 7748 395610
/lib/libcom_err.so.2.1
pipe 28938 postfix mem REG 253,0 7880 395608
/lib/libkeyutils-1.2.so
pipe 28938 postfix 0u CHR 1,3 1482 /dev/null pipe
28938 postfix 1u CHR 1,3 1482 /dev/null pipe
28938 postfix 2u CHR 1,3 1482 /dev/null pipe 28938
postfix 3r FIFO 0,6 236941 pipe pipe 28938 postfix
4w FIFO 0,6 236941 pipe pipe 28938 postfix 5u unix
0xc4edeb80 236939 socket pipe 28938 postfix 6u unix
0xc4ede980 236936 private/dovecot pipe 28938 postfix 7u unix
0xc2f27c80 255271 socket pipe 28938 postfix 8u REG
253,0 0 491707 /var/spool/postfix/pid/unix.dovecot
pipe 28938 postfix 9u unix 0xc2f27080 255281 socket pipe
28938 postfix 10r 0000 0,11 0 255283 eventpoll pipe 28938
postfix 13r 0000 0,11 0 236827 eventpoll
If anyone has an idea what to look at next it would be appreciated.
Thanks,
-Ted-
More information about the dovecot
mailing list