Bug #50483 for Crypt-SSLeay: Timeout problem on linux

Wed Oct 14 02:28:47 2009 jesper.j.persson [...] gmail.com - Ticket created

Subject:

Timeout problem on linux

This is perl, v5.8.8 built for i386-linux-thread-multi Linux 2.6.18-128.1.16.el5 #1 SMP Tue Jun 30 06:10:28 EDT 2009 i686 i686 i386 GNU/Linux Problem: On linux I get a very long timeout doing a request to a https page that is not responding. On windows it fails after 22 seconds. On linux it fails after 189 seconds. On windows: -------------------------------------------------------------------------------------- require LWP::UserAgent; my $ua = LWP::UserAgent->new; $ua->timeout(10); my $starttime = time; my $response = $ua->get('https://www.laptopshop.co.uk/miscpages/sitealarmcheck.htm'); if ($response->is_success) { print "request sucess\n"; }else { print $response->status_line . "\n"; } my $endtime = time; print "time used: ".($endtime - $starttime)." seconds\n"; ^D500 Connect failed: connect: Unknown error; Unknown error time used: 22 seconds -------------------------------------------------------------------------------------- On linux (CentOS release 5.3 (Final)): -------------------------------------------------------------------------------------- require LWP::UserAgent; my $ua = LWP::UserAgent->new; $ua->timeout(10); my $starttime = time; my $response = $ua->get('https://www.laptopshop.co.uk/miscpages/sitealarmcheck.htm'); if ($response->is_success) { print "request sucess\n"; }else { print $response->status_line . "\n"; } my $endtime = time; print "time used: ".($endtime - $starttime)." seconds\n"; 500 Connect failed: connect: Connection timed out; Connection timed out time used: 189 seconds -------------------------------------------------------------------------------------- I tried to debug perl via the -d switch and I can se that it hangs on line IO::Socket::connect(/usr/lib/perl5/5.8.8/i386-linux-thread-multi/IO/Socket.pm:114): 114: if (!connect($sock, $addr)) { This is the stack trace some steps after the above line: $ = Carp::short_error_loc() called from file `/usr/lib/perl5/5.8.8/Carp/Heavy.pm' line 187 @ = Carp::shortmess_heavy('') called from file `/usr/lib/perl5/5.8.8/Carp.pm' line 260 @ = Carp::shortmess('') called from file `/usr/lib/perl5/5.8.8/Carp.pm' line 269 . = Carp::croak('') called from file `/usr/lib/perl5/site_perl/5.8.8/i386-linux-thread-multi/Net/SSL.pm' line 113 $ = Net::SSL::connect(ref(LWP::Protocol::https::Socket), '^B^@^AM-;^M-eM-!M-W^@^@^@^@^@^@^@^@') called from file `/usr/lib/perl5/5.8.8/IO/Socket/INET.pm' line 199 $ = IO::Socket::INET::configure(ref(LWP::Protocol::https::Socket), ref(HASH)) called from file `/usr/lib/perl5/site_perl/5.8.8/i386-linux-thread-multi/Net/SSL.pm' line 71 $ = Net::SSL::configure(ref(LWP::Protocol::https::Socket), ref(HASH)) called from file `/usr/lib/perl5/site_perl/5.8.8/Net/HTTPS.pm' line 47 $ = Net::HTTPS::http_connect(ref(LWP::Protocol::https::Socket), ref(HASH)) called from file `/usr/lib/perl5/site_perl/5.8.8/Net/HTTP/Methods.pm' line 76 $ = Net::HTTP::Methods::http_configure(ref(LWP::Protocol::https::Socket), ref(HASH)) called from file `/usr/lib/perl5/site_perl/5.8.8/Net/HTTPS.pm' line 42 $ = Net::HTTPS::configure(ref(LWP::Protocol::https::Socket), ref(HASH)) called from file `/usr/lib/perl5/5.8.8/i386-linux-thread-multi/IO/Socket.pm' line 48 $ = IO::Socket::new('LWP::Protocol::https::Socket', 'Proto', 'tcp', 'PeerAddr', 'www.laptopshop.co.uk', 'SendTE', 1, 'PeerPort', 443, 'Timeout', 10, 'KeepAlive', '') called from file `/usr/lib/perl5/5.8.8/IO/Socket/INET.pm' line 32 $ = IO::Socket::INET::new('LWP::Protocol::https::Socket', 'Proto', 'tcp', 'PeerAddr', 'www.laptopshop.co.uk', 'SendTE', 1, 'PeerPort', 443, 'Timeout', 10, 'KeepAlive', '') called from file `/usr/lib/perl5/site_perl/5.8.8/i386-linux-thread-multi/Net/SSL.pm' line 34 $ = Net::SSL::new('LWP::Protocol::https::Socket', 'PeerAddr', 'www.laptopshop.co.uk', 'PeerPort', 443, 'Proto', 'tcp', 'Timeout', 10, 'KeepAlive', '', 'SendTE', 1) called from file `/usr/lib/perl5/site_perl/5.8.8/LWP/Protocol/http.pm' line 31 $ = LWP::Protocol::http::_new_socket(ref(LWP::Protocol::https), 'www.laptopshop.co.uk', 443, 10) called from file `/usr/lib/perl5/site_perl/5.8.8/LWP/Protocol/http.pm' line 149 $ = LWP::Protocol::http::request(ref(LWP::Protocol::https), ref(HTTP::Request), undef, undef, undef, 10) called from file `/usr/lib/perl5/site_perl/5.8.8/LWP/UserAgent.pm' line 173 . = eval {...} called from file `/usr/lib/perl5/site_perl/5.8.8/LWP/UserAgent.pm' line 172 $ = LWP::UserAgent::send_request(ref(LWP::UserAgent), ref(HTTP::Request), undef, undef) called from file `/usr/lib/perl5/site_perl/5.8.8/LWP/UserAgent.pm' line 255 $ = LWP::UserAgent::simple_request(ref(LWP::UserAgent), ref(HTTP::Request), undef, undef) called from file `/usr/lib/perl5/site_perl/5.8.8/LWP/UserAgent.pm' line 263 $ = LWP::UserAgent::request(ref(LWP::UserAgent), ref(HTTP::Request)) called from file `/usr/lib/perl5/site_perl/5.8.8/LWP/UserAgent.pm' line 391 $ = LWP::UserAgent::get(ref(LWP::UserAgent), 'https://www.laptopshop.co.uk/miscpages/sitealarmcheck.htm') called from file `test_https.pl' line 7 It can be a problem to reproduce the bug if the webpage: https://www.laptopshop.co.uk/miscpages/sitealarmcheck.htm starts to respond again.

