Beefy Boxes and Bandwidth Generously Provided by pair Networks
Welcome to the Monastery
 
PerlMonks  

Long delay with Crypt::SSLeay and LWP

by waldo22 (Novice)
on Jul 24, 2012 at 22:17 UTC ( #983524=perlquestion: print w/replies, xml ) Need Help??

waldo22 has asked for the wisdom of the Perl Monks concerning the following question:

I just upgraded to Debian Wheezy from Lenny (long story) and a few of my Perl packages didn't make the upgrade for some reason, among them Crypt::SSLeay (libcrypt-ssleay-perl).

I was unable to connect to my credit card payment gateway (Payflow Pro) using LWP until I installed libcrypt-ssleay-perl, and now it "works", but it takes 15-20 seconds to make the SSL connection due to the very unhelpful error message "error in unknown state":

SSL_connect:before/connect initialization SSL_connect:unknown state (waiting 15-20 seconds...) #this comment is from waldo22 SSL_connect:error in unknown state SSL_connect:before/connect initialization SSL_connect:SSLv3 write client hello A SSL_connect:SSLv3 read server hello A SSL_connect:SSLv3 read server certificate A SSL_connect:SSLv3 read server done A SSL_connect:SSLv3 write client key exchange A SSL_connect:SSLv3 write change cipher spec A SSL_connect:SSLv3 write finished A SSL_connect:SSLv3 flush data SSL_connect:SSLv3 read finished A
Here's a pastebin of the console from the actual request/response:

I should note that there was no delay with the previous version of LWP::UA, and that the request is clearly working, but with the unacceptable delay.

I have a feeling this has something to do with LWP changing the default behavior for certificate authorities and server certificiate verification:
lwp SSL validation
and possibly:
certificate verify failed

The PayflowPro Perl module is using Crypt::SSLeay via LWP::useragent.

Current versions of relevant libraries are:

PayflowPro 3101 (just upgraded from 2111, but same results) libwww-perl 6.04-1 libcrypt-ssleay-perl 0.58-1 liblwp-protocol-https 6.03-1

Obviously 15-20 seconds is way too long to wait to make an SSL connection, but without a more helpful error message, I don't know what to do.

Does anyone have any suggestions on how to better debug this or to get more verbose output?

Thanks a bunch,

-Wes

Replies are listed 'Best First'.
Re: Long delay with Crypt::SSLeay and LWP
by Anonymous Monk on Jul 25, 2012 at 06:58 UTC
    Try Net::SSLeay on for size :)
    #!/usr/bin/perl -- use LWP::Simple ; use IO::Socket::SSL qw(debug3); get( q{https://pilot-payflowpro.paypal.com/} ); __END__ DEBUG: .../IO/Socket/SSL.pm:1567: new ctx 18240320 DEBUG: .../IO/Socket/SSL.pm:334: socket not yet connected DEBUG: .../IO/Socket/SSL.pm:336: socket connected DEBUG: .../IO/Socket/SSL.pm:354: ssl handshake not started DEBUG: .../IO/Socket/SSL.pm:1555: ok=1 cert=18273264 DEBUG: .../IO/Socket/SSL.pm:1555: ok=1 cert=18997536 DEBUG: .../IO/Socket/SSL.pm:1555: ok=1 cert=18245888 DEBUG: .../IO/Socket/SSL.pm:1170: scheme=www cert=18245888 DEBUG: .../IO/Socket/SSL.pm:1177: identity=pilot-payflowpro.paypal.com + cn=pilot-payflowpro.paypal.com alt=2 pilot-payflowpro.paypal.com DEBUG: .../IO/Socket/SSL.pm:414: Net::SSLeay::connect -> 1 DEBUG: .../IO/Socket/SSL.pm:469: ssl handshake done DEBUG: .../IO/Socket/SSL.pm:1604: free ctx 18240320 open=18240320 DEBUG: .../IO/Socket/SSL.pm:1609: free ctx 18240320 callback DEBUG: .../IO/Socket/SSL.pm:1612: OK free ctx 18240320

      Thanks for the tip. That produced slightly more helpful output. Does this mean anything to you?

      DEBUG: .../IO/Socket/SSL.pm:196: set domain to 2 DEBUG: .../IO/Socket/SSL.pm:1622: new ctx 33610976 DEBUG: .../IO/Socket/SSL.pm:339: socket not yet connected DEBUG: .../IO/Socket/SSL.pm:341: socket connected DEBUG: .../IO/Socket/SSL.pm:359: ssl handshake not started (long pause again - at least 30 sec.) DEBUG: .../IO/Socket/SSL.pm:422: Net::SSLeay::connect -> -1 DEBUG: .../IO/Socket/SSL.pm:1299: SSL connect attempt failed with unkn +own error error:00000000:lib(0):func(0):reason(0) DEBUG: .../IO/Socket/SSL.pm:428: fatal SSL error: SSL connect attempt +failed with unknown error error:00000000:lib(0):func(0):reason(0) DEBUG: .../IO/Socket/SSL.pm:1299: IO::Socket::INET6 configuration fail +ed error:00000000:lib(0):func(0):reason(0) DEBUG: .../IO/Socket/SSL.pm:1659: free ctx 33610976 open=33610976 DEBUG: .../IO/Socket/SSL.pm:1667: OK free ctx 33610976

        Does this mean anything to you?

        :) Not particularly, though it hints to me the problem likely isn't perl specific -- you can probably confirm this hunch by running openssl ... see Debugging SSL communications

