Gregor Maier
2007-07-18 15:41:48 UTC
Hello,
I came across an issue with postfix using ldap and virtual domains and
mailboxes. When the LDAP server is down, smtpd cannot resolve
addresses etc. using trivial-rewrite. If the ldap server is up,
everything works fine.
Example:
After smtpd received the MAIL FROM command, it tries to lookup the
associated address, but since ldap is down, trivial-rewrite cannot
resolve the address and exits. Smtpd (resp. the resolver resolve_clnt())
will try again and again and again. This also means, that the smtpd
does not send any answer to its client. I.e. the client sends the
MAIL FROM and then nothing happens. Eventually the smtp connection
might timeout.
IMHO the smtpd should return a temporary error (4xx) when lookups fail
and smtpd should not loop trying to resolve the address. Yes, one can
use backup ldap servers, etc. but nevertheless, if the database is not
responding smtpd should handle the situation gracefully!
Gathering from other mails this problem occurs whenever an external
database (ldap, mysql, psql, etc.) is used and the database is down.
What I gathered from the source code, fixing this problem might not
be trivial. It looks like, that resolv_clnt() is used by various
parts of postfix (local, etc.). For smtpd, resolv_clnt() could just
break the loop after a limited number of iterations and send a
temporary 4xx error to its peer. But I'm not sure if this might
break local delivery or other parts that use resolv_clnt().
Ideas?
Comments?
Here's my mail.log for the event. smtpd is run with -vv
------- /var/log/mail.log, smtpd run with -vv ------
Jul 18 15:04:26 mailtest postfix/smtpd[14594]: extract_addr: input: <***@fs.tum.de>
Jul 18 15:04:26 mailtest postfix/smtpd[14594]: smtpd_check_addr: addr=***@fs.tum.de
Jul 18 15:04:26 mailtest postfix/smtpd[14594]: connect to subsystem private/rewrite
Jul 18 15:04:26 mailtest postfix/smtpd[14594]: send attr request = rewrite
Jul 18 15:04:26 mailtest postfix/smtpd[14594]: send attr rule = local
Jul 18 15:04:26 mailtest postfix/smtpd[14594]: send attr address = ***@fs.tum.de
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: private/rewrite socket: wanted attribute: flags
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: input attribute name: flags
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: input attribute value: 0
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: private/rewrite socket: wanted attribute: address
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: input attribute name: address
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: input attribute value: ***@fs.tum.de
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: private/rewrite socket: wanted attribute: (list terminator)
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: input attribute name: (end)
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: rewrite_clnt: local: ***@fs.tum.de -> ***@fs.tum.de
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: send attr request = resolve
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: send attr sender =
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: send attr address = ***@fs.tum.de
Jul 18 15:04:35 mailtest postfix/trivial-rewrite[14596]: warning: dict_ldap_connect: Unable to bind to server ldap://[LDAP-SERVER-NAME]:389 as : 81 (Can't contact LDAP server)
Jul 18 15:04:35 mailtest postfix/trivial-rewrite[14596]: fatal: ldap:/etc/postfix/virtual_aliases.ldap(0,lock|fold_fix): table lookup proble
m
Jul 18 15:04:36 mailtest postfix/smtpd[14594]: warning: problem talking to service rewrite: Success
Jul 18 15:04:36 mailtest postfix/master[14587]: warning: process /usr/lib/postfix/trivial-rewrite pid 14596 exit status 1
Jul 18 15:04:37 mailtest postfix/smtpd[14594]: rewrite stream disconnect
Jul 18 15:04:37 mailtest postfix/smtpd[14594]: connect to subsystem private/rewrite
Jul 18 15:04:37 mailtest postfix/smtpd[14594]: send attr request = resolve
Jul 18 15:04:37 mailtest postfix/smtpd[14594]: send attr sender =
Jul 18 15:04:37 mailtest postfix/smtpd[14594]: send attr address = ***@fs.tum.de
Jul 18 15:04:46 mailtest postfix/trivial-rewrite[14597]: warning: dict_ldap_connect: Unable to bind to server ldap://[LDAP-SERVER-NAME]:389 as : 81 (Can't contact LDAP server)
Jul 18 15:04:46 mailtest postfix/trivial-rewrite[14597]: fatal: ldap:/etc/postfix/virtual_aliases.ldap(0,lock|fold_fix): table lookup proble
m
Jul 18 15:04:47 mailtest postfix/smtpd[14594]: warning: problem talking to service rewrite: Success
Jul 18 15:04:47 mailtest postfix/master[14587]: warning: process /usr/lib/postfix/trivial-rewrite pid 14597 exit status 1
Jul 18 15:04:47 mailtest postfix/master[14587]: warning: /usr/lib/postfix/trivial-rewrite: bad command startup -- throttling
-------------------------------
cu
Gregor
I came across an issue with postfix using ldap and virtual domains and
mailboxes. When the LDAP server is down, smtpd cannot resolve
addresses etc. using trivial-rewrite. If the ldap server is up,
everything works fine.
Example:
After smtpd received the MAIL FROM command, it tries to lookup the
associated address, but since ldap is down, trivial-rewrite cannot
resolve the address and exits. Smtpd (resp. the resolver resolve_clnt())
will try again and again and again. This also means, that the smtpd
does not send any answer to its client. I.e. the client sends the
MAIL FROM and then nothing happens. Eventually the smtp connection
might timeout.
IMHO the smtpd should return a temporary error (4xx) when lookups fail
and smtpd should not loop trying to resolve the address. Yes, one can
use backup ldap servers, etc. but nevertheless, if the database is not
responding smtpd should handle the situation gracefully!
Gathering from other mails this problem occurs whenever an external
database (ldap, mysql, psql, etc.) is used and the database is down.
What I gathered from the source code, fixing this problem might not
be trivial. It looks like, that resolv_clnt() is used by various
parts of postfix (local, etc.). For smtpd, resolv_clnt() could just
break the loop after a limited number of iterations and send a
temporary 4xx error to its peer. But I'm not sure if this might
break local delivery or other parts that use resolv_clnt().
Ideas?
Comments?
Here's my mail.log for the event. smtpd is run with -vv
------- /var/log/mail.log, smtpd run with -vv ------
Jul 18 15:04:26 mailtest postfix/smtpd[14594]: extract_addr: input: <***@fs.tum.de>
Jul 18 15:04:26 mailtest postfix/smtpd[14594]: smtpd_check_addr: addr=***@fs.tum.de
Jul 18 15:04:26 mailtest postfix/smtpd[14594]: connect to subsystem private/rewrite
Jul 18 15:04:26 mailtest postfix/smtpd[14594]: send attr request = rewrite
Jul 18 15:04:26 mailtest postfix/smtpd[14594]: send attr rule = local
Jul 18 15:04:26 mailtest postfix/smtpd[14594]: send attr address = ***@fs.tum.de
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: private/rewrite socket: wanted attribute: flags
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: input attribute name: flags
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: input attribute value: 0
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: private/rewrite socket: wanted attribute: address
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: input attribute name: address
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: input attribute value: ***@fs.tum.de
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: private/rewrite socket: wanted attribute: (list terminator)
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: input attribute name: (end)
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: rewrite_clnt: local: ***@fs.tum.de -> ***@fs.tum.de
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: send attr request = resolve
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: send attr sender =
Jul 18 15:04:32 mailtest postfix/smtpd[14594]: send attr address = ***@fs.tum.de
Jul 18 15:04:35 mailtest postfix/trivial-rewrite[14596]: warning: dict_ldap_connect: Unable to bind to server ldap://[LDAP-SERVER-NAME]:389 as : 81 (Can't contact LDAP server)
Jul 18 15:04:35 mailtest postfix/trivial-rewrite[14596]: fatal: ldap:/etc/postfix/virtual_aliases.ldap(0,lock|fold_fix): table lookup proble
m
Jul 18 15:04:36 mailtest postfix/smtpd[14594]: warning: problem talking to service rewrite: Success
Jul 18 15:04:36 mailtest postfix/master[14587]: warning: process /usr/lib/postfix/trivial-rewrite pid 14596 exit status 1
Jul 18 15:04:37 mailtest postfix/smtpd[14594]: rewrite stream disconnect
Jul 18 15:04:37 mailtest postfix/smtpd[14594]: connect to subsystem private/rewrite
Jul 18 15:04:37 mailtest postfix/smtpd[14594]: send attr request = resolve
Jul 18 15:04:37 mailtest postfix/smtpd[14594]: send attr sender =
Jul 18 15:04:37 mailtest postfix/smtpd[14594]: send attr address = ***@fs.tum.de
Jul 18 15:04:46 mailtest postfix/trivial-rewrite[14597]: warning: dict_ldap_connect: Unable to bind to server ldap://[LDAP-SERVER-NAME]:389 as : 81 (Can't contact LDAP server)
Jul 18 15:04:46 mailtest postfix/trivial-rewrite[14597]: fatal: ldap:/etc/postfix/virtual_aliases.ldap(0,lock|fold_fix): table lookup proble
m
Jul 18 15:04:47 mailtest postfix/smtpd[14594]: warning: problem talking to service rewrite: Success
Jul 18 15:04:47 mailtest postfix/master[14587]: warning: process /usr/lib/postfix/trivial-rewrite pid 14597 exit status 1
Jul 18 15:04:47 mailtest postfix/master[14587]: warning: /usr/lib/postfix/trivial-rewrite: bad command startup -- throttling
-------------------------------
cu
Gregor