Sun Aug 15 00:26:51 2010 nanis [...] runu.moc.invalid - Correspondence added

Hello: As you guessed, the server you used in the example seems to be fine now. However, I was able to check this with https://cnn.com/ On Windows, the following script terminates in 2 seconds: C:\Temp> cat t.pl #!/usr/bin/perl use strict; use warnings; use LWP::UserAgent; my $ua = LWP::UserAgent->new; $ua->timeout( 10 ); my $t0 = time; my $response = $ua->get('https://cnn.com/'); print $response->status_line, "\n"; printf "Time used: %d seconds\n", time - $t0; C:\Temp> t 500 Connect failed: connect: Unknown error; Unknown error Time used: 2 seconds On ArchLinux with perl 5.12.1, I get 21 seconds. From strace output: 0.000344 connect(3, { sa_family=AF_INET, sin_port=htons(443), sin_addr=inet_addr("157.166.226.25")}, 16 ) = -1 ETIMEDOUT (Connection timed out) 20.999601 close(3) = 0 This is the same on the old Athlon 1.2GHz machine at home behind an old Linksys wireless router as well as on a Linode. So, I think there is something other than Crypt-SSLeay involved here, maybe some sysctl setting but I am very ignorant when it comes to those things. I am going to change the status of this bug to "stalled". Please re-open it if you find out anything else. Thank you. -- Sinan On Wed Oct 14 02:28:47 2009, jper wrote: Show quoted text

> This is perl, v5.8.8 built for i386-linux-thread-multi > > Linux 2.6.18-128.1.16.el5 #1 SMP Tue Jun 30 06:10:28 EDT 2009 i686 > i686 i386 GNU/Linux > > Problem: > On linux I get a very long timeout doing a request to a https page > that is not responding. > > On windows it fails after 22 seconds. > On linux it fails after 189 seconds. > > On windows: >

-------------------------------------------------------------------------------------- Show quoted text

> require LWP::UserAgent; > my $ua = LWP::UserAgent->new; > $ua->timeout(10); > my $starttime = time; > my $response = $ua-

> >get('https://www.laptopshop.co.uk/miscpages/sitealarmcheck.htm');