Re: Long delay with Crypt::SSLeay and LWP
by Anonymous Monk on Jul 25, 2012 at 00:37 UTC
    It definitely sounds like a timeout. One party or the other is probably requesting some verification from someone else and timing-out. What you want to determine is why it thinks it needs to ask somebody "else," knowing as you do that it should not think it needs to.
Re: Long delay with Crypt::SSLeay and LWP
by waldo22 (Novice) on Aug 01, 2012 at 18:19 UTC

    Well, perhaps this wasn't a Perl problem, but there's a Perl solution (of course!)

    There appears to be a problem with OpenSSL 1.0.1 where attempting to autonegotiate with TLS1.1 (or 1.2???) with some servers causes those servers to drop the connection and reject the request. See:

    https://bugs.launchpad.net/ubuntu/+source/openssl/+bug/965371
    http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=665452

    According to the bug ticket, they say it is "fixed" for Paypal in Debian OpenSSL 1.0.1b, but I'm running 1.0.1c-3 and still experience the problem. I don't know if that means it's fixed for www.paypal.com but not payflowpro.paypal.com, or what.

    SOLUTION: Setting $ENV{HTTPS_VERSION} = 3; to force SSL3 seems to fix the problem, at least for Crypt::SSLeay.

    Presumably this works because it does not attempt to negotiate TLS1.1, and just uses SSL3.

    Testing with openssl s_client, it works with the options -ssl3, -tls1, and -no_tls1, so it must be a negotiation problem, in my opinion.

    Anyway, that's a workaround, at least.

    Different problem, but same solution: http://www.perlmonks.org/?node_id=746493

    -Wes

      So I'm going to reply to this (after an appropriately long delay :-), because I just upgraded to wheezy and am having the same problem and search turned this up.

      I really hate bashing %ENV to communicate between different parts of Perl. As a general rule of thumb, if you're trying to communicate intra-process, there's nearly always a better way than messing with %ENV.

      Also it looks like IO::Socket::SSL is preferred over Net::SSL/Crypt::SSLeay these days. In my original version of this post there was some question of whether the latter is even being maintained and can actually do certificate verification, but apparently it is and can. I got confused because Crypt::SSLeay evidently can't do hostname verification which is a distinct issue (though arguably still an issue). There's also a comment in the Crypt::SSLeay pod to the effect that that module only exists to https-enable LWP::UserAgent whereas IO::Socket::SSL is a more general-purpose package.

      I could be wrong about all this, but in any case if you want to be able to explicitly control what you're using, which, unfortunately, you have to in order to be able to specify SSL options to LWP::UserAgent, here's my code:

      # Make sure LWP::UserAgent uses the right kind of socket use IO::Socket::SSL; $NET::HTTPS::SSL_SOCKET_CLASS = 'IO::Socket::SSL'; use LWP::UserAgent; # some servers immediately go radio-silent # if you try SSL versions < 3 our %ssl_options = (SSL_version => 'SSLv3'); ... $ua = LWP::UserAgent->new(ssl_opts => \%ssl_options),

      ((Update (11/5/2014): leave SSL_version alone; see comment below))

      The NET::HTTPS line is for the case where LWP::UserAgent has already been loaded, already chose the wrong default socket implementation because of what was in place when LWP::UserAgent was loaded the first time, and you need to undo that.

      I suppose if you badly need to play nice with other packages that explicitly depend on Net::SSL being used, there's also

      { local $NET::HTTPS::SSL_SOCKET_CLASS = 'IO::Socket::SSL'; $ua = LWP::UserAgent->new(ssl_opts => \%ssl_options), }
      so that only your own invocations of LWP::UserAgent are affected (though there's an argument that could be made that it's the Net::SSL users that should be doing this instead).

        Thank you very much. That was my problem. Forcing to v3 worked.

Log In?
Username:
Password:

What's my password?
Create A New User
Node Status?
node history
Node Type: perlquestion [id://983524]
Approved by BrowserUk
Front-paged by BrowserUk
help
Chatterbox?
and the web crawler heard nothing...

How do I use this? | Other CB clients
Other Users?
Others scrutinizing the Monastery: (7)
As of 2020-07-07 12:12 GMT
Sections?
Information?
Find Nodes?
Leftovers?
    Voting Booth?

    No recent polls found

    Notices?