StevenMiles
asked on
I'm generating hundreds of megabytes in my error log file from one bad line of code.
I'm experiencing a new problem developing a site, a problem that I didn't have just a week ago. Generally, I upload my perl programs to my server, and in a telnet window I "tail" the error log file. I have warnings turned on. So if I get warnings or terminal errors, I can see the problem right away in the telnet window, fix the code, upload and try again. It's fast and it works.
But now, once in a while I'll hit an error, maybe a minor thing like an uninitialized variable warning, that will generate 2 megabytes of errors *per second* until I stop apache. I don't think I'm in a program loop, and I've looked carefully, I thought. But I got almost a gig of errors before I recognized what was happening the first time!
Here's an excerpt from the log file that is generated:
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cg
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cg
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cg
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cg
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cg
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cg
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.
... and on and on and on. Eventually it mentions the original error again, and then more of this.
This is what's in a BEGIN{} block at the top of the program, SA_PayPal_ipnReturn04.pl:
use CGI::Carp;
use Carp 'cluck';
$SIG{__WARN__} = sub { cluck @_ };
I'm embarrassed to say I don't know why I use that exact syntax. I found it in an article on debugging perl, and I place it at the top of every program, and it has always worked perfectly before. Line 101 is the line that starts "$SIG{__WARN__}"
Of course, correct me if I'm wrong, but it seems that the problem of the error log file filling up is different from the problem of fixing this one particular uninitialized value. I can't have perl filling all the hard disks with the error file and crashing the server every time it sees an error.
I don't know why this hasn't happened for the last 5 months, but it's happening now.
Can you give me ideas of where to go to look for the cause, or a better way to tell perl that I want excellent and convenient warnings and error reporting? I can't use FatalsToBrowser for various reasons -- I want to tail the error log file.
Thanks so much for any insight.
But now, once in a while I'll hit an error, maybe a minor thing like an uninitialized variable warning, that will generate 2 megabytes of errors *per second* until I stop apache. I don't think I'm in a program loop, and I've looked carefully, I thought. But I got almost a gig of errors before I recognized what was happening the first time!
Here's an excerpt from the log file that is generated:
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cg
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cg
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cg
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cg
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cg
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cg
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.
... and on and on and on. Eventually it mentions the original error again, and then more of this.
This is what's in a BEGIN{} block at the top of the program, SA_PayPal_ipnReturn04.pl:
use CGI::Carp;
use Carp 'cluck';
$SIG{__WARN__} = sub { cluck @_ };
I'm embarrassed to say I don't know why I use that exact syntax. I found it in an article on debugging perl, and I place it at the top of every program, and it has always worked perfectly before. Line 101 is the line that starts "$SIG{__WARN__}"
Of course, correct me if I'm wrong, but it seems that the problem of the error log file filling up is different from the problem of fixing this one particular uninitialized value. I can't have perl filling all the hard disks with the error file and crashing the server every time it sees an error.
I don't know why this hasn't happened for the last 5 months, but it's happening now.
Can you give me ideas of where to go to look for the cause, or a better way to tell perl that I want excellent and convenient warnings and error reporting? I can't use FatalsToBrowser for various reasons -- I want to tail the error log file.
Thanks so much for any insight.
Its a warning not an error. If the script works fine, you can just disable warnings. If you use the -w flag on the shebang line, remove it. If you use the warnings pragma:
use warnings;
you can remove it or use:
no warnings;
in the block of code that generates the warning to selectively block that warning.
use warnings;
you can remove it or use:
no warnings;
in the block of code that generates the warning to selectively block that warning.
You might try setting $Carp::MaxArgLen to 0 to get the full message that the $SIG{__WARN__} is passing to cluck.
use CGI::Carp;
use Carp 'cluck';
$Carp::MaxArgLen = 0;
$SIG{__WARN__} = sub { cluck @_ };
That should expand the "Use of uninitialized value in join or string at /home/www/MyDom..." out and ( hopefully) give you the exact location that is causing the warning. It'll probably (almost definitely) be in a loop somewhere. The "called at" line number is just part of your cluck stack trace and is not (shouldn't be) related to the actual cause of your warning.
use CGI::Carp;
use Carp 'cluck';
$Carp::MaxArgLen = 0;
$SIG{__WARN__} = sub { cluck @_ };
That should expand the "Use of uninitialized value in join or string at /home/www/MyDom..." out and ( hopefully) give you the exact location that is causing the warning. It'll probably (almost definitely) be in a loop somewhere. The "called at" line number is just part of your cluck stack trace and is not (shouldn't be) related to the actual cause of your warning.
ASKER
I have more information on the problem, and I've raised the point value of the question to 500.
I believe I've traced the problem to the end of the program, where I print to STDERR the contents of a hash just before the program exits, so that I can see what processing took place during the program. Here is the offending code:
foreach $key (sort keys (%vs))
{print STDERR "--ProfilePageExit---$key = $vs{$key}\n"}
The uninitialized error happens when I try to print the key and value for a hash element that was assigned an undefined value. Earlier in the program was this line:
$vs{"HTTP_COOKIE"} = $ENV{"HTTP_COOKIE"};
If there is no cookie, this line does *not* issue a warning, but trying to print the hash to STDERR *does*.
From looking at the logs, I think the offending program was run by a robot, but I can generate the same problem by first deleting my cookies and running the program myself.
But the biggest problem is that, instead of just giving me a warning, it blasts the error log file with so much material that if I stop apache within even a couple of seconds, I still have 15 megs of warnings. This will crash my server.
I deleted my cookie, so the error could happen, and ran the program. Here's what came out in STDERR. It's a line with the date and time, showing that I'm about to exit the program, and then a listing of the values of all hash elements. There was no $ENV{"HTTP_COOKIE"}, so $vs{"HTTP_COOKIE"} was undefined. I get a reasonable warning, followed by the line containing HTTP_COOKIE, followed by more elements of the hash:
--08:53:28, Mon Feb 11, 2008-----ProfilePage Exit Point--------------
--ProfilePageExit---Affili
--ProfilePageExit---AllUse
--ProfilePageExit---Domain
Use of uninitialized value in concatenation (.) or string at /home/www/MyDomain/root/cg
at /home/www/MyDomain/root/cg
Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cg
Profile::run() called at /home/www/MyDomain/root/cg
ModPerl::ROOT::ModPerl::Re
eval {...} called at /usr/lib/perl5/vendor_perl
ModPerl::RegistryCooker::r
ModPerl::RegistryCooker::d
ModPerl::Registry::handler
eval {...} called at -e line 0
--ProfilePageExit---HTTP_C
--ProfilePageExit---HomePa
--ProfilePageExit---HomeUR
--ProfilePageExit---Loggin
... and more elements. Lines 1000 and 1001 in the program were the lines that said:
foreach $key (sort keys (%vs))
{print STDERR "--ProfilePageExit---$key = $vs{$key}\n"}
This was not a problem.
Then I refreshed the browser to run the program again. I got the same thing: a reasonable warning at the same location. The warning is identical with the exception of some hex things that I don't understand:
--08:53:54, Mon Feb 11, 2008-----ProfilePage Exit Point--------------
--ProfilePageExit---Affili
--ProfilePageExit---AllUse
--ProfilePageExit---Domain
Use of uninitialized value in concatenation (.) or string at /home/www/MyDomain/root/cg
at /home/www/MyDomain/root/cg
Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cg
Profile::run() called at /home/www/MyDomain/root/cg
ModPerl::ROOT::ModPerl::Re
eval {...} called at /usr/lib/perl5/vendor_perl
ModPerl::RegistryCooker::r
ModPerl::RegistryCooker::d
ModPerl::Registry::handler
eval {...} called at -e line 0
--ProfilePageExit---HTTP_C
--ProfilePageExit---HomePa
--ProfilePageExit---HomeUR
--ProfilePageExit---Loggin
This was also not a problem. But then I refreshed the browser a third time, and perl started to blast the megabytes of errors to the log file. Each warning of this set that was filling up the log file was identical to the previous two warnings, except for those hex items, and *also* with the exception that the last two lines are a little different. I'll quote from the log file again, putting asterisks around the different lines just before the warning starts up again:
--08:54:14, Mon Feb 11, 2008-----ProfilePage Exit Point--------------
--ProfilePageExit---Affili
--ProfilePageExit---AllUse
--ProfilePageExit---Domain
DESCRIPTION OF DIAGNOSTICS
These messages are classified as follows (listed in increasing order of
desperation):
[I removed the Description of Diagnostics here]
Use of uninitialized value in concatenation (.) or string at
/home/www/MyDomain/root/cg
(W uninitialized) An undefined value was used as if it were already
defined. It was interpreted as a "" or a 0, but maybe it was a mistake.
To suppress this warning assign a defined value to your variables.
[more description of diagnostics here]
Use of uninitialized value in concatenation (.) or string at /home/www/MyDomain/root/cg
at /home/www/MyDomain/root/cg
Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cg
Profile::run() called at /home/www/MyDomain/root/cg
ModPerl::ROOT::ModPerl::Re
eval {...} called at /usr/lib/perl5/vendor_perl
ModPerl::RegistryCooker::r
ModPerl::RegistryCooker::d
**ModPerl::Registry::handl
eval {...} called at /home/www/MyDomain/root/cg
Use of uninitialized value in concatenation (.) or string at /home/www/MyDomain/root/cg
at /home/www/MyDomain/root/cg
Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cg
Profile::run() called at /home/www/MyDomain/root/cg
ModPerl::ROOT::ModPerl::Re
eval {...} called at /usr/lib/perl5/vendor_perl
ModPerl::RegistryCooker::r
ModPerl::RegistryCooker::d
**ModPerl::Registry::handl
eval {...} called at /home/www/MyDomain/root/cg
at /home/www/MyDomain/root/cg
Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /usr/lib/perl5/5.8.8/Carp.
Carp::cluck('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cg
Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cg
Profile::run() called at /home/www/MyDomain/root/cg
ModPerl::ROOT::ModPerl::Re
eval {...} called at /usr/lib/perl5/vendor_perl
ModPerl::RegistryCooker::r
ModPerl::RegistryCooker::d
**ModPerl::Registry::handl
eval {...} called at /home/www/MyDomain/root/cg
Use of uninitialized value in concatenation (.) or string at /home/www/MyDomain/root/cg
at /home/www/MyDomain/root/cg
... and it goes on and on. There are other patterns I found, but I didn't want to quote everything out of the log.
When I changed this line:
$vs{"HTTP_COOKIE"} = $ENV{"HTTP_COOKIE"};
to this:
if (defined($ENV{"HTTP_COOKIE
{$vs{"HTTP_COOKIE"} = $ENV{"HTTP_COOKIE"}}
...of course the warnings wouldn't happen at all. But I'm not looking to correct this one error. I'm trying to see why perl will throw out enough warnings to crash my server!
/SD
I believe I've traced the problem to the end of the program, where I print to STDERR the contents of a hash just before the program exits, so that I can see what processing took place during the program. Here is the offending code:
foreach $key (sort keys (%vs))
{print STDERR "--ProfilePageExit---$key = $vs{$key}\n"}
The uninitialized error happens when I try to print the key and value for a hash element that was assigned an undefined value. Earlier in the program was this line:
$vs{"HTTP_COOKIE"} = $ENV{"HTTP_COOKIE"};
If there is no cookie, this line does *not* issue a warning, but trying to print the hash to STDERR *does*.
From looking at the logs, I think the offending program was run by a robot, but I can generate the same problem by first deleting my cookies and running the program myself.
But the biggest problem is that, instead of just giving me a warning, it blasts the error log file with so much material that if I stop apache within even a couple of seconds, I still have 15 megs of warnings. This will crash my server.
I deleted my cookie, so the error could happen, and ran the program. Here's what came out in STDERR. It's a line with the date and time, showing that I'm about to exit the program, and then a listing of the values of all hash elements. There was no $ENV{"HTTP_COOKIE"}, so $vs{"HTTP_COOKIE"} was undefined. I get a reasonable warning, followed by the line containing HTTP_COOKIE, followed by more elements of the hash:
--08:53:28, Mon Feb 11, 2008-----ProfilePage Exit Point--------------
--ProfilePageExit---Affili
--ProfilePageExit---AllUse
--ProfilePageExit---Domain
Use of uninitialized value in concatenation (.) or string at /home/www/MyDomain/root/cg
at /home/www/MyDomain/root/cg
Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cg
Profile::run() called at /home/www/MyDomain/root/cg
ModPerl::ROOT::ModPerl::Re
eval {...} called at /usr/lib/perl5/vendor_perl
ModPerl::RegistryCooker::r
ModPerl::RegistryCooker::d
ModPerl::Registry::handler
eval {...} called at -e line 0
--ProfilePageExit---HTTP_C
--ProfilePageExit---HomePa
--ProfilePageExit---HomeUR
--ProfilePageExit---Loggin
... and more elements. Lines 1000 and 1001 in the program were the lines that said:
foreach $key (sort keys (%vs))
{print STDERR "--ProfilePageExit---$key = $vs{$key}\n"}
This was not a problem.
Then I refreshed the browser to run the program again. I got the same thing: a reasonable warning at the same location. The warning is identical with the exception of some hex things that I don't understand:
--08:53:54, Mon Feb 11, 2008-----ProfilePage Exit Point--------------
--ProfilePageExit---Affili
--ProfilePageExit---AllUse
--ProfilePageExit---Domain
Use of uninitialized value in concatenation (.) or string at /home/www/MyDomain/root/cg
at /home/www/MyDomain/root/cg
Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cg
Profile::run() called at /home/www/MyDomain/root/cg
ModPerl::ROOT::ModPerl::Re
eval {...} called at /usr/lib/perl5/vendor_perl
ModPerl::RegistryCooker::r
ModPerl::RegistryCooker::d
ModPerl::Registry::handler
eval {...} called at -e line 0
--ProfilePageExit---HTTP_C
--ProfilePageExit---HomePa
--ProfilePageExit---HomeUR
--ProfilePageExit---Loggin
This was also not a problem. But then I refreshed the browser a third time, and perl started to blast the megabytes of errors to the log file. Each warning of this set that was filling up the log file was identical to the previous two warnings, except for those hex items, and *also* with the exception that the last two lines are a little different. I'll quote from the log file again, putting asterisks around the different lines just before the warning starts up again:
--08:54:14, Mon Feb 11, 2008-----ProfilePage Exit Point--------------
--ProfilePageExit---Affili
--ProfilePageExit---AllUse
--ProfilePageExit---Domain
DESCRIPTION OF DIAGNOSTICS
These messages are classified as follows (listed in increasing order of
desperation):
[I removed the Description of Diagnostics here]
Use of uninitialized value in concatenation (.) or string at
/home/www/MyDomain/root/cg
(W uninitialized) An undefined value was used as if it were already
defined. It was interpreted as a "" or a 0, but maybe it was a mistake.
To suppress this warning assign a defined value to your variables.
[more description of diagnostics here]
Use of uninitialized value in concatenation (.) or string at /home/www/MyDomain/root/cg
at /home/www/MyDomain/root/cg
Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cg
Profile::run() called at /home/www/MyDomain/root/cg
ModPerl::ROOT::ModPerl::Re
eval {...} called at /usr/lib/perl5/vendor_perl
ModPerl::RegistryCooker::r
ModPerl::RegistryCooker::d
**ModPerl::Registry::handl
eval {...} called at /home/www/MyDomain/root/cg
Use of uninitialized value in concatenation (.) or string at /home/www/MyDomain/root/cg
at /home/www/MyDomain/root/cg
Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cg
Profile::run() called at /home/www/MyDomain/root/cg
ModPerl::ROOT::ModPerl::Re
eval {...} called at /usr/lib/perl5/vendor_perl
ModPerl::RegistryCooker::r
ModPerl::RegistryCooker::d
**ModPerl::Registry::handl
eval {...} called at /home/www/MyDomain/root/cg
at /home/www/MyDomain/root/cg
Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /usr/lib/perl5/5.8.8/Carp.
Carp::cluck('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cg
Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cg
Profile::run() called at /home/www/MyDomain/root/cg
ModPerl::ROOT::ModPerl::Re
eval {...} called at /usr/lib/perl5/vendor_perl
ModPerl::RegistryCooker::r
ModPerl::RegistryCooker::d
**ModPerl::Registry::handl
eval {...} called at /home/www/MyDomain/root/cg
Use of uninitialized value in concatenation (.) or string at /home/www/MyDomain/root/cg
at /home/www/MyDomain/root/cg
... and it goes on and on. There are other patterns I found, but I didn't want to quote everything out of the log.
When I changed this line:
$vs{"HTTP_COOKIE"} = $ENV{"HTTP_COOKIE"};
to this:
if (defined($ENV{"HTTP_COOKIE
{$vs{"HTTP_COOKIE"} = $ENV{"HTTP_COOKIE"}}
...of course the warnings wouldn't happen at all. But I'm not looking to correct this one error. I'm trying to see why perl will throw out enough warnings to crash my server!
/SD
Try:
print STDERR "--ProfilePageExit---$key = $vs{$key}\n" if $vs{$key};
print STDERR "--ProfilePageExit---$key = $vs{$key}\n" if $vs{$key};
ASKER
Hi, clockwatcher,
Thank you so much for your input. Respectfully, though, I'm much less interested in how to prevent this one line from generating an error, and much more interested in why, in general, a problem can generate errors that can crash my server if I don't stop apache immediately. I worry that some other small error in another program will take down my server because of this problem.
Thank you so much for your input. Respectfully, though, I'm much less interested in how to prevent this one line from generating an error, and much more interested in why, in general, a problem can generate errors that can crash my server if I don't stop apache immediately. I worry that some other small error in another program will take down my server because of this problem.
ASKER CERTIFIED SOLUTION
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
If you remove the call to cluck, does the problem go away:
$SIG{__WARN__} = sub{return;};
$SIG{__WARN__} = sub{return;};
/home/www/MyDomain/root/cg
Is it easy to initialize the variable?
If looks like your program is in a tight loop so that lots of error messages are generated.