StartTLS 在 saslauthd 中因 LDAP 机制而失败

StartTLS 在 saslauthd 中因 LDAP 机制而失败

我将我的邮件服务器从 Ubuntu 14.04 升级到 16.04,现在 StartTLS 不再适用于 saslauthd 中的 LDAP 机制。

% sudo testsaslauthd -u clement -p bar
0: NO "authentication failed"

syslog 中没有任何内容,因此我为 saslauthd 启用了调试模式:

% sudo saslauthd -a ldap -d -m /var/run/saslauthd
saslauthd[6742] :rel_accept_lock : released accept lock
saslauthd[6743] :get_accept_lock : acquired accept lock
saslauthd[6742] :do_auth         : auth failure: [user=clement] [service=imap] [realm=] [mech=ldap] [reason=Unknown]
saslauthd[6742] :do_request      : response: NO

这是配置文件

% sudo cat /etc/saslauthd.conf
ldap_servers: ldap://ldap.mydomain.fr/
ldap_bind_dn: uid=postfix,ou=services,dc=mydomain,dc=fr
ldap_bind_pw: foo
ldap_timeout: 10
ldap_time_limit: 10
ldap_scope: sub
ldap_search_base: ou=people,dc=mydomain,dc=fr
ldap_auth_method: bind
ldap_filter: (&(uniqueIdentifier=%u)(mailEnabled=TRUE))
ldap_debug: 0
ldap_verbose: off
ldap_ssl: no
ldap_starttls: yes
ldap_referrals: yes

