Beefy Boxes and Bandwidth Generously Provided by pair Networks
Your skill will accomplish
what the force of many cannot
 
PerlMonks  

Re^2: Errors uncaught by CGI::Carp

by pryrt (Abbot)
on Oct 15, 2021 at 14:17 UTC ( [id://11137584]=note: print w/replies, xml ) Need Help??


in reply to Re: Errors uncaught by CGI::Carp
in thread Errors uncaught by CGI::Carp

What could cause the BEGIN block to execute but not the rest of the script without carpout writing anything at all to the log file???

Are you sure the whole script isn't running? Remember, fatal errors are not the only cause of 500 errors on webservers -- so it might be that the whole script is running without dying, but you are still getting a 500 error. It's sounding to me like your 500 error is not coming from a fatal error in your script -- so not because of a die or croak or similar -- but more likely from a mistake in the output of your script; if so, then your fatalsToBrowser or carpout cannot do anything to help you debug.

A quick example of a script that never dies and successfully runs to the end, but still causes a 500 error on the server:

#!/usr/bin/perl use 5.012; # strict, // use warnings; print "Content-Type: text/plain;\n"; # the missing \n will cause a +500 return code, even though your script has no fatal error, and no d +ie print "Hello World\n";

If the problem is in the output of your script (and my guess is in the header section... or that the headers aren't separated by a newline from the content), not in the execution of your script, then you are going to need some way to duplicate the STDOUT output to also go into the logfile of your choice. I know of two ways to do that.

1: If you can install IO::Tee, or can pipe to the tee command on your server, then you should follow the advice in Copy STDOUT and STDERR to logfile and also display to screen for duplicating your STDOUT into your logfile directly.

2: otherwise, you can redirect your script's STDOUT to an in-memory file in a BEGIN block, then at the END, print the contents of that in-memory variable to a logfile and to the original STDOUT handle. Some example code which will run that on my "erroring script" follows in the spoiler:

#!/usr/bin/perl use 5.014; # strict, //, s//r non-destructive use warnings; use cPanelUserConfig; { use autodie; my $fh_cgiout; my $memory; BEGIN { open $fh_cgiout, '>&', \*STDOUT; # duplicate real S +TDOUT to fh_cgiout: this means if you print to $fh_cgiout, it will ac +tually go to the webserver close STDOUT; # must close STDOU +T before reassigning it open STDOUT, '>', \$memory; # now when the scr +ipt prints, it will "print" the text into memory, for later use } END { # at the very end, just before exiting, duplicate the contents # of the dupout_filename back to the CGI output filehandle (wh +at was originally STDOUT); # start by closing the fake STDOUT and the fh_dupout, so that +the dupout file is safe to read close STDOUT; # next, append the memory contents to the logfile open my $fh, '>>', 'dupout.log'; # append to yo +ur logfile my $prefix = sprintf "DEBUG %5d %s: ", $$, scalar gmtime; # +I suggest a prefix in your logfile, to easily identify process ID and + time for identifying the run print {$fh} ($memory =~ s/^/$prefix/gmr); # prepend ever +y line of memory with the prefix, without editing the memory variable + contents (/r regex option, v5.14) close $fh; # restore the original CGI STDOUT from $fh_cgiout open STDOUT, '>&', $fh_cgiout; # finally, print the memory contents to the original STDOUT, s +o that it will go to the webserver print $memory; # this time pr +int the memory unedited } } print "Content-Type: text/plain;\n"; print "Hello World\n"; __END__

I put that onto my cPanel-based shared-host website, and loaded it in my browser twice: once with the wrong single \n and once with the right \n\n. The first time, there was a 500 error; the second time, it ran just fine. The dupout.log contained:

DEBUG 329772 Fri Oct 15 14:06:30 2021: Content-Type: text/plain; DEBUG 329772 Fri Oct 15 14:06:30 2021: Hello World DEBUG 330420 Fri Oct 15 14:06:42 2021: Content-Type: text/plain; DEBUG 330420 Fri Oct 15 14:06:42 2021: DEBUG 330420 Fri Oct 15 14:06:42 2021: Hello World
... which showed that there weren't enough newlines the first time -- though you have to know enough about the rules for headers vs content to be able derive that from the output.

With that technique, hopefully you can find the difference between a working run and a failing run. (And, like I showed in the example, you should be able to test on your development server, and force a 500 by intentionally creating a bad header, to make sure that the logging is working right and that you've got the printing of the memory block back to the original STDOUT correctly implemented, before trying it live on the server that has the problem.)

Replies are listed 'Best First'.
Re^3: Errors uncaught by CGI::Carp
by Bod (Parson) on Oct 15, 2021 at 17:03 UTC
    Are you sure the whole script isn't running?

    I came to the conclusion that the whole script isn't running because the logfile I am writing to with carpout has a few warnings written to it on a successful run but is blank on an error run. Surely the warnings would still be there on an error run if the script was actually running?

    I am also getting some strange behaviour that I suspect is due to the file output buffer.

    use FindBin qw($RealBin); my $safepath; BEGIN { use CGI::Carp qw(carpout); if ($RealBin =~ m!^(/home/xxx/yyy/(test|uk)/www)!) { $safepath = "$1/../lib"; } else { die "Illegal use of software - visit www.way-finder.uk to use +this site"; } open LOG, '>>', '/home/xxx/yyy/test_error_log.log' or die "Unable +to open error log"; print LOG localtime . " - $ENV{'HTTP_HOST'}\n\n"; carpout(\*LOG); } use lib "$safepath";

    During an error running of the script, the logfile gets created but nothing is written to it despite the print in the BEGIN block. During a successful execution, the timestamp in the BEGIN block gets written to the logfile after the warnings even through it shows an earlier timestamp.

    Thank you for your suggestions. They give me some things to try. I had run out of ideas!

    before trying it live on the server that has the problem

    They are one and the same server - just different domains in the same shared hosting. But yes, I will test it well first.
    This is why I don't think it is a resource issue as there are other domains on the same hosting that have a lot more traffic and carry out more IO than this site which, apart from loading Perl modules, authenticating with Facebook and connecting to the database, does no IO at all. But I am open to any suggestions.

Re^3: Errors uncaught by CGI::Carp
by Bod (Parson) on Oct 15, 2021 at 18:14 UTC
    you can redirect your script's STDOUT to an in-memory file in a BEGIN block, then at the END, print the contents of that in-memory variable to a logfile and to the original STDOUT handle

    I have tried this approach. It is working in the test environment and has been applied to one of the production scripts that I use quite a bit and from which I regularly get 500 errors. And of course, I keep testing and it isn't giving errors...but I am sure it will before long!

    Here is what the top of the script looks like...

    There's some magic in there that I don't fully understand...can I clarify?

    The braces around the first BEGIN and END block are to limit the scope of use autodie; - is that right and is that 'all' they are doing?

    I can see what print {$fh} ($memory =~ s/^/$prefix/gmr); is doing but could not write it from scratch! The braces are needed because the thing that is printed is being calculated on the fly instead of being a constant or intopolated from a variable - is that right?

    Thanks for your help thus far...I have a rapidly growing log file capturing all the stuff output to people's browsers. Hopefully somewhere in that lot I will find the clue that unlocks my understanding of the error.

      The braces around the first BEGIN and END block are to limit the scope of use autodie; - is that right and is that 'all' they are doing?

      Not quite all. They are also supplying scope for the two my-variables, so that they will only be accessible by that BEGIN and END block.

      I can see what print {$fh} ($memory =~ s/^/$prefix/gmr); is doing but could not write it from scratch! The braces are needed because the thing that is printed is being calculated on the fly instead of being a constant or intopolated from a variable - is that right?

      The braces are not needed around $fh. I just got in the habit of using the braces because more complicated filehandle expressions, like $structure{FH}, do require the braces, as described in print. Plus it helps me visually see that the print is going somewhere other than STDOUT. I don't always do that, but I try to usually do it. And the parentheses aren't required either -- but again, I used them for my own readability. AFAICT, print $fh $memory =~ s/^/$prefix/gmr; should work just as well -- though looking at it tells me I much prefer the extra syntax I used before, for personal readability.

      And writing it from scratch wasn't intuitive for me, either: I am new to the non-destructive substitution, so I had to build up to it to make sure I was confident it did what I thought it would.

Re^3: Errors uncaught by CGI::Carp
by Bod (Parson) on Oct 15, 2021 at 21:13 UTC

    I was beginning to think that the test code redirecting STDOUT had somehow cured the problem. I have been using the site for longer than usual without an error from the most used script - the one with the test code. I have an occasional error from other scripts.

    But - I have just had a 500 error.
    Looking at the logfile, the HTML belongs to the previously loaded page, not the one it is trying to load, and the timestamp shows it was the previous page.

    So it looks like the 500 error is happening without the script starting up.

    Again, I have checked the errors and there is nothing other than a few warnings. I have checked the RAM usage and it peaked at 664Mb out of 1Gb allowance over the last 24 hours.

Log In?
Username:
Password:

What's my password?
Create A New User
Domain Nodelet?
Node Status?
node history
Node Type: note [id://11137584]
help
Chatterbox?
and the web crawler heard nothing...

How do I use this?Last hourOther CB clients
Other Users?
Others about the Monastery: (5)
As of 2024-03-28 16:00 GMT
Sections?
Information?
Find Nodes?
Leftovers?
    Voting Booth?

    No recent polls found