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.pm line 272
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cgi-bin/SA_PayPal_ipnReturn04.pl line 101
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.pm line 272
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cgi-bin/SA_PayPal_ipnReturn04.pl line 101
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.pm line 272
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cgi-bin/SA_PayPal_ipnReturn04.pl line 101
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.pm line 272
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cgi-bin/SA_PayPal_ipnReturn04.pl line 101
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.pm line 272
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cgi-bin/SA_PayPal_ipnReturn04.pl line 101
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.pm line 272
Carp::cluck('Use of uninitialized value in join or string at /home/www/MyDom...') called at /home/www/MyDomain/root/cgi-bin/SA_PayPal_ipnReturn04.pl line 101
IPN_Return::__ANON__('Use of uninitialized value in join or string at /home/www/MyDom...') called at /usr/lib/perl5/5.8.8/Carp.pm line 272

... 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.

StevenMilesAsked:
Who is Participating?
I wear a lot of hats...

"The solutions and answers provided on Experts Exchange have been extremely helpful to me over the last few years. I wear a lot of hats - Developer, Database Administrator, Help Desk, etc., so I know a lot of things but not a lot about one thing. Experts Exchange gives me answers from people who do know a lot about one thing, in a easy to use platform." -Todd S.

Kim RyanIT ConsultantCommented:
Have you looked at this line
/home/www/MyDomain/root/cgi-bin/SA_PayPal_ipnReturn04.pl line 101
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.
0
Perl_DiverCommented:
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.
0
clockwatcherCommented:
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.
0
Newly released Acronis True Image 2019

In announcing the release of the 15th Anniversary Edition of Acronis True Image 2019, the company revealed that its artificial intelligence-based anti-ransomware technology – stopped more than 200,000 ransomware attacks on 150,000 customers last year.

StevenMilesAuthor Commented:
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---AffiliatesDirectory = /home/www/MyDomain/affiliates
--ProfilePageExit---AllUsersDirectory = /home/www/MyDomain/all_users
--ProfilePageExit---DomainName = MyDomain.net
Use of uninitialized value in concatenation (.) or string at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 1000.
 at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 26
      Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 1000
      Profile::run() called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage.pl line 31
      ModPerl::ROOT::ModPerl::Registry::home_www_MyDomain_root_cgi_2dbin_SA_ProfilePage_2epl::handler('Apache2::RequestRec=SCALAR(0x8ec9d64)') called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/RegistryCooker.pm line 203
      eval {...} called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/RegistryCooker.pm line 203
      ModPerl::RegistryCooker::run('ModPerl::Registry=HASH(0x8ec9cb0)') called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/RegistryCooker.pm line 169
      ModPerl::RegistryCooker::default_handler('ModPerl::Registry=HASH(0x8ec9cb0)') called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/Registry.pm line 30
      ModPerl::Registry::handler('ModPerl::Registry', 'Apache2::RequestRec=SCALAR(0x8ec9d64)') called at -e line 0
      eval {...} called at -e line 0
--ProfilePageExit---HTTP_COOKIE =
--ProfilePageExit---HomePath = /home/www/MyDomain
--ProfilePageExit---HomeURL = http://www.MyDomain.net
--ProfilePageExit---LoggingIn = 0

... 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---AffiliatesDirectory = /home/www/MyDomain/affiliates
--ProfilePageExit---AllUsersDirectory = /home/www/MyDomain/all_users
--ProfilePageExit---DomainName = MyDomain.net
Use of uninitialized value in concatenation (.) or string at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 1000.
 at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 26
      Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 1000
      Profile::run() called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage.pl line 31
      ModPerl::ROOT::ModPerl::Registry::home_www_MyDomain_root_cgi_2dbin_SA_ProfilePage_2epl::handler('Apache2::RequestRec=SCALAR(0x8ec9d1c)') called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/RegistryCooker.pm line 203
      eval {...} called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/RegistryCooker.pm line 203
      ModPerl::RegistryCooker::run('ModPerl::Registry=HASH(0x8eb8c48)') called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/RegistryCooker.pm line 169
      ModPerl::RegistryCooker::default_handler('ModPerl::Registry=HASH(0x8eb8c48)') called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/Registry.pm line 30
      ModPerl::Registry::handler('ModPerl::Registry', 'Apache2::RequestRec=SCALAR(0x8ec9d1c)') called at -e line 0
      eval {...} called at -e line 0
