Its the O_EXCL in the open call! How can I make it not use O_EXCL?

Thanks,

-Ted-

strace.out.6700:open("/home/vmail/mydomain.net/myaccount/tmp/1254635441.M259070P6700.myserver.mydomain.net", O_WRONLY|O_CREAT|O_EXCL|O_TRUNC|O_LARGEFILE, 0777) = -1 EACCES (Permission denied)

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@mydomain.net service=deliver Oct 3 21:33:58 myserver dovecot: auth(default): prefetch(myaccount@mydomain.net): passdb didn't return userdb entries, trying the next userdb Oct 3 21:33:58 myserver dovecot: auth-worker(default): sql(myaccount@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@mydomain.net' AND active = '1' Oct 3 21:33:58 myserver dovecot: auth(default): master out: USER 1 myaccount@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@mydomain.net): auth input: home=/home/vmail/mydomain.net/myaccount Oct 3 21:33:58 myserver dovecot: deliver(myaccount@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@mydomain.net): auth input: uid=5000 Oct 3 21:33:58 myserver dovecot: deliver(myaccount@mydomain.net): auth input: gid=5000 Oct 3 21:33:58 myserver dovecot: deliver(myaccount@mydomain.net): auth input: quota=dirsize:storage=0 Oct 3 21:33:58 myserver dovecot: deliver(myaccount@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@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@mydomain.net): Namespace : Using permissions from /home/vmail/mydomain.net/myaccount: mode=0770 gid=-1 Oct 3 21:33:58 myserver dovecot: deliver(myaccount@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@mydomain.net): msgid=<200910040116.n941GjtJ001913@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@mydomain.net>, orig_to=<server.ops@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@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@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@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@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@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@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@mydomain.net 192.168.2.151] vmail 27036 26744 0 21:09 ? 00:00:01 imap [myotheraccount1@myotherdomain.com 192.168.2.151] vmail 27037 26744 0 21:09 ? 00:00:01 imap [myaccount@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@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@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-