LDAP TLS problem

Hi all,
I'm failing to setup TLS to OpenLDAP correctly. Running 
   ldapsearch -x -ZZ -h cube.fritz.box -b dc=fritz,dc=box
works.

However, sssd_fritz.box.log contains

(Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_sys_connect_done] (0x0100):
Executing START TLS
(Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_connect_done] (0x0080): START TLS
result: Success(0), (null)
(Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_cli_auth_step] (0x0100): expire
timeout is 900
(Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_cli_connect_recv] (0x0400):
Connection established.
(Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [fo_set_port_status] (0x0100): Marking
port 389 of server 'cube.fritz.box' as 'working'
(Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [set_server_common_status] (0x0100):
Marking server 'cube.fritz.box' as 'working'
(Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [fo_set_port_status] (0x0400): Marking
port 389 of duplicate server 'cube.fritz.box' as 'working'
(Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_search_user_next_base] (0x0400):
Searching for users with base [dc=fritz,dc=box]
(Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_get_generic_ext_step] (0x0400):
calling ldap_search_ext with
[(&(uidNumber=11012)(objectclass=posixAccount)(uid=*)(&(uidNumber=*)(!(uidNumber=0))))][dc=fritz,dc=box].
(Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_process_result] (0x0040):
ldap_result error: [Can't contact LDAP server]
(Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [generic_ext_search_handler] (0x0040):
sdap_get_generic_ext_recv failed [5]: Eingabe-/Ausgabefehler
(Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_get_users_done] (0x0040): Failed to
retrieve users [5][Eingabe-/Ausgabefehler].
(Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_id_op_done] (0x0200): communication
error on cached connection, moving to next server

Config is

[domain/fritz.box]
id_provider = ldap
debug_level = 6
ldap_schema = rfc2307
enumerate = false
ldap_uri = ldap://cube.fritz.box
ldap_search_base = dc=fritz,dc=box
ldap_access_filter = memberOf=cn=users,ou=Group,dc=fritz,dc=box
ldap_tls_cacert = /etc/ssl/certs/Local_ROOT_CA.crt
ldap_tls_reqcert = demand
ldap_id_use_start_tls = True

# file /etc/ssl/certs/Local_ROOT_CA.crt 
/etc/ssl/certs/Local_ROOT_CA.crt: PEM certificate

# cat /etc/ldap/ldap.conf 
BASE    dc=fritz,dc=box
URI     ldaps://cube.fritz.box
SSL     start_tls
TLS_CACERT      /etc/ssl/certs/Local_ROOT_CA.crt
TLS_REQCERT     demand

All indicates that SSSD terminates the connection.

OpenLDAP log:
Oct 30 21:49:40 cube slapd[14620]: conn=1289 fd=20 ACCEPT from IP=192.168.254.13:55698
(IP=0.0.0.0:389)
Oct 30 21:49:40 cube slapd[14620]: conn=1289 op=0 EXT oid=1.3.6.1.4.1.1466.20037
Oct 30 21:49:40 cube slapd[14620]: conn=1289 op=0 STARTTLS
Oct 30 21:49:40 cube slapd[14620]: conn=1289 op=0 RESULT oid= err=0 text=
Oct 30 21:49:40 cube slapd[14620]: conn=1289 fd=20 closed (TLS negotiation failure)
Oct 30 21:49:40 cube slapd[14620]: conn=1290 fd=20 ACCEPT from IP=192.168.254.13:55700
(IP=0.0.0.0:389)
Oct 30 21:49:40 cube slapd[14620]: conn=1290 op=0 EXT oid=1.3.6.1.4.1.1466.20037
Oct 30 21:49:40 cube slapd[14620]: conn=1290 op=0 STARTTLS
Oct 30 21:49:40 cube slapd[14620]: conn=1290 op=0 RESULT oid= err=0 text=
Oct 30 21:49:40 cube slapd[14620]: conn=1290 fd=20 closed (TLS negotiation failure)

Wireshark says:
- correct certificate is presented by OpenLDAP
- clients sends 
Secure Sockets Layer
    TLSv1.2 Record Layer: Alert (Level: Warning, Description: Close Notify)
        Content Type: Alert (21)
        Version: TLS 1.2 (0x0303)
        Length: 2
        Alert Message
            Level: Warning (1)
            Description: Close Notify (0)

Increasing debug_level doesn't provide more details.

This is on debian sid with 
# dpkg -l sssd
ii  sssd                                   1.14.1-1                 amd64                 
  System Security Services Daemon -- metapackage

How to proceed?
How to find out more what's wrong with the TLS setup?

TIA,
Chris.

[Jakub Hrozek]

On Sun, Oct 30, 2016 at 09:10:36PM -0000, c.haul(a)web.de wrote:
>  Hi all,
>  I'm failing to setup TLS to OpenLDAP correctly. Running 
>     ldapsearch -x -ZZ -h cube.fritz.box -b dc=fritz,dc=box
>  works.
>  
>  However, sssd_fritz.box.log contains
>  
>  (Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_sys_connect_done] (0x0100):
> Executing START TLS
>  (Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_connect_done] (0x0080): START TLS
> result: Success(0), (null)
>  (Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_cli_auth_step] (0x0100): expire
> timeout is 900
>  (Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_cli_connect_recv] (0x0400):
> Connection established.
>  (Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [fo_set_port_status] (0x0100): Marking
> port 389 of server 'cube.fritz.box' as 'working'
>  (Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [set_server_common_status] (0x0100):
> Marking server 'cube.fritz.box' as 'working'
>  (Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [fo_set_port_status] (0x0400): Marking
> port 389 of duplicate server 'cube.fritz.box' as 'working'
>  (Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_search_user_next_base] (0x0400):
> Searching for users with base [dc=fritz,dc=box]
>  (Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_get_generic_ext_step] (0x0400):
> calling ldap_search_ext with
> [(&(uidNumber=11012)(objectclass=posixAccount)(uid=*)(&(uidNumber=*)(!(uidNumber=0))))][dc=fritz,dc=box].
>  (Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_process_result] (0x0040):
> ldap_result error: [Can't contact LDAP server]
>  (Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [generic_ext_search_handler] (0x0040):
> sdap_get_generic_ext_recv failed [5]: Eingabe-/Ausgabefehler
>  (Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_get_users_done] (0x0040): Failed
> to retrieve users [5][Eingabe-/Ausgabefehler].
>  (Sun Oct 30 21:49:40 2016) [sssd[be[fritz.box]]] [sdap_id_op_done] (0x0200):
> communication error on cached connection, moving to next server
>  
>  Config is
>  
>  [domain/fritz.box]
>  id_provider = ldap
>  debug_level = 6
>  ldap_schema = rfc2307
>  enumerate = false
>  ldap_uri = ldap://cube.fritz.box
>  ldap_search_base = dc=fritz,dc=box
>  ldap_access_filter = memberOf=cn=users,ou=Group,dc=fritz,dc=box
>  ldap_tls_cacert = /etc/ssl/certs/Local_ROOT_CA.crt
>  ldap_tls_reqcert = demand
>  ldap_id_use_start_tls = True
>  
>  # file /etc/ssl/certs/Local_ROOT_CA.crt 
>  /etc/ssl/certs/Local_ROOT_CA.crt: PEM certificate
>  
>  # cat /etc/ldap/ldap.conf 
>  BASE    dc=fritz,dc=box
>  URI     ldaps://cube.fritz.box
>  SSL     start_tls
>  TLS_CACERT      /etc/ssl/certs/Local_ROOT_CA.crt
>  TLS_REQCERT     demand
>  
>  All indicates that SSSD terminates the connection.
>  
>  OpenLDAP log:
>  Oct 30 21:49:40 cube slapd[14620]: conn=1289 fd=20 ACCEPT from IP=192.168.254.13:55698
> (IP=0.0.0.0:389)
>  Oct 30 21:49:40 cube slapd[14620]: conn=1289 op=0 EXT oid=1.3.6.1.4.1.1466.20037
>  Oct 30 21:49:40 cube slapd[14620]: conn=1289 op=0 STARTTLS
>  Oct 30 21:49:40 cube slapd[14620]: conn=1289 op=0 RESULT oid= err=0 text=
>  Oct 30 21:49:40 cube slapd[14620]: conn=1289 fd=20 closed (TLS negotiation failure)
>  Oct 30 21:49:40 cube slapd[14620]: conn=1290 fd=20 ACCEPT from IP=192.168.254.13:55700
> (IP=0.0.0.0:389)
>  Oct 30 21:49:40 cube slapd[14620]: conn=1290 op=0 EXT oid=1.3.6.1.4.1.1466.20037
>  Oct 30 21:49:40 cube slapd[14620]: conn=1290 op=0 STARTTLS
>  Oct 30 21:49:40 cube slapd[14620]: conn=1290 op=0 RESULT oid= err=0 text=
>  Oct 30 21:49:40 cube slapd[14620]: conn=1290 fd=20 closed (TLS negotiation failure)
>  
>  Wireshark says:
>  - correct certificate is presented by OpenLDAP
>  - clients sends 
>  Secure Sockets Layer
>      TLSv1.2 Record Layer: Alert (Level: Warning, Description: Close Notify)
>          Content Type: Alert (21)
>          Version: TLS 1.2 (0x0303)
>          Length: 2
>          Alert Message
>              Level: Warning (1)
>              Description: Close Notify (0)
>  
>  Increasing debug_level doesn't provide more details.
>  
>  This is on debian sid with 
>  # dpkg -l sssd
>  ii  sssd                                   1.14.1-1                 amd64                
>    System Security Services Daemon -- metapackage
>  
>  How to proceed?
>  How to find out more what's wrong with the TLS setup? 
Lukas fixed the bug recently:
    https://github.com/SSSD/sssd/pull/67
the patch should make its way to upstream soon.

Thanks for the quick reply.
Will wait and see.

Chris.