> if ($response->is_success) { > print "request sucess\n"; > }else { > print $response->status_line . "\n"; > } > my $endtime = time; > print "time used: ".($endtime - $starttime)." seconds\n"; > > ^D500 Connect failed: connect: Unknown error; Unknown error > time used: 22 seconds >

-------------------------------------------------------------------------------------- Show quoted text

> > On linux (CentOS release 5.3 (Final)): >

-------------------------------------------------------------------------------------- Show quoted text

> require LWP::UserAgent; > my $ua = LWP::UserAgent->new; > $ua->timeout(10); > my $starttime = time; > my $response = $ua-

> >get('https://www.laptopshop.co.uk/miscpages/sitealarmcheck.htm');

> if ($response->is_success) { > print "request sucess\n"; > }else { > print $response->status_line . "\n"; > } > my $endtime = time; > print "time used: ".($endtime - $starttime)." seconds\n"; > > 500 Connect failed: connect: Connection timed out; Connection timed > out > time used: 189 seconds >

-------------------------------------------------------------------------------------- Show quoted text

> > I tried to debug perl via the -d switch and I can se that it hangs on > line > > IO::Socket::connect(/usr/lib/perl5/5.8.8/i386-linux-thread- > multi/IO/Socket.pm:114): > 114: if (!connect($sock, $addr)) { > > This is the stack trace some steps after the above line: > > $ = Carp::short_error_loc() called from file > `/usr/lib/perl5/5.8.8/Carp/Heavy.pm' line 187 > @ = Carp::shortmess_heavy('') called from file > `/usr/lib/perl5/5.8.8/Carp.pm' line 260 > @ = Carp::shortmess('') called from file > `/usr/lib/perl5/5.8.8/Carp.pm' line 269 > . = Carp::croak('') called from file > `/usr/lib/perl5/site_perl/5.8.8/i386-linux-thread-multi/Net/SSL.pm' > line 113 > $ = Net::SSL::connect(ref(LWP::Protocol::https::Socket), '^B^@^AM-;^M- > eM-!M-W^@^@^@^@^@^@^@^@') called from file > `/usr/lib/perl5/5.8.8/IO/Socket/INET.pm' line 199 > $ = IO::Socket::INET::configure(ref(LWP::Protocol::https::Socket), > ref(HASH)) called from file `/usr/lib/perl5/site_perl/5.8.8/i386- > linux-thread-multi/Net/SSL.pm' line 71 > $ = Net::SSL::configure(ref(LWP::Protocol::https::Socket), ref(HASH)) > called from file `/usr/lib/perl5/site_perl/5.8.8/Net/HTTPS.pm' line 47 > $ = Net::HTTPS::http_connect(ref(LWP::Protocol::https::Socket), > ref(HASH)) called from file > `/usr/lib/perl5/site_perl/5.8.8/Net/HTTP/Methods.pm' line 76 > $ = > Net::HTTP::Methods::http_configure(ref(LWP::Protocol::https::Socket), > ref(HASH)) called from file > `/usr/lib/perl5/site_perl/5.8.8/Net/HTTPS.pm' line 42 > $ = Net::HTTPS::configure(ref(LWP::Protocol::https::Socket), > ref(HASH)) called from file `/usr/lib/perl5/5.8.8/i386-linux-thread- > multi/IO/Socket.pm' line 48 > $ = IO::Socket::new('LWP::Protocol::https::Socket', 'Proto', 'tcp', > 'PeerAddr', 'www.laptopshop.co.uk', 'SendTE', 1, 'PeerPort', 443, > 'Timeout', 10, 'KeepAlive', '') called from file > `/usr/lib/perl5/5.8.8/IO/Socket/INET.pm' line 32 > $ = IO::Socket::INET::new('LWP::Protocol::https::Socket', 'Proto', > 'tcp', 'PeerAddr', 'www.laptopshop.co.uk', 'SendTE', 1, 'PeerPort', > 443, 'Timeout', 10, 'KeepAlive', '') called from file > `/usr/lib/perl5/site_perl/5.8.8/i386-linux-thread-multi/Net/SSL.pm' > line 34 > $ = Net::SSL::new('LWP::Protocol::https::Socket', 'PeerAddr', > 'www.laptopshop.co.uk', 'PeerPort', 443, 'Proto', 'tcp', 'Timeout', > 10, 'KeepAlive', '', 'SendTE', 1) called from file > `/usr/lib/perl5/site_perl/5.8.8/LWP/Protocol/http.pm' line 31 > $ = LWP::Protocol::http::_new_socket(ref(LWP::Protocol::https), > 'www.laptopshop.co.uk', 443, 10) called from file > `/usr/lib/perl5/site_perl/5.8.8/LWP/Protocol/http.pm' line 149 > $ = LWP::Protocol::http::request(ref(LWP::Protocol::https), > ref(HTTP::Request), undef, undef, undef, 10) called from file > `/usr/lib/perl5/site_perl/5.8.8/LWP/UserAgent.pm' line 173 > . = eval {...} called from file > `/usr/lib/perl5/site_perl/5.8.8/LWP/UserAgent.pm' line 172 > $ = LWP::UserAgent::send_request(ref(LWP::UserAgent), > ref(HTTP::Request), undef, undef) called from file > `/usr/lib/perl5/site_perl/5.8.8/LWP/UserAgent.pm' line 255 > $ = LWP::UserAgent::simple_request(ref(LWP::UserAgent), > ref(HTTP::Request), undef, undef) called from file > `/usr/lib/perl5/site_perl/5.8.8/LWP/UserAgent.pm' line 263 > $ = LWP::UserAgent::request(ref(LWP::UserAgent), ref(HTTP::Request)) > called from file `/usr/lib/perl5/site_perl/5.8.8/LWP/UserAgent.pm' > line 391 > $ = LWP::UserAgent::get(ref(LWP::UserAgent), > 'https://www.laptopshop.co.uk/miscpages/sitealarmcheck.htm') called > from file `test_https.pl' line 7 > > It can be a problem to reproduce the bug if the webpage: > https://www.laptopshop.co.uk/miscpages/sitealarmcheck.htm > starts to respond again.

Sun Aug 15 00:26:52 2010 The RT System itself - Status changed from 'new' to 'open'

Sun Aug 15 00:26:52 2010 nanis [...] runu.moc.invalid - Status changed from 'open' to 'stalled'

Sun Aug 15 00:46:20 2010 nanis [...] runu.moc.invalid - Correspondence added

In fact, wget takes the same amount of time to report a connection timeout as well (22 seconds on Linux, 2 seconds on Windows). I don't know exactly what's going on here, but it does not look like it is related to Crypt-SSLeay. -- Sinan On Sun Aug 15 00:26:51 2010, NANIS wrote: Show quoted text

> Hello: > > As you guessed, the server you used in the example seems to be fine > now. > However, I was able to check this with https://cnn.com/ > > On Windows, the following script terminates in 2 seconds: > > C:\Temp> cat t.pl > #!/usr/bin/perl > > use strict; use warnings; > > use LWP::UserAgent; > my $ua = LWP::UserAgent->new; > $ua->timeout( 10 ); > > my $t0 = time; > my $response = $ua->get('https://cnn.com/'); > > print $response->status_line, "\n"; > printf "Time used: %d seconds\n", time - $t0; > > > C:\Temp> t > 500 Connect failed: connect: Unknown error; Unknown error > Time used: 2 seconds > > On ArchLinux with perl 5.12.1, I get 21 seconds. > > From strace output: > > 0.000344 connect(3, { > sa_family=AF_INET, > sin_port=htons(443), > sin_addr=inet_addr("157.166.226.25")}, > 16 > ) = -1 ETIMEDOUT (Connection timed out) > 20.999601 close(3) = 0 > > This is the same on the old Athlon 1.2GHz machine at home behind an > old > Linksys wireless router as well as on a Linode. > > So, I think there is something other than Crypt-SSLeay involved here, > maybe some sysctl setting but I am very ignorant when it comes to > those > things. > > I am going to change the status of this bug to "stalled". Please re- > open > it if you find out anything else. > > Thank you. > > -- Sinan > > > On Wed Oct 14 02:28:47 2009, jper wrote:

> > This is perl, v5.8.8 built for i386-linux-thread-multi > > > > Linux 2.6.18-128.1.16.el5 #1 SMP Tue Jun 30 06:10:28 EDT 2009 i686 > > i686 i386 GNU/Linux > > > > Problem: > > On linux I get a very long timeout doing a request to a https page > > that is not responding. > > > > On windows it fails after 22 seconds. > > On linux it fails after 189 seconds. > > > > On windows: > >

Sun Aug 15 00:46:22 2010 The RT System itself - Status changed from 'stalled' to 'open'

Sun Aug 15 00:46:22 2010 nanis [...] runu.moc.invalid - Status changed from 'open' to 'rejected'