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.