| Subject: | New placeholders (CSPECS) for PatternLayout %R |
The following patch adds the placeholder (cspecs) %R which prints the
number of milliseconds elapsed from the last logging event to the
current logging event.
This new cspecs is quite useful in order to quickly find the logging
events that are near "hotspots". Thus, this cspecs can be used as a poor
man's profiler.
This cspecs is implented as a built-in cspecs instead of a custom one in
order to reuse the same code and the same value used by the timestamp
that's used to for the cspecs %r. This way both %r and %R can be used at
the same time without any penalty.
| Subject: | PatternLayout.pm.patch |
--- PatternLayout.pm 2008-01-11 21:34:41.000000000 +0100
+++ /usr/share/perl5/Log/Log4perl/Layout/PatternLayout.pm 2008-01-11 22:07:06.000000000 +0100
@@ -20,7 +20,7 @@
our %GLOBAL_USER_DEFINED_CSPECS = ();
-our $CSPECS = 'cCdFHIlLmMnpPrtTxX%';
+our $CSPECS = 'cCdFHIlLmMnpPrRtTxX%';
BEGIN {
@@ -79,6 +79,7 @@
stack => [],
CSPECS => $CSPECS,
dontCollapseArrayRefs => $options->{dontCollapseArrayRefs}{value},
+ last_time => undef,
};
if(exists $options->{time_function}) {
@@ -229,7 +230,7 @@
$info{P} = $$;
$info{H} = $HOSTNAME;
- if($self->{info_needed}->{r}) {
+ if($self->{info_needed}->{r} || $self->{info_needed}->{R}) {
if($TIME_HIRES_AVAILABLE) {
$info{r} =
int((Time::HiRes::tv_interval ( $PROGRAM_START_TIME ))*1000);
@@ -241,6 +242,12 @@
$info{r} = time() - $PROGRAM_START_TIME;
}
}
+ if($self->{info_needed}->{R}) {
+ my $current_time = $info{r};
+ my $last_time = $self->{last_time} || $current_time;
+ $info{R} = $current_time - $last_time;
+ $self->{last_time} = $current_time;
+ }
# Stack trace wanted?
if($self->{info_needed}->{T}) {
@@ -476,6 +483,8 @@
%P pid of the current process
%r Number of milliseconds elapsed from program start to logging
event
+ %R Number of milliseconds elapsed from last logging event to
+ logging event
%T A stack trace of functions called
%x The topmost NDC (see below)
%X{key} The entry 'key' of the MDC (see below)