[Evolution] Bug#462972: Further info

[Chris Carr]

Evolution is configured to use ldaps (port 636), using SSL encryption.

I am trying to bind "Using distinguished name (DN)". 

In the login box I have "cn=Chris Carr,ou=Contacts,dc=sadnet" (without
quotes). 

The server is dbass.homelinux.com

"Copy book content locally for offline operation" is unchecked.

"Mark as default folder" is checked. 

Evolution's error message is as follows: 

----
Error loading addressbook.

We were unable to open this addressbook. This either means you have
entered an incorrect URI, or the LDAP server is unreachable.
----

Yet slapd's full debug output is this: 

Jan 29 18:33:20 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:33:20 baba slapd[14841]: daemon: activity on:
Jan 29 18:33:20 baba slapd[14841]:  14r
Jan 29 18:33:20 baba slapd[14841]:
Jan 29 18:33:20 baba slapd[14841]: daemon: read active on 14
Jan 29 18:33:20 baba slapd[14841]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Jan 29 18:33:20 baba slapd[14841]: connection_get(14)
Jan 29 18:33:20 baba slapd[14841]: connection_get(14): got connid=2
Jan 29 18:33:20 baba slapd[14841]: connection_read(14): checking for
input on id=2
Jan 29 18:33:20 baba slapd[14841]: ber_get_next on fd 14 failed errno=0
(Success)
Jan 29 18:33:20 baba slapd[14841]: connection_read(14): input error=-2
id=2, closing.
Jan 29 18:33:20 baba slapd[14841]: connection_closing: readying conn=2
sd=14 for close
Jan 29 18:33:20 baba slapd[14841]: connection_close: conn=2 sd=14
Jan 29 18:33:20 baba slapd[14841]: daemon: removing 14
Jan 29 18:33:20 baba slapd[14841]: conn=2 fd=14 closed (connection lost)
Jan 29 18:33:20 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:33:20 baba slapd[14841]: daemon: activity on:
Jan 29 18:33:20 baba slapd[14841]:
Jan 29 18:33:20 baba slapd[14841]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Jan 29 18:33:20 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:33:20 baba slapd[14841]: daemon: activity on:
Jan 29 18:33:20 baba slapd[14841]:
Jan 29 18:33:20 baba slapd[14841]: slap_listener_activate(8):
Jan 29 18:33:20 baba slapd[14841]: daemon: epoll: listen=8 busy
Jan 29 18:33:20 baba slapd[14841]: >>> slap_listener(ldaps:///)
Jan 29 18:33:20 baba slapd[14841]: daemon: listen=8, new connection on
14
Jan 29 18:33:20 baba slapd[14841]: daemon: added 14r (active)
listener=(nil)
Jan 29 18:33:20 baba slapd[14841]: conn=5 fd=14 ACCEPT from
IP=192.168.1.10:32931 (IP=0.0.0.0:636)
Jan 29 18:33:20 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:33:20 baba slapd[14841]: daemon: activity on:
Jan 29 18:33:20 baba slapd[14841]:
Jan 29 18:33:20 baba slapd[14841]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Jan 29 18:33:20 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:33:20 baba slapd[14841]: daemon: activity on:
Jan 29 18:33:20 baba slapd[14841]:  14r
Jan 29 18:33:20 baba slapd[14841]:
Jan 29 18:33:20 baba slapd[14841]: daemon: read active on 14
Jan 29 18:33:20 baba slapd[14841]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Jan 29 18:33:20 baba slapd[14841]: connection_get(14)
Jan 29 18:33:20 baba slapd[14841]: connection_get(14): got connid=5
Jan 29 18:33:20 baba slapd[14841]: connection_read(14): checking for
input on id=5
Jan 29 18:33:20 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:33:20 baba slapd[14841]: daemon: activity on:
Jan 29 18:33:20 baba slapd[14841]:
Jan 29 18:33:20 baba slapd[14841]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Jan 29 18:33:20 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:33:20 baba slapd[14841]: daemon: activity on:
Jan 29 18:33:20 baba slapd[14841]:  14r
Jan 29 18:33:20 baba slapd[14841]:
Jan 29 18:33:20 baba slapd[14841]: daemon: read active on 14
Jan 29 18:33:20 baba slapd[14841]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Jan 29 18:33:20 baba slapd[14841]: connection_get(14)
Jan 29 18:33:20 baba slapd[14841]: connection_get(14): got connid=5
Jan 29 18:33:20 baba slapd[14841]: connection_read(14): checking for
input on id=5
Jan 29 18:33:20 baba slapd[14841]: connection_read(14): unable to get
TLS client DN, error=49 id=5
Jan 29 18:33:20 baba slapd[14841]: conn=5 fd=14 TLS established
tls_ssf=16 ssf=16
Jan 29 18:33:20 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:33:20 baba slapd[14841]: daemon: activity on:
Jan 29 18:33:20 baba slapd[14841]:
Jan 29 18:33:20 baba slapd[14841]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on:
Jan 29 18:34:14 baba slapd[14841]:  14r
Jan 29 18:34:14 baba slapd[14841]:
Jan 29 18:34:14 baba slapd[14841]: daemon: read active on 14
Jan 29 18:34:14 baba slapd[14841]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Jan 29 18:34:14 baba slapd[14841]: connection_get(14)
Jan 29 18:34:14 baba slapd[14841]: connection_get(14): got connid=5
Jan 29 18:34:14 baba slapd[14841]: connection_read(14): checking for
input on id=5
Jan 29 18:34:14 baba slapd[14841]: ber_get_next on fd 14 failed errno=0
(Success)
Jan 29 18:34:14 baba slapd[14841]: connection_read(14): input error=-2
id=5, closing.
Jan 29 18:34:14 baba slapd[14841]: connection_closing: readying conn=5
sd=14 for close
Jan 29 18:34:14 baba slapd[14841]: connection_close: conn=5 sd=14
Jan 29 18:34:14 baba slapd[14841]: daemon: removing 14
Jan 29 18:34:14 baba slapd[14841]: conn=5 fd=14 closed (connection lost)
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on:
Jan 29 18:34:14 baba slapd[14841]:
Jan 29 18:34:14 baba slapd[14841]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on:
Jan 29 18:34:14 baba slapd[14841]:
Jan 29 18:34:14 baba slapd[14841]: slap_listener_activate(8):
Jan 29 18:34:14 baba slapd[14841]: daemon: epoll: listen=8 busy
Jan 29 18:34:14 baba slapd[14841]: >>> slap_listener(ldaps:///)
Jan 29 18:34:14 baba slapd[14841]: daemon: listen=8, new connection on
14
Jan 29 18:34:14 baba slapd[14841]: daemon: added 14r (active)
listener=(nil)
Jan 29 18:34:14 baba slapd[14841]: conn=6 fd=14 ACCEPT from
IP=192.168.1.10:32932 (IP=0.0.0.0:636)
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on:
Jan 29 18:34:14 baba slapd[14841]:
Jan 29 18:34:14 baba slapd[14841]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on:
Jan 29 18:34:14 baba slapd[14841]:  14r
Jan 29 18:34:14 baba slapd[14841]:
Jan 29 18:34:14 baba slapd[14841]: daemon: read active on 14
Jan 29 18:34:14 baba slapd[14841]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Jan 29 18:34:14 baba slapd[14841]: connection_get(14)
Jan 29 18:34:14 baba slapd[14841]: connection_get(14): got connid=6
Jan 29 18:34:14 baba slapd[14841]: connection_read(14): checking for
input on id=6
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on:
Jan 29 18:34:14 baba slapd[14841]:
Jan 29 18:34:14 baba slapd[14841]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on:
Jan 29 18:34:14 baba slapd[14841]:  14r
Jan 29 18:34:14 baba slapd[14841]:
Jan 29 18:34:14 baba slapd[14841]: daemon: read active on 14
Jan 29 18:34:14 baba slapd[14841]: daemon: epoll: listen=8
active_threads=0 tvp=zero
Jan 29 18:34:14 baba slapd[14841]: connection_get(14)
Jan 29 18:34:14 baba slapd[14841]: connection_get(14): got connid=6
Jan 29 18:34:14 baba slapd[14841]: connection_read(14): checking for
input on id=6
Jan 29 18:34:14 baba slapd[14841]: connection_read(14): unable to get
TLS client DN, error=49 id=6
Jan 29 18:34:14 baba slapd[14841]: conn=6 fd=14 TLS established
tls_ssf=16 ssf=16
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on 1 descriptor
Jan 29 18:34:14 baba slapd[14841]: daemon: activity on:
Jan 29 18:34:14 baba slapd[14841]:
Jan 29 18:34:14 baba slapd[14841]: daemon: epoll: listen=8
active_threads=0 tvp=zero

Twice is says "ACCEPT" and twice it says "TLS established" - there is no
indication here that slapd is refusing the connection. Yet the bind does
not seem to be taking place. 

Is this a bug or am I doing something wrong? 

Regards,

CC