[Dovecot] deliver exits with status 89 on some but not all mails of a batch
Patrick Nagel
patrick.nagel at star-group.net
Tue May 13 15:38:22 EEST 2008
Hi,
I'm trying to get dovecot's LDA 'deliver' to deliver mails that come in through a postfix daemon on the same box. I'm talking
about dovecot version 1.0.rc15 (on CentOS 5 as Linux-VServer guest on a CentOS 5 host).
Configuration
-------------
# /etc/dovecot.conf
ssl_cert_file: /etc/pki/selfmade/server.crt
ssl_key_file: /etc/pki/selfmade/server.key
login_dir: /var/run/dovecot/login
login_executable(default): /usr/libexec/dovecot/imap-login
login_executable(imap): /usr/libexec/dovecot/imap-login
login_executable(pop3): /usr/libexec/dovecot/pop3-login
verbose_proctitle: yes
mail_extra_groups: mail
mail_location: maildir:~/Maildir
mail_executable(default): /usr/libexec/dovecot/imap
mail_executable(imap): /usr/libexec/dovecot/imap
mail_executable(pop3): /usr/libexec/dovecot/pop3
mail_plugin_dir(default): /usr/lib/dovecot/imap
mail_plugin_dir(imap): /usr/lib/dovecot/imap
mail_plugin_dir(pop3): /usr/lib/dovecot/pop3
auth default:
verbose: yes
passdb:
driver: ldap
args: /etc/dovecot-ldap.conf
userdb:
driver: ldap
args: /etc/dovecot-ldap.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: 384
user: dovecot
group: dovecot
dovecot-ldap.conf looks like this:
uris = ldap://dbserver
dn = cn=dovecot,ou=services,dc=company,dc=net
dnpass = secret
ldap_version = 3
base = ou=people,dc=company,dc=net
scope = onelevel
user_attrs = homeDirectory=home,uidNumber=uid,gidNumber=gid
user_filter = (&(objectClass=posixAccount)(uid=%n))
pass_attrs = uid=user,userPassword=password
pass_filter = (&(objectClass=posixAccount)(uid=%u))
default_pass_scheme = LDAP-MD5
postfix has mailbox_transport set to dovecot, and master.cf contains the following:
dovecot unix - n n - - pipe
flags=DRhu user=fry:fry argv=/usr/libexec/dovecot/lda/deliver -d ${recipient}
Problem
-------
When a lot of mails come in 'at the same time', for example because an employee mailed all other (local) employees, the
following happens: Some mails are being delivered as advertised, but on some mails, deliver exits with status 89 and the message
bounces. Here is a (postfix) log that illustrates the problem. I replaced all receivers with 'xy', but they are in fact all
different.
May 13 17:58:32 mail1 postfix/smtpd[28164]: connect from unknown[192.168.0.103]
May 13 17:58:32 mail1 postfix/smtpd[28164]: 1D6508FD93FF: client=unknown[192.168.0.103]
May 13 17:58:33 mail1 postfix/cleanup[28165]: 1D6508FD93FF: message-id=<200805131758288906193 at company.net>
May 13 17:58:33 mail1 postfix/qmgr[27255]: 1D6508FD93FF: from=<zz at company.net>, size=1613090, nrcpt=31 (queue active)
May 13 17:58:33 mail1 postfix/smtpd[28164]: disconnect from unknown[192.168.0.103]
May 13 17:58:33 mail1 postfix/pipe[28169]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=1.9, delays=1.5/0/0/0.35, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:33 mail1 postfix/pipe[28299]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=1.9, delays=1.5/0.02/0/0.34, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:33 mail1 postfix/pipe[28168]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=1.9, delays=1.5/0/0/0.35, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:33 mail1 postfix/pipe[28298]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=1.9, delays=1.5/0.01/0/0.34, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:34 mail1 postfix/pipe[28362]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=2.7, delays=1.5/0.21/0/0.95, dsn=5.3.0, status=bounced (Command died with status 89: "/usr/libexec/dovecot/lda/deliver")
May 13 17:58:34 mail1 postfix/pipe[28304]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=2.7, delays=1.5/0.1/0/1.1, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:34 mail1 postfix/pipe[28320]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=2.7, delays=1.5/0.13/0/1, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:34 mail1 postfix/pipe[28311]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=2.7, delays=1.5/0.12/0/1, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:34 mail1 postfix/pipe[28313]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=2.7, delays=1.5/0.12/0/1, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:34 mail1 postfix/pipe[28306]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=2.7, delays=1.5/0.11/0/1.1, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:34 mail1 postfix/pipe[28333]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=2.7, delays=1.5/0.14/0/1, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:34 mail1 postfix/pipe[28317]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=2.7, delays=1.5/0.12/0/1.1, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:34 mail1 postfix/pipe[28337]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=2.7, delays=1.5/0.16/0/1, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:34 mail1 postfix/pipe[28342]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=2.8, delays=1.5/0.17/0/1.1, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:34 mail1 postfix/pipe[28368]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=2.9, delays=1.5/0.23/0/1.1, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:35 mail1 postfix/pipe[28364]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=3.1, delays=1.5/0.22/0/1.4, dsn=5.3.0, status=bounced (Command died with status 89: "/usr/libexec/dovecot/lda/deliver")
May 13 17:58:35 mail1 postfix/pipe[28350]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=3.2, delays=1.5/0.19/0/1.5, dsn=5.3.0, status=bounced (Command died with status 89: "/usr/libexec/dovecot/lda/deliver")
May 13 17:58:35 mail1 postfix/pipe[28376]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=3.3, delays=1.5/0.26/0/1.6, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:35 mail1 postfix/pipe[28375]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=3.3, delays=1.5/0.25/0/1.6, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:35 mail1 postfix/pipe[28334]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=3.3, delays=1.5/0.15/0/1.7, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:35 mail1 postfix/pipe[28347]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=3.3, delays=1.5/0.18/0/1.6, dsn=5.3.0, status=bounced (Command died with status 89: "/usr/libexec/dovecot/lda/deliver")
May 13 17:58:35 mail1 postfix/pipe[28372]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=3.3, delays=1.5/0.24/0/1.6, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:35 mail1 postfix/pipe[28355]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=3.5, delays=1.5/0.2/0/1.7, dsn=5.3.0, status=bounced (Command died with status 89: "/usr/libexec/dovecot/lda/deliver")
May 13 17:58:35 mail1 postfix/pipe[28340]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=3.5, delays=1.5/0.17/0/1.8, dsn=2.0.0, status=sent (delivered via dovecot service)
May 13 17:58:36 mail1 postfix/pipe[28366]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=4, delays=1.5/0.23/0/2.2, dsn=5.3.0, status=bounced (Command died with status 89: "/usr/libexec/dovecot/lda/deliver")
May 13 17:58:36 mail1 postfix/pipe[28325]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=4.2, delays=1.5/0.13/0/2.5, dsn=5.3.0, status=bounced (Command died with status 89: "/usr/libexec/dovecot/lda/deliver")
May 13 17:58:36 mail1 postfix/pipe[28323]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=4.2, delays=1.5/0.13/0/2.5, dsn=5.3.0, status=bounced (Command died with status 89: "/usr/libexec/dovecot/lda/deliver")
May 13 17:58:36 mail1 postfix/pipe[28330]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=4.2, delays=1.5/0.14/0/2.5, dsn=5.3.0, status=bounced (Command died with status 89: "/usr/libexec/dovecot/lda/deliver")
May 13 17:58:36 mail1 postfix/pipe[28359]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=4.3, delays=1.5/0.2/0/2.5, dsn=5.3.0, status=bounced (Command died with status 89: "/usr/libexec/dovecot/lda/deliver")
May 13 17:58:36 mail1 postfix/pipe[28354]: 1D6508FD93FF: to=<xy at city.company.net>, orig_to=<xy at company.net>, relay=dovecot,
delay=4.4, delays=1.5/0.19/0/2.6, dsn=5.3.0, status=bounced (Command died with status 89: "/usr/libexec/dovecot/lda/deliver")
May 13 17:58:51 mail1 postfix/smtp[28292]: 1D6508FD93FF: to=<xy at company.net>, relay=10.10.0.1[10.10.0.1]:25, delay=20,
delays=1.5/0.09/1.3/17, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 3E8611881EB)
May 13 17:58:52 mail1 postfix/cleanup[28160]: F0CE98FD9453: message-id=<20080513095851.F0CE98FD9453 at mail1.city.company.net>
May 13 17:58:52 mail1 postfix/qmgr[27255]: F0CE98FD9453: from=<>, size=7408, nrcpt=1 (queue active)
May 13 17:58:52 mail1 postfix/bounce[28379]: 1D6508FD93FF: sender non-delivery notification: F0CE98FD9453
May 13 17:58:52 mail1 postfix/qmgr[27255]: 1D6508FD93FF: removed
Does anybody have an idea what could cause this behaviour? How to debug?
Patrick.
--
STAR Software (Shanghai) Co., Ltd. http://www.star-group.net/
Phone: +86 (21) 5427 7799 x 826 Fax: +86 (21) 6485 0071
PGP key: https://stshacom1.star-china.net/keys/patrick_nagel.asc
Fingerprint: E09A D65E 855F B334 E5C3 5386 EF23 20FC E883 A005
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 189 bytes
Desc: This is a digitally signed message part.
Url : http://dovecot.org/pipermail/dovecot/attachments/20080513/d760c9cf/attachment.bin
More information about the dovecot
mailing list