以下是来自 LDAP 服务器的日志:

Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on 1 descriptor
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on:
Oct  1 14:16:07 ldap slapd[3942]: 
Oct  1 14:16:07 ldap slapd[3942]: slap_listener_activate(9):
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=9 busy
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: >>> slap_listener(ldap:///)
Oct  1 14:16:07 ldap slapd[3942]: daemon: listen=9, new connection on 13
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on 1 descriptor
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on:
Oct  1 14:16:07 ldap slapd[3942]: 
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: added 13r (active) listener=(nil)
Oct  1 14:16:07 ldap slapd[3942]: conn=1000 fd=13 ACCEPT from IP=192.168.1.5:51932 (IP=0.0.0.0:389)
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on 1 descriptor
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on:
Oct  1 14:16:07 ldap slapd[3942]:  13r
Oct  1 14:16:07 ldap slapd[3942]: 
Oct  1 14:16:07 ldap slapd[3942]: daemon: read active on 13
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on 1 descriptor
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on:
Oct  1 14:16:07 ldap slapd[3942]: 
Oct  1 14:16:07 ldap slapd[3942]: connection_get(13)
Oct  1 14:16:07 ldap slapd[3942]: connection_get(13): got connid=1000
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: connection_read(13): checking for input on id=1000
Oct  1 14:16:07 ldap slapd[3942]: op tag 0x60, time 1506860167
Oct  1 14:16:07 ldap slapd[3942]: conn=1000 op=0 do_bind
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on 1 descriptor
Oct  1 14:16:07 ldap slapd[3942]: >>> dnPrettyNormal: <uid=saslauthd,ou=services,dc=mydomain,dc=fr>
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on:
Oct  1 14:16:07 ldap slapd[3942]: <<< dnPrettyNormal: <uid=saslauthd,ou=services,dc=mydomain,dc=fr>, <uid=saslauthd,ou=services,dc=mydomain,dc=fr>
Oct  1 14:16:07 ldap slapd[3942]: conn=1000 op=0 BIND dn="uid=saslauthd,ou=services,dc=mydomain,dc=fr" method=128
Oct  1 14:16:07 ldap slapd[3942]: 
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: do_bind: version=3 dn="uid=saslauthd,ou=services,dc=mydomain,dc=fr" method=128
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: send_ldap_result: conn=1000 op=0 p=3
Oct  1 14:16:07 ldap slapd[3942]: send_ldap_result: err=13 matched="" text="TLS confidentiality required"
Oct  1 14:16:07 ldap slapd[3942]: send_ldap_response: msgid=1 tag=97 err=13
Oct  1 14:16:07 ldap slapd[3942]: conn=1000 op=0 RESULT tag=97 err=13 text=TLS confidentiality required
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on 1 descriptor
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on:
Oct  1 14:16:07 ldap slapd[3942]:  13r
Oct  1 14:16:07 ldap slapd[3942]: 
Oct  1 14:16:07 ldap slapd[3942]: daemon: read active on 13
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: connection_get(13)
Oct  1 14:16:07 ldap slapd[3942]: connection_get(13): got connid=1000
Oct  1 14:16:07 ldap slapd[3942]: connection_read(13): checking for input on id=1000
Oct  1 14:16:07 ldap slapd[3942]: op tag 0x42, time 1506860167
Oct  1 14:16:07 ldap slapd[3942]: ber_get_next on fd 13 failed errno=0 (Success)
Oct  1 14:16:07 ldap slapd[3942]: connection_read(13): input error=-2 id=1000, closing.
Oct  1 14:16:07 ldap slapd[3942]: connection_closing: readying conn=1000 sd=13 for close
Oct  1 14:16:07 ldap slapd[3942]: connection_close: deferring conn=1000 sd=13
Oct  1 14:16:07 ldap slapd[3942]: conn=1000 op=1 do_unbind
Oct  1 14:16:07 ldap slapd[3942]: conn=1000 op=1 UNBIND
Oct  1 14:16:07 ldap slapd[3942]: connection_resched: attempting closing conn=1000 sd=13
Oct  1 14:16:07 ldap slapd[3942]: connection_close: conn=1000 sd=13
Oct  1 14:16:07 ldap slapd[3942]: daemon: removing 13
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on 1 descriptor
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on:
Oct  1 14:16:07 ldap slapd[3942]: 
Oct  1 14:16:07 ldap slapd[3942]: conn=1000 fd=13 closed
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on 1 descriptor
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on:
Oct  1 14:16:07 ldap slapd[3942]: 
Oct  1 14:16:07 ldap slapd[3942]: slap_listener_activate(9):
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=9 busy
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: >>> slap_listener(ldap:///)
Oct  1 14:16:07 ldap slapd[3942]: daemon: listen=9, new connection on 13
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on 1 descriptor
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on:
Oct  1 14:16:07 ldap slapd[3942]: 
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: added 13r (active) listener=(nil)
Oct  1 14:16:07 ldap slapd[3942]: conn=1001 fd=13 ACCEPT from IP=192.168.1.5:51934 (IP=0.0.0.0:389)
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on 1 descriptor
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on:
Oct  1 14:16:07 ldap slapd[3942]: 
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on 1 descriptor
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on:
Oct  1 14:16:07 ldap slapd[3942]:  13r
Oct  1 14:16:07 ldap slapd[3942]: 
Oct  1 14:16:07 ldap slapd[3942]: daemon: read active on 13
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: connection_get(13)
Oct  1 14:16:07 ldap slapd[3942]: connection_get(13): got connid=1001
Oct  1 14:16:07 ldap slapd[3942]: connection_read(13): checking for input on id=1001
Oct  1 14:16:07 ldap slapd[3942]: op tag 0x60, time 1506860167
Oct  1 14:16:07 ldap slapd[3942]: conn=1001 op=0 do_bind
Oct  1 14:16:07 ldap slapd[3942]: >>> dnPrettyNormal: <uid=saslauthd,ou=services,dc=mydomain,dc=fr>
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on 1 descriptor
Oct  1 14:16:07 ldap slapd[3942]: <<< dnPrettyNormal: <uid=saslauthd,ou=services,dc=mydomain,dc=fr>, <uid=saslauthd,ou=services,dc=mydomain,dc=fr>
Oct  1 14:16:07 ldap slapd[3942]: conn=1001 op=0 BIND dn="uid=saslauthd,ou=services,dc=mydomain,dc=fr" method=128
Oct  1 14:16:07 ldap slapd[3942]: daemon: activity on:
Oct  1 14:16:07 ldap slapd[3942]: 
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: daemon: epoll: listen=11 active_threads=0 tvp=zero
Oct  1 14:16:07 ldap slapd[3942]: do_bind: version=3 dn="uid=saslauthd,ou=services,dc=mydomain,dc=fr" method=128
Oct  1 14:16:07 ldap slapd[3942]: send_ldap_result: conn=1001 op=0 p=3
Oct  1 14:16:07 ldap slapd[3942]: send_ldap_result: err=13 matched="" text="TLS confidentiality required"
Oct  1 14:16:07 ldap slapd[3942]: send_ldap_response: msgid=1 tag=97 err=13
Oct  1 14:16:07 ldap slapd[3942]: conn=1001 op=0 RESULT tag=97 err=13 text=TLS confidentiality required

最相关的部分似乎是

err=13 text=TLS confidentiality required

这让我认为 saslauthd 不会启动 StartTLS。

现在,如果我不需要 OpenLDAP 中的 StartTLS

% sudo testsaslauthd -u clement -p bar
0: OK "Success."

答案1

输入或TLS_REQCERT allow确保/etc/ldap/ldap.conf您的 LDAP 服务器证书可以被验证。

相关内容