--ProfilePageExit---HTTP_COOKIE =
--ProfilePageExit---HomePath = /home/www/MyDomain
--ProfilePageExit---HomeURL = http://www.MyDomain.net
--ProfilePageExit---LoggingIn = 0

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---AffiliatesDirectory = /home/www/MyDomain/affiliates
--ProfilePageExit---AllUsersDirectory = /home/www/MyDomain/all_users
--ProfilePageExit---DomainName = MyDomain.net
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/cgi-bin/SA_ProfilePage04.pl line 1000 (#1)
    (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/cgi-bin/SA_ProfilePage04.pl line 1000.
 at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 26
      Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 1000
      Profile::run() called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage.pl line 31
      ModPerl::ROOT::ModPerl::Registry::home_www_MyDomain_root_cgi_2dbin_SA_ProfilePage_2epl::handler('Apache2::RequestRec=SCALAR(0x8ec9ce0)') called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/RegistryCooker.pm line 203
      eval {...} called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/RegistryCooker.pm line 203
      ModPerl::RegistryCooker::run('ModPerl::Registry=HASH(0x8ec9e30)') called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/RegistryCooker.pm line 169
      ModPerl::RegistryCooker::default_handler('ModPerl::Registry=HASH(0x8ec9e30)') called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/Registry.pm line 30
      **ModPerl::Registry::handler('ModPerl::Registry', 'Apache2::RequestRec=SCALAR(0x8ec9ce0)') called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 0
      eval {...} called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 0 (#1)**
Use of uninitialized value in concatenation (.) or string at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 1000.
 at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 26
      Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 1000
      Profile::run() called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage.pl line 31
      ModPerl::ROOT::ModPerl::Registry::home_www_MyDomain_root_cgi_2dbin_SA_ProfilePage_2epl::handler('Apache2::RequestRec=SCALAR(0x8ec9ce0)') called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/RegistryCooker.pm line 203
      eval {...} called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/RegistryCooker.pm line 203
      ModPerl::RegistryCooker::run('ModPerl::Registry=HASH(0x8ec9e30)') called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/RegistryCooker.pm line 169
      ModPerl::RegistryCooker::default_handler('ModPerl::Registry=HASH(0x8ec9e30)') called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/Registry.pm line 30
      **ModPerl::Registry::handler('ModPerl::Registry', 'Apache2::RequestRec=SCALAR(0x8ec9ce0)') called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 0
      eval {...} called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 0**
 at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 26
      Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /usr/lib/perl5/5.8.8/Carp.pm line 272
      Carp::cluck('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 26
      Profile::__ANON__('Use of uninitialized value in concatenation (.) or string at ...') called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 1000
      Profile::run() called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage.pl line 31
      ModPerl::ROOT::ModPerl::Registry::home_www_MyDomain_root_cgi_2dbin_SA_ProfilePage_2epl::handler('Apache2::RequestRec=SCALAR(0x8ec9ce0)') called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/RegistryCooker.pm line 203
      eval {...} called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/RegistryCooker.pm line 203
      ModPerl::RegistryCooker::run('ModPerl::Registry=HASH(0x8ec9e30)') called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/RegistryCooker.pm line 169
      ModPerl::RegistryCooker::default_handler('ModPerl::Registry=HASH(0x8ec9e30)') called at /usr/lib/perl5/vendor_perl/5.8.8/i386-linux-thread-multi/ModPerl/Registry.pm line 30
      **ModPerl::Registry::handler('ModPerl::Registry', 'Apache2::RequestRec=SCALAR(0x8ec9ce0)') called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 0
      eval {...} called at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 0 (#1) **
Use of uninitialized value in concatenation (.) or string at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 1000.
 at /home/www/MyDomain/root/cgi-bin/SA_ProfilePage04.pl line 26
 
 ... 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


0
clockwatcherCommented:
Try:

print STDERR "--ProfilePageExit---$key = $vs{$key}\n" if $vs{$key};
0
StevenMilesAuthor Commented:
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.
0
clockwatcherCommented:
If you're not sure that the modules you're using aren't free of warnings then:

   $SIG{__WARN__} = sub { cluck @_ };

Is probably a bad idea.  If you happen to hit a warning in CGI::Carp, you might get an infinite loop.  I don't know if that's what is going on...very hard to tell since you're not getting the full text of where exactly the warning is happening ('Use of uninitialized value in concatenation (.) or string at ...' isn't helpful --- you need the full text of the warning to be of any use) but it's possible that the warning is happening within CGI::Carp itself,  if it is then that'd explain your problem.

If you posted your script somewhere where we could take a look at it, replicate the problem and step it through a debugger, it'd probably be easier to help.
0

Experts Exchange Solution brought to you by

Your issues matter to us.

Facing a tech roadblock? Get the help and guidance you need from experienced professionals who care. Ask your question anytime, anywhere, with no hassle.

Start your 7-day free trial
Adam314Commented:
If you remove the call to cluck, does the problem go away:
$SIG{__WARN__} = sub{return;};
0
It's more than this solution.Get answers and train to solve all your tech problems - anytime, anywhere.Try it for free Edge Out The Competitionfor your dream job with proven skills and certifications.Get started today Stand Outas the employee with proven skills.Start learning today for free Move Your Career Forwardwith certification training in the latest technologies.Start your trial today
Scripting Languages

From novice to tech pro — start learning today.