| Subject: | SSL fails after plain text + STARTTLS |
| Date: | Sun, 17 Nov 2013 17:35:22 +0100 |
| To: | <bug-IO-Socket-SSL [...] rt.cpan.org> |
| From: | Klara Mall <klara.mall [...] kit.edu> |
Hi,
I use the Perl software radiator (RADIUS server) where I
authenticate users with LDAP. With some LDAP servers I use an SSL
connection and with some plain text and STARTTLS. With this
configuration radiator told me from time to time that it could not
open the LDAP connection. I analyzed this and noticed that the first
SSL connection after using plaintext + STARTTLS fails. Rather the
verification of the certificate fails providing that you use two
different servers in the plain text / STARTTLS and the SSL
connection.
I could reproduce this with a litte Perl program:
-----------------------------------------------------------------
#!/usr/bin/perl -w
use IO::Socket::SSL qw(debug3);
my $tls_host = "kit-dc-04.kit.edu";
my $ssl_host = "kit-ad.scc.kit.edu";
require Net::LDAP;
my $ldap_tls = Net::LDAP->new(
$tls_host,
port => 389,
timeout => 3);
$ldap_tls-> start_tls(
verify => 'require',
cafile => 'ca.pem');
require Net::LDAPS;
my $ldap_ssl = Net::LDAPS->new(
$ssl_host,
port => 636,
timeout => 3,
verify => 'require',
cafile => 'ca.pem');
-----------------------------------------------------------------
Result:
-----------------------------------------------------------------
DEBUG: .../IO/Socket/SSL.pm:1653: new ctx 22392624
DEBUG: .../IO/Socket/SSL.pm:1061: start handshake
DEBUG: .../IO/Socket/SSL.pm:383: ssl handshake not started
DEBUG: .../IO/Socket/SSL.pm:433: set socket to non-blocking to enforce timeout=3
DEBUG: .../IO/Socket/SSL.pm:446: Net::SSLeay::connect -> -1
DEBUG: .../IO/Socket/SSL.pm:456: ssl handshake in progress
DEBUG: .../IO/Socket/SSL.pm:466: waiting for fd to become ready: SSL wants a read first
DEBUG: .../IO/Socket/SSL.pm:486: socket ready, retrying connect
DEBUG: .../IO/Socket/SSL.pm:446: Net::SSLeay::connect -> -1
DEBUG: .../IO/Socket/SSL.pm:456: ssl handshake in progress
DEBUG: .../IO/Socket/SSL.pm:466: waiting for fd to become ready: SSL wants a read first
DEBUG: .../IO/Socket/SSL.pm:486: socket ready, retrying connect
DEBUG: .../IO/Socket/SSL.pm:1641: ok=1 cert=22397184
DEBUG: .../IO/Socket/SSL.pm:1641: ok=1 cert=22521520
DEBUG: .../IO/Socket/SSL.pm:1641: ok=1 cert=22513408
DEBUG: .../IO/Socket/SSL.pm:1641: ok=1 cert=22421632
DEBUG: .../IO/Socket/SSL.pm:1201: scheme=ldap cert=22421632
DEBUG: .../IO/Socket/SSL.pm:1210: identity=kit-dc-04.kit.edu cn=kit-dc-04.kit.edu alt=2 kit-dc-04.kit.edu 2 kit-dc.kit.edu
DEBUG: .../IO/Socket/SSL.pm:446: Net::SSLeay::connect -> -1
DEBUG: .../IO/Socket/SSL.pm:456: ssl handshake in progress
DEBUG: .../IO/Socket/SSL.pm:466: waiting for fd to become ready: SSL wants a read first
DEBUG: .../IO/Socket/SSL.pm:486: socket ready, retrying connect
DEBUG: .../IO/Socket/SSL.pm:446: Net::SSLeay::connect -> 1
DEBUG: .../IO/Socket/SSL.pm:501: ssl handshake done
DEBUG: .../IO/Socket/SSL.pm:1653: new ctx 22444320
DEBUG: .../IO/Socket/SSL.pm:363: socket not yet connected
DEBUG: .../IO/Socket/SSL.pm:365: socket connected
DEBUG: .../IO/Socket/SSL.pm:383: ssl handshake not started
DEBUG: .../IO/Socket/SSL.pm:433: set socket to non-blocking to enforce timeout=3
DEBUG: .../IO/Socket/SSL.pm:446: Net::SSLeay::connect -> -1
DEBUG: .../IO/Socket/SSL.pm:456: ssl handshake in progress
DEBUG: .../IO/Socket/SSL.pm:466: waiting for fd to become ready: SSL wants a read first
DEBUG: .../IO/Socket/SSL.pm:486: socket ready, retrying connect
DEBUG: .../IO/Socket/SSL.pm:1641: ok=1 cert=22556704
DEBUG: .../IO/Socket/SSL.pm:1641: ok=1 cert=22677424
DEBUG: .../IO/Socket/SSL.pm:1641: ok=1 cert=22669216
DEBUG: .../IO/Socket/SSL.pm:1641: ok=1 cert=22570864
DEBUG: .../IO/Socket/SSL.pm:1201: scheme=ldap cert=22570864
DEBUG: .../IO/Socket/SSL.pm:1210: identity=kit-dc-04.kit.edu cn=kit-ad.scc.kit.edu alt=1 f5@scc.kit.edu
DEBUG: .../IO/Socket/SSL.pm:446: Net::SSLeay::connect -> -1
DEBUG: .../IO/Socket/SSL.pm:1328: SSL connect attempt failed with unknown error error:14090086:SSL routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed
DEBUG: .../IO/Socket/SSL.pm:452: fatal SSL error: SSL connect attempt failed with unknown error error:14090086:SSL routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed
DEBUG: .../IO/Socket/SSL.pm:1328: IO::Socket::IP configuration failed error:00000000:lib(0):func(0):reason(0)
DEBUG: .../IO/Socket/SSL.pm:1690: free ctx 22444320 open=22444320 22392624
DEBUG: .../IO/Socket/SSL.pm:1695: free ctx 22444320 callback
DEBUG: .../IO/Socket/SSL.pm:1698: OK free ctx 22444320
DEBUG: .../IO/Socket/SSL.pm:1690: free ctx 22392624 open=22392624
DEBUG: .../IO/Socket/SSL.pm:1695: free ctx 22392624 callback
DEBUG: .../IO/Socket/SSL.pm:1698: OK free ctx 22392624
-----------------------------------------------------------------
To understand the problem I had a look at SSL.pm from
IO::Socket:SSL. As far as I understand SSL variables which are not
set are overriden with global variables. So I moved this code block
somewhat down which fixes it. (Although I'm wondering if the
identity should be overriden with a global variable at all.)
I'm using IO::Socket:SSL 1.74 from Debian wheezy, but I also
installed the recent version 1.959. It's the same problem although
the code is a bit different.
Fix for version 1.74 (Debian wheezy):
-----------------------------------------------------------
--- SSL.pm.orig 2013-11-13 02:11:46.752935483 +0100
+++ SSL.pm 2013-11-13 02:12:44.413920483 +0100
@@ -291,9 +291,6 @@
}
}
- #Replace nonexistent entries with defaults
- %$arg_hash = ( %default_args, %$GLOBAL_CONTEXT_ARGS, %$arg_hash );
-
#Avoid passing undef arguments to Net::SSLeay
defined($arg_hash->{$_}) or delete($arg_hash->{$_}) foreach (keys %$arg_hash);
@@ -327,6 +324,9 @@
return $rv;
};
}
+
+ #Replace nonexistent entries with defaults
+ %$arg_hash = ( %default_args, %$GLOBAL_CONTEXT_ARGS, %$arg_hash );
${*$self}{'_SSL_arguments'} = $arg_hash;
${*$self}{'_SSL_ctx'} = IO::Socket::SSL::SSL_Context->new($arg_hash) || return;
-----------------------------------------------------------
Fix for recent version 1.959:
-----------------------------------------------------------
--- SSL.pm.orig 2013-11-13 02:05:17.658251025 +0100
+++ SSL.pm 2013-11-13 02:04:55.129862855 +0100
@@ -300,13 +300,6 @@
$is_server = $arg_hash->{SSL_server} = $arg_hash->{Listen} || 0;
}
- # add user defined defaults
- %$arg_hash = (
- %$GLOBAL_SSL_ARGS,
- $is_server ? %$GLOBAL_SSL_SERVER_ARGS : %$GLOBAL_SSL_CLIENT_ARGS,
- %$arg_hash
- );
-
my $ctx = $arg_hash->{'SSL_reuse_ctx'};
if ($ctx) {
if ($ctx->isa('IO::Socket::SSL::SSL_Context') and
@@ -320,6 +313,13 @@
# create context
# this will fill in defaults in $arg_hash
$ctx ||= IO::Socket::SSL::SSL_Context->new($arg_hash);
+
+ # add user defined defaults
+ %$arg_hash = (
+ %$GLOBAL_SSL_ARGS,
+ $is_server ? %$GLOBAL_SSL_SERVER_ARGS : %$GLOBAL_SSL_CLIENT_ARGS,
+ %$arg_hash
+ );
${*$self}{'_SSL_arguments'} = $arg_hash;
${*$self}{'_SSL_ctx'} = $ctx;
-----------------------------------------------------------
Don't know if these fixes are ok, but I think they show where the
problem resides.
BTW: For testing I installed libnet-ldap-perl from Debian squeeze
and it works. As it seems the reason is that the part of the
IO::Socket::SSL code with the identity is not used (no DEBUG output
for this).
Is this a bug in IO::Socket::SSL? It would be nice if you check
what's the problem here.
Thanks in advance
Klara
--
Karlsruher Institut für Technologie (KIT)
Steinbuch Centre for Computing (SCC)
Klara Mall
Netze und Telekommunikation (NET)
Hermann-von-Helmholtz-Platz 1
76344 Eggenstein-Leopoldshafen
Telefon: +49 721 608-28630
Telefon: +49 721 608-48946
E-Mail: klara.mall@kit.edu
Web: http://www.scc.kit.edu
KIT - Universität des Landes Baden-Württemberg und
nationales Forschungszentrum in der Helmholtz-Gemeinschaft