[RADIATOR] Net::LDAPS problem with Active Directory on port 636

[Klara Mall]

Hi,

On Tue, Nov 12, 2013 at 10:29:18PM +0100, Klara Mall wrote:
> I analyzed now (given two different LDAP server hosts):
> a. if I use SSL in both connections it works.
> b. if I use TLS in both connections it works.
> c. if I use TLS in RewriteFunction and SSL in AuthBy LDAP2 it doesn't work.
> d. if I use SSL in RewriteFunction and TLS in AuthBy LDAP2 it doesn't work.
> 
> c: This is what I was describing in this email (2nd authentication fails).
> 
> d: Not the 2nd authentication fails but the 1st.
> RewriteFunction is ok:
> 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
> AuthBy LDAP2 fails:
> DEBUG: .../IO/Socket/SSL.pm:1210: identity=kit-dc-04.kit.edu cn=kit-ad.scc.kit.edu alt=1 f5 at scc.kit.edu
> 
> I seems that the first TLS connection after an SSL connection fails.
> I have to try to reproduce this with a Perl program which does
> nothing else than such two connections.

Sorry, I have mixed this up again (it's very hard to test this
without getting confused).

What I described in my first email was d. That means that the first SSL
connection after a TLS connection fails - i.e the 2nd auth try
fails here.

c.: The same: the first SSL connection after a TLS connection fails
- i.e. the 1st auth try fails here.

I could reproduce it:
-----------------------------------------------------------------
#!/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 at 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
-----------------------------------------------------------------


So is this a bug in IO::Socket::SSL?

Regards
Klara