(ITS#8395) DH Params code causes startTLS failure while slapd initializes the code - openldap-bugs

2 Apr 2016


      Full_Name: Quanah Gibson-Mount
Version: RE24
OS: Linux 2.6
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (75.111.52.177)
While testing the new DH params code for slapd, we found that there is an
interval in which slapd will break for startTLS connections while it loads in
the DH key.
Example:
Slapd is up and running, accepts startTLS connections just fine:
Apr  2 21:13:08 zre-ldap002 slapd[4844]: conn=1004 fd=13 TLS established
tls_ssf=256 ssf=256 tls_proto=TLSv1.2 tls_cipher=AES256-SHA256
Then we update olcTLSDHParamFile to add a DH key:
Apr  2 21:13:09 zre-ldap002 slapd[4844]: conn=1005 op=22 MOD dn="cn=config"
Apr  2 21:13:09 zre-ldap002 slapd[4844]: conn=1005 op=22 MOD
attr=olcTLSDHParamFile
Immediately after this, all startTLS attempts fail for the next few minutes:
Apr  2 21:13:15 zre-ldap002 slapd[4844]: conn=1008 fd=14 ACCEPT from
IP=10.137.242.52:48327 (IP=10.137.242.52:389)
Apr  2 21:13:15 zre-ldap002 slapd[4844]: conn=1008 op=0 EXT
oid=1.3.6.1.4.1.1466.20037
Apr  2 21:13:15 zre-ldap002 slapd[4844]: conn=1008 op=0 STARTTLS
Apr  2 21:13:15 zre-ldap002 slapd[4844]: conn=1008 op=0 RESULT oid= err=52
etime=0.000078 text=Could not initialize TLS
Apr  2 21:13:16 zre-ldap002 slapd[4844]: conn=1008 op=1 UNBIND
Apr  2 21:13:16 zre-ldap002 slapd[4844]: conn=1008 fd=14 closed
Apr  2 21:13:16 zre-ldap002 slapd[4844]: conn=1009 fd=14 ACCEPT from
IP=10.137.242.52:48328 (IP=10.137.242.52:389)
Apr  2 21:13:16 zre-ldap002 slapd[4844]: conn=1009 op=0 EXT
oid=1.3.6.1.4.1.1466.20037
Apr  2 21:13:16 zre-ldap002 slapd[4844]: conn=1009 op=0 STARTTLS
Apr  2 21:13:16 zre-ldap002 slapd[4844]: conn=1009 op=0 RESULT oid= err=52
etime=0.000054 text=Could not initialize TLS
Apr  2 21:13:16 zre-ldap002 slapd[4844]: conn=1009 op=1 UNBIND
Apr  2 21:13:16 zre-ldap002 slapd[4844]: conn=1009 fd=14 closed
Apr  2 21:13:17 zre-ldap002 slapd[4844]: connD1D1010 fd=14 ACCEPT from
IP=10.137.242.52:48329 (IP=10.137.242.52:389)
Apr  2 21:13:18 zre-ldap002 slapd[4844]: conn=1010 op=0 EXT
oid=1.3.6.1.4.1.1466.20037
Apr  2 21:13:18 zre-ldap002 slapd[4844]: conn=1010 op=0 STARTTLS
Apr  2 21:13:18 zre-ldap002 slapd[4844]: conn=1010 op=0 RESULT oid= err=52
etime=0.000124 text=Could not initialize TLS
Apr  2 21:13:18 zre-ldap002 slapd[4844]: conn=1010 op=1 UNBIND
Apr  2 21:13:18 zre-ldap002 slapd[4844]: conn=1010 fd=14 closed
Apr  2 21:13:18 zre-ldap002 slapd[4844]: conn=1011 fd=14 ACCEPT from
IP=10.137.242.52:48330 (IP=10.137.242.52:389)
Apr  2 21:13:18 zre-ldap002 slapd[4844]: conn=1011 op=0 EXT
oid=1.3.6.1.4.1.1466.20037
Apr  2 21:13:18 zre-ldap002 slapd[4844]: conn=1011 op=0 STARTTLS
Apr  2 21:13:18 zre-lda0202 slapd[4844]: conn=1011 op=0 RESULT oid= err=52
etime=0.000075 text=Could not initialize TLS
Apr  2 21:13:18 zre-ldap002 slapd[4844]: conn=1011 op=1 UNBIND
Apr  2 21:13:18 zre-ldap002 slapd[4844]: conn=1011 fd=14 closed
Apr  2 21:13:20 zre-ldap002 slapd[4844]: conn=1012 fd=14 ACCEPT from
IP=10.137.242.52:48331 (IP=10.137.242.52:389)
Apr  2 21:13:20 zre-ldap002 slapd[4844]: conn=1012 op=0 EXT
oid=1.3.6.1.4.1.1466.20037
Apr  2 21:13:20 zre-ldap002 slapd[4844]: conn=1012 op=0 STARTTLS
Apr  2 21:13:20 zre-ldap002 slapd[4844]: conn=1012 op=0 RESULT oid= err=52
etime=0.000098 text=Could not initialize TLS
Apr  2 21:13:20 zre-ldap002 slapd[4844]: conn=1012 op=1 UNBIND
Apr  2 21:13:20 zre-ldap002 slapd[4844]: conn=1012 fd=14 closed
Apr  2 21:13:20 zre-ldap002 slapd[4844]: conn=1013 fd=14 ACCEPT from
IP=10.137.242.52:48332 (IP=10.137.242.52:389)
Apr  2 21:13:20 zre-ldap002 slapd[4844]: conn=1013 op=0 EXT
oid=1.3.6.1.4.1.1466.20037
Apr  2 21:13:20 zre-ldap002 slapd[4844]: conn=1013 op=0 STARTTLS
Apr  2 21:13:20 zre-ldap002 slapd[4844]: conn=1013 op=0 RESULT oid= err=52
etime=0.000062 text=Could not initialize TLS
Apr  2 21:13:20 zre-ldap002 slapd[4844]: conn=1013 op=1 UNBIND
Apr  2 21:13:20 zre-ldap002 slapd[4844]: conn=1013 fd=14 closed
Apr  2 21:13"22 zre-ldap0 s slapd[4844]: conn=1014 fd=14 ACCEPT from
IP=10.137.242.52:48333 (IP=10.137.242.52:389)
Apr  2 21:13:22 zre-ldap002 slapd[4844]: conn=1014 op=0 EXT
oid=1.3.6.1.4.1.1466.20037
Apr  2 21:13:22 zre-ldap002 slapd[4844]: conn=1014 op=0 STARTTLS
Apr  2 21:13:22 zre-ldap002 slapd[4844]: conn=1014 op=0 RESULT oid= err=52
etime=0.000108 text=Could not initialize TLS
Apr  2 21:13:22 zre-ldap002 slapd[4844]: conn=1014 op=1 UNBIND
Apr  2 21:13:22 zre-ldap002 slapd[4844]: conn=1014 fd=14 closed
Apr  2 21:13:22 zre-ldap002 slapd[4844]: conn=1015 fd=14 ACCEPT from
IP=10.137.242.52:48334 (IP=10.137.242.52:389)
Apr  2 21:13:22 zre-ldap002 slapd[4844]: conn=1015 op=0 EXT
oid=1.3.6.1.4.1.1466.20037
Apr  2 21:13:22 zre-ldap002 slapd[4844]: conn=1015 op=0 STARTTLS
Apr  2 21:13:22 zre-ldap002 slapd[4844]: conn=1015 op=0 RESULT oid= err=52
etime=0.000066 text=Could not initialize TLS
Apr  2 21:13:22 zre-ldap002 slapd[4844]: conn=1015 op=1 UNBIND
....
Apr  2 21:14:01 zre-ldap002 slapd[4844]: conn=1022d%d=14 ACCEPT from
IP=10.137.242.52:48339 (IP=10.137.242.52:389)
Apr  2 21:14:01 zre-ldap002 slapd[4844]: conn=1022 op=0 EXT
oid=1.3.6.1.4.1.1466.20037
Apr  2 21:14:01 zre-ldap002 slapd[4844]: conn=1022 op=0 STARTTLS
Apr  2 21:14:01 zre-ldap002 slapd[4844]: conn=1022 op=0 RESULT oid= err=52
etime=0.000143 text=Could not initialize TLS
Apr  2 21:14:01 zre-ldap002 slapd[4844]: conn=1022 fd=14 closed (connection
lost)
Eventually it recovers:
Apr  2 21:16:02 zre-ldap002 slapd[4844]: conn=1027 fd=14 ACCEPT from
IP=10.137.242.52:48340 (IP=10.137.242.52:389)
Apr  2 21:16:02 zre-ldap002 slapd[4844]: conn=1027 op=0 EXT
oid=1.3.6.1.4.1.1466.20037
Apr  2 21:16:02 zre-ldap002 slapd[4844]: conn=1027 op=0 STARTTLS
Apr  2 21:16:02 zre-ldap002 slapd[4844]: connD1D1027 op=0 RESULT oid= err=0
etime=0.000085 text=
Apr  2 21:16:02 zre-ldap002 slapd[4844]: conn=1027 fd=14 TLS established
tls_ssf=128 ssf=128 tls_proto=TLSv1.2 tls_cipher=AES128-SHA256
My guess is that startTLS is essentially broken while slapd spends time loading
in the DH key.  I would think that during this time, slapd should be deferring
connections rather than accepting them immediately.