zuser has asked for the wisdom of the Perl Monks concerning the following question:

Hello Monks, i am having a weird problem.

I have a fast cgi perl program running on apache 1.3 / mod_fastcgi-2.4.2 / perl 5.6.1

At the beginning of the program i redirect STDERR, so as not to clutter /usr/local/apache/logs/error_log. I use the following code for doing this.

sub redirect_elog { my ($file) = @_; local *LCSTDERR; open(LCSTDERR, ">>$file") or die "Can't open log file $file"; open(STDERR, ">&LCSTDERR") or die "can't redirect standard error"; }
This works just fine.
When i use the same fastcgi perl program in another machine, but here using perl 5.8.5 the problem starts.

In this case some of the error messages are redirected to the file i specify and some others go to the main STDERR !! ie /usr/local/apache/logs/error_log

This splitting of errors happens only with fastcgi and not with regular cgi scripts.

One more thing i noted was, when the warn messages land up in the file i specified, they contain only the message i printed, ie if in my program i had a message like warn "err message going to log", in my redirected file i would get just the line "err message going to log" line,

while in the err messages that is being printed to /usr/local/apache/logs/error_log, ie STDERR, the message will have the usual apache errlog prefix of datetime + ip, ie i will have a message in the logs like

[Thu Aug 17 11:32:17 2006] [ error] [client 12.12.42.12] err message going to log

so i imagine, whatever messages are going to STDERR are going through apaches ap_log_error method wherin the date and ip are added to the msg

can anyone please throw some light on this, so that the err messages does not land up in STDERR ie /usr/local/apache/logs/error_log, but goes instead to the redirected log file

thanks very much

Replies are listed 'Best First'.
Re: fastcgi stderr redirect problems
by shmem (Chancellor) on Aug 17, 2006 at 16:35 UTC
    Hello zuser,

    some (more) code would be handy. Otherwise, we have to guess.

    But as for just guessing, you localize LCSTDERR to your subroutine block. I wonder whether that's sensible.

    At which point do you invoke redirect_elog? Do you have a global *LCSTDERR ?

    What happens if you just open(STDERR, ">>$file") or die - does the behaviour persist?

    --shmem

    _($_=" "x(1<<5)."?\n".q·/)Oo.  G°\        /
                                  /\_¯/(q    /
    ----------------------------  \__(m.====·.(_("always off the crowd"))."·
    ");sub _{s./.($e="'Itrs `mnsgdq Gdbj O`qkdq")=~y/"-y/#-z/;$e.e && print}
      Hello shmem,

      Thanks for you reply.

      i call redirect_elog the first thing in the program and i tried the other approach too ie  open(STDERR, ">>$file") or die, it still gives the same problem.

      The code i have is something like this.
      #!/usr/local/bin/perl -wT use strict; use TEST::App::MainApp; $SIG{__WARN__} = \&warn_handler; redirect_error_log("/export/home/rdave/logs/error_log"); my $app = TEST::App::MainApp() $app->run_loop(); use constant MAX_MSGLEN => 1022; sub warn_handler { my $msg = join "", @_; # print to STDERR $msg = "[" . "$$|" . time2iso() . "] " . $msg; # send in chunks, if necessary while (length $msg > MAX_MSGLEN) { my $chunk = substr($msg, 0, MAX_MSGLEN); $msg = substr($msg, MAX_MSGLEN); warn $chunk, "\n"; } warn $msg; }
      Then in the run_loop in another package

      sub run_loop { my ($self) = @_; my $requester = $self->requester; $self->{_REQUEST_NUMBER}=0; # initialize the request counter while (my $input = $requester->new_request()) { $self->_reset_timings; # start request timing begin_timing('REQUEST'); $self->scratch->init; ++$self->{_REQUEST_NUMBER}; warn "[--] Starting a new request $self->{_REQUEST_NUMBER} (Cl +ient: $ENV{REMOTE_ADDR}) ...\n"; $self->{_INPUT} = $input; # read application configuration $self->config_object->getConfig($self->name()); # process request $self->_process_request; # finish the request $requester->close_request(); $self->invoke_post_request_callbacks; # end request timing $self->timing('REQUEST', time_since('REQUEST')); warn "[--] Finished handling request $self->{_REQUEST_NUMBER} +...\n"; $self->post_request; }
      I am not changing or redirecting STDERR anywhere else in the program other than the first time. In the above code snippet the first warn goes to /usr/local/apache/logs/error_log and the bottom one goes to local log file. The code is spread over 1000s of lines, so sorry could'nt post it, but one thing is sure, that the program is not touching STDERR/redirect_elog/LCSTDERR elsewhere and this one works fine with perl 5.6.1 and behaving this way with perl 5.8.5
        Sorry for the delay.

        Hint: You set up a SIG{__WARN__} handler. Inside the handler subroutine you call warn. What is perl supposed to do at this point? Does it just warn or does it call the handler subroutine? What is in $SIG{__WARN__} after the call to the handler subroutine? What is fileno 2 in the handler subroutine?

        Since you are calling redirect_error_log only once at the beginning of the app, you should put the code of that sub into a BEGIN block to avoid confusion.

        --shmem

        _($_=" "x(1<<5)."?\n".q·/)Oo.  G°\        /
                                      /\_¯/(q    /
        ----------------------------  \__(m.====·.(_("always off the crowd"))."·
        ");sub _{s./.($e="'Itrs `mnsgdq Gdbj O`qkdq")=~y/"-y/#-z/;$e.e && print}