http://qs321.pair.com?node_id=925535


in reply to Re: log4perl and efficiency
in thread log4perl and efficiency

I really think this has more to do with variable interpolation than it does with log4perl.

Comparing example A:

$self->{logger}->trace("total NbObsThis $i=$nbObservedThisNGram->[$i];
+ nbObsAll $i=$nbObservedAllNGrams->[$i]; total=$totalObservedAll; nbE
+xpected $i=$nbExpectedThis[$i]; chisq = $chiSquare[$i]");

[download]

with example B:

$self->{logger}->trace('no interpolation');

[download]

would be useful to demonstrate the difference in overhead between perl internals and log4perl. You're going to be stuck with interpolation performance no matter what logging framework you use.

Replies are listed 'Best First'.
Re^3: log4perl and efficiency
by erwan (Sexton) on Sep 12, 2011 at 19:03 UTC

    I don't think so, I mean in the first place I got rid of this interpolation problem by testing the log level using a call to Log4perl: 

    if ($self->{logger}->is_trace()) { # for efficiency (not to compute th
+e expression) 
            $self->{logger}->trace("total NbObsThis $i=$nbObservedThis
+NGram->[$i]; nbObsAll $i=$nbObservedAllNGrams->[$i]; total=$totalObse
+rvedAll; nbExpected $i=$nbExpectedThis[$i]; chisq = $chiSquare[$i]")
}

    [download]

    It helped indeed, but the cost of "is_trace()" was still prohibitive. Then I added a new variable $self->{disableLogger} set to true if the level is OFF (testing the log level only once) and replaced the condition with 

    if (!$self->{disableLogger} && $self->{logger}->is_trace()) { # test f
+or efficiency (not to compute the expression) {
            $self->{logger}->trace("total NbObsThis $i=$nbObservedThis
+NGram->[$i]; nbObsAll $i=$nbObservedAllNGrams->[$i]; total=$totalObse
+rvedAll; nbExpected $i=$nbExpectedThis[$i]; chisq = $chiSquare[$i]")
}

    [download]

    and this takes way less time (according to NYTProf). As previously said, it seems that a simple call to is_debug() (no interpolation) implies a complex (and long) computation in Log4perl.

[reply]
[d/l]
[select]

      Better yet, use a constant instead of a hashref lookup, and the whole if block will be obliterated at compile time when you disable debugging.

      use constant DEBUG => 0;
...
if (DEBUG) {
    # complex logging, which disappears from the op tree
}

      [download]

      FWIW, my experience has been like Solo's, where you end up inadvertently evaluating the arguments to the logging methods, and this takes a lot of time (or a little bit of time in a tight loop that's called a zillion times).

[reply]
[d/l]

In Section Seekers of Perl Wisdom