Re: [Dovecot] Dovecot LDA LDAP lookups on samba4 server ends very often in timeouts (Christian Wiese)
Dear Christian thank you very much - you got it at the very first shot: modified /etc/ openldap/ldap.conf adding REFERRALS off en everything works without issues now many thanks Marco Carcano
[Dovecot] Dovecot LDA LDAP lookups on samba4 server ends very often in timeouts
I hope that someone will be so kind to help me into solving this really strange thing (don't know if it is a bug or not) I have a samba4 server and want to use postfix+dovecot - dovecot version is 2.0.11 as for the postfix side everything is OK (all the LDAP lookups works without any error, tested also manually with postmap -q) the real pain is with dovecot deliver: it seems that sometimes lda tries to lookup to the LDPA (samba 4) server, got a reply, an then report(after 2 minutes) a lookup timeout error the really strange thing is that (very seldom) lda works, but most of the times I got the timeout error. The strange thing is that if I use ldapsearch I never got timeout neither late replies, and even postfix performs its lookups without any issue it seems something related to lda itself (I do not know if I have a wrong configuration, but I think this is not a configuration issue, otherwise it should not work at all) here are the information logged when it does not work - after this log you will find the one when I got the failure (if needed I can provide a .pcap file too) (trailing and leading spaces of AT charcater has been added by me) ## FAULTY DELIVER LOG # Feb 20 12:20:50 sng02 postfix/smtpd[8928]: connect from localhost[127.0.0.1] Feb 20 12:21:14 sng02 postfix/smtpd[8928]: A38D4407F5: client=localhost[127.0.0.1] Feb 20 12:21:20 sng02 postfix/cleanup[8891]: A38D4407F5: warning: header Subject: prova from localhost[127.0.0.1]; from=marco @ senderdomain.tld to=mac @ mydomain.com proto=SMTP helo=senderdomain.tld Feb 20 12:21:20 sng02 postfix/cleanup[8891]: A38D4407F5: message-id=20130220112114.A38D4407F5 @ srv01.mydomain.local Feb 20 12:21:20 sng02 postfix/qmgr[8889]: A38D4407F5: from=marco @ senderdomain.tld, size=371, nrcpt=1 (queue active) Feb 20 12:21:20 sng02 dovecot: lda: Debug: Loading modules from directory: /usr/lib64/dovecot Feb 20 12:21:20 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib10_quota_plugin.so Feb 20 12:21:20 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib20_expire_plugin.so Feb 20 12:21:20 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib90_sieve_plugin.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libauthdb_ldap.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_pgsql.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libmech_gssapi.so Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_bind Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_simple_bind Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_sasl_bind Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_new_connection 1 1 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_open_connection Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_connect_to_host: TCP localhost:389 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_new_socket: 16 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_prepare_socket: 16 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_connect_to_host: Trying ::1 389 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_pvt_connect: fd: 16 tm: -1 async: 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_open_defconn: successful Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_server_request Feb 20 12:21:20 sng02 dovecot: auth: Debug: master in: USER#0111#011marco.carcano#011service=lda Feb 20 12:21:20 sng02 dovecot: auth: Debug: password(marco.carcano): passdb doesn't support credential lookups Feb 20 12:21:20 sng02 dovecot: auth: Error: static(marco.carcano): passdb doesn't support lookups, can't verify user's existence Feb 20 12:21:20 sng02 dovecot: auth: Debug: ldap(marco.carcano): user search: base=DC=mydomain,DC=local scope=subtree filter=(sAMAccountname=marco.carcano) fields=Mailbox,dovecotMailQuota Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_result ld 0x6cba60 msgid -1 Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg ld 0x6cba60 msgid -1 (timeout 0 usec) Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg continue ld 0x6cba60 msgid -1 all 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ** ld 0x6cba60 Connections: Feb 20 12:21:20 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 20 12:21:20 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 20 12:21:20 sng02 dovecot: auth: Error: last used: Wed Feb 20 12:21:20 2013 Feb 20 12:21:20 sng02 dovecot: auth: Error: Feb 20 12:21:20 sng02 dovecot:
Re: [Dovecot] Dovecot LDA LDAP lookups on samba4 server ends very often in timeouts
just to complete the informations of this thread, here is the log of a mail delivered succesfully (trailing and leading spaces of AT charcater has been added by me) ## MAIL SUCCEFFULLY DELIVERED LOG # Feb 19 17:41:01 sng02 postfix/smtpd[4006]: connect from localhost[127.0.0.1] Feb 19 17:41:28 sng02 postfix/smtpd[4006]: 95659407F5: client=localhost[127.0.0.1] Feb 19 17:41:36 sng02 postfix/cleanup[4011]: 95659407F5: warning: header Subject: prova from localhost[127.0.0.1]; from=marco @ senderdomain.tld to=mac @ mydomain.com proto=SMTP helo=senderdomain.tld Feb 19 17:41:36 sng02 postfix/cleanup[4011]: 95659407F5: message-id=20130219164128.95659407F5 @ srv01.mydomain.local Feb 19 17:41:36 sng02 postfix/qmgr[3992]: 95659407F5: from=marco @ senderdomain.tld, size=371, nrcpt=1 (queue active) Feb 19 17:41:36 sng02 dovecot: lda: Debug: Loading modules from directory: /usr/lib64/dovecot Feb 19 17:41:36 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib10_quota_plugin.so Feb 19 17:41:36 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib20_expire_plugin.so Feb 19 17:41:36 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib90_sieve_plugin.so Feb 19 17:41:36 sng02 dovecot: auth: Debug: master in: USER#0111#011marco.carcano#011service=lda Feb 19 17:41:36 sng02 dovecot: auth: Debug: password(marco.carcano): passdb doesn't support credential lookups Feb 19 17:41:36 sng02 dovecot: auth: Error: static(marco.carcano): passdb doesn't support lookups, can't verify user's existence Feb 19 17:41:36 sng02 dovecot: auth: Debug: ldap(marco.carcano): user search: base=DC=mydomain,DC=local scope=subtree filter=(sAMAccountname=marco.carcano) fields=Mailbox,dovecotMailQuota Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap(marco.carcano): Connection appears to be hanging, reconnecting Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_unbind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_request (origid 2, msgid 3) Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_request (origid 2, msgid 2) Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_connection 1 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_unbind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_connection: actually freed Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_connection 1 1 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_unbind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_free_connection: actually freed Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_create Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_bind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_simple_bind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_sasl_bind Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_new_connection 1 1 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_int_open_connection Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_connect_to_host: TCP localhost:389 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_new_socket: 16 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_prepare_socket: 16 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_connect_to_host: Trying ::1 389 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_pvt_connect: fd: 16 tm: -1 async: 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_open_defconn: successful Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_send_server_request Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_result ld 0x666a60 msgid -1 Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg ld 0x666a60 msgid -1 (timeout 0 usec) Feb 19 17:41:36 sng02 dovecot: auth: Error: wait4msg continue ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Connections: Feb 19 17:41:36 sng02 dovecot: auth: Error: * host: localhost port: 389 (default) Feb 19 17:41:36 sng02 dovecot: auth: Error: refcnt: 2 status: Connected Feb 19 17:41:36 sng02 dovecot: auth: Error: last used: Tue Feb 19 17:41:36 2013 Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Outstanding Requests: Feb 19 17:41:36 sng02 dovecot: auth: Error: * msgid 1, origid 1, status InProgress Feb 19 17:41:36 sng02 dovecot: auth: Error:outstanding referrals 0, parent count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 request count 1 (abandoned 0) Feb 19 17:41:36 sng02 dovecot: auth: Error: ** ld 0x666a60 Response Queue: Feb 19 17:41:36 sng02 dovecot: auth: Error:Empty Feb 19 17:41:36 sng02 dovecot: auth: Error: ld 0x666a60 response count 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList ld 0x666a60 msgid -1 all 0 Feb 19 17:41:36 sng02 dovecot: auth: Error: ldap_chkResponseList returns ld 0x666a60 NULL Feb 19 17:41:36 sng02 dovecot: auth: Error:
Re: [Dovecot] Dovecot LDA LDAP lookups on samba4 server ends very often in timeouts
Hi Marco, try to check if LDAP REFERRALS are enabled. I had a similar issue some time ago when trying to authenticate against an AD, which didn't worked (long timeouts) as long as I switched off REFERRALS in the systems ldap.conf. (more info you might get by 'man ldap.conf') Cheers, Chris Am Wed, 20 Feb 2013 13:25:39 +0100 schrieb ma...@carcano.ch: I hope that someone will be so kind to help me into solving this really strange thing (don't know if it is a bug or not) I have a samba4 server and want to use postfix+dovecot - dovecot version is 2.0.11 as for the postfix side everything is OK (all the LDAP lookups works without any error, tested also manually with postmap -q) the real pain is with dovecot deliver: it seems that sometimes lda tries to lookup to the LDPA (samba 4) server, got a reply, an then report(after 2 minutes) a lookup timeout error the really strange thing is that (very seldom) lda works, but most of the times I got the timeout error. The strange thing is that if I use ldapsearch I never got timeout neither late replies, and even postfix performs its lookups without any issue it seems something related to lda itself (I do not know if I have a wrong configuration, but I think this is not a configuration issue, otherwise it should not work at all) here are the information logged when it does not work - after this log you will find the one when I got the failure (if needed I can provide a .pcap file too) (trailing and leading spaces of AT charcater has been added by me) ## FAULTY DELIVER LOG # Feb 20 12:20:50 sng02 postfix/smtpd[8928]: connect from localhost[127.0.0.1] Feb 20 12:21:14 sng02 postfix/smtpd[8928]: A38D4407F5: client=localhost[127.0.0.1] Feb 20 12:21:20 sng02 postfix/cleanup[8891]: A38D4407F5: warning: header Subject: prova from localhost[127.0.0.1]; from=marco @ senderdomain.tld to=mac @ mydomain.com proto=SMTP helo=senderdomain.tld Feb 20 12:21:20 sng02 postfix/cleanup[8891]: A38D4407F5: message-id=20130220112114.A38D4407F5 @ srv01.mydomain.local Feb 20 12:21:20 sng02 postfix/qmgr[8889]: A38D4407F5: from=marco @ senderdomain.tld, size=371, nrcpt=1 (queue active) Feb 20 12:21:20 sng02 dovecot: lda: Debug: Loading modules from directory: /usr/lib64/dovecot Feb 20 12:21:20 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib10_quota_plugin.so Feb 20 12:21:20 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib20_expire_plugin.so Feb 20 12:21:20 sng02 dovecot: lda: Debug: Module loaded: /usr/lib64/dovecot/lib90_sieve_plugin.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Loading modules from directory: /usr/lib64/dovecot/auth Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libauthdb_ldap.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_pgsql.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so Feb 20 12:21:20 sng02 dovecot: auth: Debug: Module loaded: /usr/lib64/dovecot/auth/libmech_gssapi.so Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_bind Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_simple_bind Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_sasl_bind Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_initial_request Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_new_connection 1 1 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_int_open_connection Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_connect_to_host: TCP localhost:389 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_new_socket: 16 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_prepare_socket: 16 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_connect_to_host: Trying ::1 389 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_pvt_connect: fd: 16 tm: -1 async: 0 Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_open_defconn: successful Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_send_server_request Feb 20 12:21:20 sng02 dovecot: auth: Debug: master in: USER#0111#011marco.carcano#011service=lda Feb 20 12:21:20 sng02 dovecot: auth: Debug: password(marco.carcano): passdb doesn't support credential lookups Feb 20 12:21:20 sng02 dovecot: auth: Error: static(marco.carcano): passdb doesn't support lookups, can't verify user's existence Feb 20 12:21:20 sng02 dovecot: auth: Debug: ldap(marco.carcano): user search: base=DC=mydomain,DC=local scope=subtree filter=(sAMAccountname=marco.carcano) fields=Mailbox,dovecotMailQuota Feb 20 12:21:20 sng02 dovecot: auth: Error: ldap_result ld 0x6cba60 msgid -1 Feb 20 12:21:20 sng02 dovecot: auth: Error: wait4msg ld 0x6cba60 msgid -1 (timeout 0 usec) Feb 20 12:21:20 sng02 dovecot: auth: Error:
