Beefy Boxes and Bandwidth Generously Provided by pair Networks
Syntactic Confectionery Delight
 
PerlMonks  

HTTP error response code 500 using LWP::UserAgent on one site, but not on any other

by ted.byers (Scribe)
on Nov 16, 2012 at 20:32 UTC ( #1004238=perlquestion: print w/ replies, xml ) Need Help??
ted.byers has asked for the wisdom of the Perl Monks concerning the following question:

This is a real puzzle. I am trying to determine why a script works on my workstation (Windows 7), but not on either of two servers running Windows Server 2008. We're using Activestate perl, and the behaviour is identical regardless of whether we use 5.12, 5.14 or 5.16, with the latest release of LWP.

I have a basic script that I used to teach a colleague about Perl web programming. It reproduces the problem exactly. Here it is:

use strict; use Log::Log4perl qw(:easy get_logger); use LWP::UserAgent; use HTTP::Request; use HTTP::Request::Common; use HTTP::Response; use HTTP::Status; $| = 1; my $ua = LWP::UserAgent->new; $ua->add_handler("request_send", sub { log_it("Request: ".shift->dump +); return }); $ua->add_handler("response_done", sub { my $rsp = shift; my @red = $rs +p->redirects; my $r; foreach $r (@red) {log_it("Response redirect: ". +$r)}; log_it("Response last request: ".$rsp->request->uri); log_it("R +esponse headers: ".$rsp->headers_as_string); log_it("Response code: " +.$rsp->code); my $msg = status_message($rsp->code); log_it("Response +status: ".$msg) if defined $msg; log_it("Response status: ".$rsp->sta +tus_line); return }); # Define configuration my $conf = q( log4perl.logger = TRACE, FileApp, ScreenApp log4perl.appender.FileApp = Log::Log4perl::Appender:: +File log4perl.appender.FileApp.filename = lwp.log log4perl.appender.FileApp.layout = PatternLayout log4perl.appender.FileApp.layout.ConversionPattern = %d> %m%n log4perl.appender.ScreenApp = Log::Log4perl::Appender +::Screen log4perl.appender.ScreenApp.stderr = 0 log4perl.appender.ScreenApp.layout = PatternLayout log4perl.appender.ScreenApp.layout.ConversionPattern = %d> %m% +n ); # Initialize logging behaviour Log::Log4perl->init( \$conf ); Log::Log4perl->infiltrate_lwp(); my $logger = get_logger(); my $req_url = $ARGV[0]; if ($req_url =~ m/http/) { $req_url = "$req_url"; } else { $req_url = "http://$req_url"; } # whether you use GET or POST, both shown below, depends on what the # server accepts. try both, preferring POST my $response = $ua->request(POST "$req_url"); my $code = $response->code; if ($code == 405) { $response = $ua->request(GET "$req_url"); } # #my $response = $ua->request(POST "$req_url",/%parms); # print "\n===================================================\n"; # print "The response, as a string, is:\n"; # print $response->as_string; # print "\n===================================================\n"; #if ( $response->is_redirect ) { if (($code > 299) && ($code < 400)) { print $response->previous . " redirected to location " . $respons +e->header('Location') . "\n"; print "The content is: ",$response->content,"\n"; print "\n===================================================\n"; print "The response, as a string, is:\n"; print $response->as_string; print "\n===================================================\n"; $logger->info($response->previous . " redirected to location " . +$response->header('Location')); } else { if ($response->is_success) { print "The content is: ",$response->content,"\n"; $logger->info("The URL $req_url was successfully retrieved."); if (lc($response->content)=~m/'error_response'/){ $logger->warn("Response problematic content: ".$response->conten +t); } } else { $logger->warn("The URL $req_url was not successfully retrieved."); } } sub log_it { my $tmp = shift; $tmp =~ s/\n+/,\t/g; $tmp =~ s/,\t$//; $logger->info($tmp); return; }

Now, if I use the above code, and pass, as the argument either 'www.google.ca' or 'https://www.google.ca', All works fine. If, instead, I pass the URL for the querying API I need to use, I get a server error, response code #500. The really bizarre aspect of this is that submitting the same request using MS IE or Firefox works as expected. That suggests that LWP is producing something different from what, or failing to produce something that, the two most common web browsers produce.

The senior tech guy at the company providing the service says that that is happening before the request even gets to his PHP script. He asked that I provide him with all the HTTP headers, along with the complete request, so that he and his team can figure out why only those requests from this script on the two servers fail at his end, and yet the precisely the same code, running on my Windows 7 workstation, succeeds. I can not imagine why the same code would generate different headers depending on which machine it is running on (in all cases, the machines running the script live behind good firewalls).

I guess there are three questions here. First, how do I modify the above script so that instead of actually sending the request to the server in question, it simply writes everything it would normally send to a file instead? This is critical, so that the tech guys at the company providing the API can begin their investigations more thoroughly, with better information. The man was truly baffled as to why a 500 error would be produced by his system. Second, how do I debug this? I did see LWP::Debug, but it's documentation says it is deprecated. I would expect, therefore, that there would be some recent alternative. Is there a directive or variable I can use that would tell LWP to produce debug info, but not actually send the data to the server? And is there a directive to use or a variable that can be set that would result in LWP sending output to standard out representing everything that happens between the client and server, from the point where the two set up an SSL session to the point where the server sends the final response? (I'd really like to be able to do this without manually stepping through the code with a debugger - and I'd like to be able to send such a trace to the folk responsible for the API I am using - knowing at what stage in that dialog the error happens would likely be priceless to them.) Third, does anyone have an thoughts on why precisely the same code would work fine on one machine but fail on another?

It is important to emphasize that this code worked fine on another server since 2007, and only failed once we tried to deploy it to a new machine (in the cloud, if that matters). It is also important to emphasize that making the request seconds after the failed attempt with the script, but using MS IE or Firefox, succeeds; so there is no issue related to connectivity.

Any ideas?

Thanks

Ted

Comment on HTTP error response code 500 using LWP::UserAgent on one site, but not on any other
Download Code
Re: HTTP error response code 500 using LWP::UserAgent on one site, but not on any other
by Old_Gray_Bear (Bishop) on Nov 16, 2012 at 21:02 UTC
    An HTTP 500 error is a general error message issued by the server when no more specific 5xx message is appropriate. You will need to get the log(s) from the failing server to determine what exactly is going sour.

    As a work around, you can have LWP send a user agent string identifying your 'browser' and one of the browsers that the remote server accepts. Note: this may lead to other "compatibility" issues.

    ----
    I Go Back to Sleep, Now.

    OGB

      Thanks OGB.

      That is actually being done by the technical staff at the company that is providing the service. I have used such logs for my own web servers countless times to diagnose problems:usualy related to my own cgi programs, but sometimes to diagnose why my users encounter troubles.

      That said, I doubt that he'd let me examine his logs, any more than I would let an outside developer examine my logs.

      Do you have any thoughts on how to tell LWP to write the headers and request to a file instead of sending them to a server; or perhaps how to have it send to the logger suitable output for every step of the process of hand-shaking between the client and server, from the moment the connection is initiated to the moment the response is sent?

      Thanks again.

      Ted>

        They should be able to give you and extract of their logs if you provide them with a start and end time and the source host name/address. It's no big thing to filter a log for the time stamps in your range and then filter for your particular address. ISPs and their ilk have to do that to comply with a court-ordered "wiretap". (Or, how did they get the Generals email?)

        ----
        I Go Back to Sleep, Now.

        OGB

      An HTTP 500 error is a general error message issued by the server when no more specific 5xx message is appropriate.

      Correct. But LWP may also generate 500 errors, as a way to communicate fatal errors to the caller:

      #!/usr/bin/perl use 5.010; use strict; use warnings; use LWP::UserAgent; use Data::Dumper; my $ua=LWP::UserAgent->new(); my $resp=$ua->get("http://no.such.server.in.my.lan/no-such-page"); say $resp->status_line; say Dumper $resp;
      500 Can't connect to no.such.server.in.my.lan:80 (Bad hostname) $VAR1 = bless( { '_content' => 'Can\'t connect to no.such.server.in.my +.lan:80 (Bad hostname) LWP::Protocol::http::Socket: Bad hostname \'no.such.server.in.my.lan\' + at /usr/lib64/perl5/site_perl/5.12.3/LWP/Protocol/http.pm line 51. ', '_rc' => 500, '_headers' => bless( { 'client-warning' => 'Internal +response', 'client-date' => 'Sat, 17 Nov +2012 19:32:13 GMT', 'content-type' => 'text/plain' }, 'HTTP::Headers' ), '_msg' => 'Can\'t connect to no.such.server.in.my.lan +:80 (Bad hostname)', '_request' => bless( { '_content' => '', '_uri' => bless( do{\(my $o = +'http://no.such.server.in.my.lan/no-such-page')}, 'URI::http' ), '_headers' => bless( { 'user-a +gent' => 'libwww-perl/6.02' }, 'HTTP: +:Headers' ), '_method' => 'GET' }, 'HTTP::Request' ) }, 'HTTP::Response' );

      Alexander

      --
      Today I will gladly share my knowledge and experience, for there are no sweeter words than "I told you so". ;-)
Re: HTTP error response code 500 using LWP::UserAgent on one site, but not on any other
by aitap (Deacon) on Nov 16, 2012 at 21:12 UTC
    You can try running Wireshark to catch all packets your machine sends to the server.
    Sorry if my advice was wrong.

      Thanks

      Yes, I have tried using Wireshark in the past. I am sure some find it useful, but I had some trouble getting it's user interface to do anything that was useful for me. Part of the problem is it gets everything; most of which is irrelevant to the problem at hand. It would be more useful if it could be told to get the traffic only between my client script and the server it is trying to connect to.

      Thanks again

      Ted

        You need to write a filter expression. In your case it should look like http && ip.addr == <server's IP address> (see example).
        Sorry if my advice was wrong.
Re: HTTP error response code 500 using LWP::UserAgent on one site, but not on any other
by ted.byers (Scribe) on Nov 19, 2012 at 22:20 UTC

    I just heard from the head tech guy at the company responsible for the service I am using. He is wondering if my "CA Store does/can not support EV1 (Extended Validation) SSL Certificates." He is asking if I can "try and update your(my) CA store?" How would I do that? Further, might it be a question of configuration, as I would expect that the CA stores on the servers, which are much newer than my workstation, would be much more current than that on my workstation.

    Any thoughts on how I ought to proceed on this?

    Thanks

    Ted

Log In?
Username:
Password:

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

How do I use this? | Other CB clients
Other Users?
Others drinking their drinks and smoking their pipes about the Monastery: (8)
As of 2014-10-26 03:46 GMT
Sections?
Information?
Find Nodes?
Leftovers?
    Voting Booth?

    For retirement, I am banking on:










    Results (150 votes), past polls