mschilli / log4perl Goto Github PK

Hi,
I have written a module that actually uses Log4Perl as logging system. This is how I use Log4Perl:

package MyPackage;

use Log::Log4perl;

my $logger = Log::Log4perl->get_logger();
...
$logger->info("foo bar");

Now, I don't know if the logger it was initialized or not by the main program. If not, the main program receives:

Log4perl: Seems like no initialization happened. Forgot to call init()?

Is there a transparent way to use Log4perl only if the main has configured it? So that the get_logger() returns always an instance that doesn't do nothing.

Actually I have in the main program:

use Log::Log4perl;
$Log::Log4perl::Logger::INITIALIZED = 1;

but I think that a module should be independent from who use it.

Thank you in advance,
Emanuele

If Time::HiRes is not available, t/013Bench.t fails:

t/012Deeper.t ............. ok
Can't locate Time/HiRes.pm in @INC (you may need to install the Time::HiRes module) (@INC contains: /builddir/build/BUILD/Log-Log4perl-1.52/blib/lib /builddir/build/BUILD/Log-Log4perl-1.52/blib/arch /usr/local/lib64/perl5/5.32 /usr/local/share/perl5/5.32 /usr/lib64/perl5/vendor_perl /usr/share/perl5/vendor_perl /usr/lib64/perl5 /usr/share/perl5 .) at /builddir/build/BUILD/Log-Log4perl-1.52/blib/lib/Log/Log4perl/Util/TimeTracker.pm line 19.
BEGIN failed--compilation aborted at /builddir/build/BUILD/Log-Log4perl-1.52/blib/lib/Log/Log4perl/Util/TimeTracker.pm line 22.
Compilation failed in require at /builddir/build/BUILD/Log-Log4perl-1.52/blib/lib/Log/Log4perl/Layout/PatternLayout.pm line 17.
BEGIN failed--compilation aborted at /builddir/build/BUILD/Log-Log4perl-1.52/blib/lib/Log/Log4perl/Layout/PatternLayout.pm line 17.
Compilation failed in require at /builddir/build/BUILD/Log-Log4perl-1.52/blib/lib/Log/Log4perl/Layout.pm line 5.
BEGIN failed--compilation aborted at /builddir/build/BUILD/Log-Log4perl-1.52/blib/lib/Log/Log4perl/Layout.pm line 5.
Compilation failed in require at /builddir/build/BUILD/Log-Log4perl-1.52/blib/lib/Log/Log4perl/Logger.pm line 11.
BEGIN failed--compilation aborted at /builddir/build/BUILD/Log-Log4perl-1.52/blib/lib/Log/Log4perl/Logger.pm line 11.
Compilation failed in require at /builddir/build/BUILD/Log-Log4perl-1.52/blib/lib/Log/Log4perl.pm line 14.
BEGIN failed--compilation aborted at /builddir/build/BUILD/Log-Log4perl-1.52/blib/lib/Log/Log4perl.pm line 14.
Compilation failed in require at t/013Bench.t line 10.
BEGIN failed--compilation aborted at t/013Bench.t line 10.
t/013Bench.t .............. 
Dubious, test returned 22 (wstat 5632, 0x1600)
No subtests run 
Undefined subroutine &Log::Log4perl::Logger::cleanup called at /builddir/build/BUILD/Log-Log4perl-1.52/blib/lib/Log/Log4perl.pm line 5.
END failed--call queue aborted at t/013Bench.t line 10.

I can see that lib/Log/Log4perl/Util/TimeTracker.pm loads Time::HiRes only if Log::Log4perl::Util::module_available returns true. Compiling TimeTracker.pm indeed succeeds. But Benchmark in the t/013Bench.t does something strange that confuses module_available():

$ perl -Ilib -e 'use Log::Log4perl;'
$ perl -Ilib -e 'use Benchmark; use Log::Log4perl;'
Can't locate Time/HiRes.pm in @INC (you may need to install the Time::HiRes module) (@INC contains: lib /usr/local/lib64/perl5/5.32 /usr/local/share/perl5/5.32 /usr/lib64/perl5/vendor_perl /usr/share/perl5/vendor_perl /usr/lib64/perl5 /usr/share/perl5) at lib/Log/Log4perl/Util/TimeTracker.pm line 19.
[...]

Log4Perl still has this warning when logging undef:

perl -W -Ilib -e 'use Log::Log4perl qw(:easy); Log::Log4perl->easy_init($INFO); INFO(undef)'
Use of uninitialized value in join or string at lib/Log/Log4perl/Appender.pm line 167.

It was last detailed in this mailing list thread:
http://www.mail-archive.com/[email protected]/msg00454.html

Hello,

#!/usr/bin/perl

use strict;
use warnings;

use Log::Log4perl;
use Log::Log4perl::Level;

my $log_conf = q/ 
    log4perl.rootLogger = INFO, Root

    log4perl.appender.Root                          = Log::Log4perl::Appender::Screen 
    log4perl.appender.Root.layout                   = Log::Log4perl::Layout::PatternLayout
    log4perl.appender.Root.layout.ConversionPattern = [Root] %m%n
/;
Log::Log4perl::init( \$log_conf );
my $logger = Log::Log4perl::get_logger();

my $logger2 = Log::Log4perl::get_logger('independentLogger');
my $stdout_appender = Log::Log4perl::Appender->new( 'Log::Log4perl::Appender::Screen', name => 'Independent' );
my $layout = Log::Log4perl::Layout::PatternLayout->new( '[Independent] %m%n' );
$stdout_appender->layout( $layout );
$logger2->add_appender( $stdout_appender );
$logger2->level( $INFO );
$logger2->additivity( 0 ); # doesn't work

$logger->info("foo");
$logger2->info("bar"); # outputs with independentLogger AND rootLogger :(

While "additivity" in init() works :

#!/usr/bin/perl

use strict;
use warnings;

use Log::Log4perl;

my $log_conf = q/ 
    log4perl.rootLogger = INFO, Root

    log4perl.appender.Root                          = Log::Log4perl::Appender::Screen 
    log4perl.appender.Root.layout                   = Log::Log4perl::Layout::PatternLayout
    log4perl.appender.Root.layout.ConversionPattern = [Root] %m%n

    log4perl.logger.independentLogger     = INFO, Independent
    log4perl.additivity.independentLogger = 0

    log4perl.appender.Independent                          = Log::Log4perl::Appender::Screen 
    log4perl.appender.Independent.layout                   = Log::Log4perl::Layout::PatternLayout
    log4perl.appender.Independent.layout.ConversionPattern = [Independent] %m%n
/;
Log::Log4perl::init( \$log_conf );
my $logger = Log::Log4perl::get_logger();
my $logger2 = Log::Log4perl::get_logger('independentLogger');

$logger->info("foo");
$logger2->info("bar"); # works, outputs with independentLogger only

Why is... those things ?

I want to get appender file name using logger object.

my $log_conf = {
   'log4perl.rootLogger'             => "DEBUG, LOG1, SCREEN",
   'log4perl.appender.SCREEN'        => "Log::Log4perl::Appender::Screen",
   'log4perl.appender.SCREEN.stderr' => "0",
   'log4perl.appender.SCREEN.layout' => "Log::Log4perl::Layout::PatternLayout",
   'log4perl.appender.SCREEN.layout.ConversionPattern' =>
     "CloudAuTOM:%d{yyyy_MMM_d H:m:s}_" . get_ip_address() . "_%C::: %m %n",
   'log4perl.appender.LOG1'          => "Log::Log4perl::Appender::File",
   'log4perl.appender.LOG1.filename' => file_path($file_name, $path),
   #'log4perl.appender.LOG1.mode'                        => "append",
   'log4perl.appender.LOG1.layout' => "Log::Log4perl::Layout::PatternLayout",
   'log4perl.appender.LOG1.layout.ConversionPattern' =>
     "CloudAuTOM:%d{yyyy_MMM_d H:m:s}_%C::: %m %n"
};
Log::Log4perl->init($log_conf);
my $logger = Log::Log4perl->get_logger($file_name);
  
# somewhat like below:
print $logger->filename;  

I went over doc and it says that I can access appenders using appender_by_name() class method.
I tried to access it using the command $logger->appender_by_name(), but it is returning me following error

Can't locate object method "appender_by_name" via package "Log::Log4perl::Logger"

Following is the dump of my logger object:

$VAR1 = bless( {
                 'TRACE' => sub { "DUMMY" },
                 'DEBUG' => sub { "DUMMY" },
                 'FATAL' => $VAR1->{'DEBUG'},
                 'additivity' => 1,
                 'level' => undef,
                 'layout' => undef,
                 'appender_names' => [],
                 'OFF' => $VAR1->{'DEBUG'},
                 'is_WARN' => sub { "DUMMY" },
                 'is_TRACE' => sub { "DUMMY" },
                 'is_OFF' => sub { "DUMMY" },
                 'is_DEBUG' => sub { "DUMMY" },
                 'ERROR' => $VAR1->{'DEBUG'},
                 'is_INFO' => sub { "DUMMY" },
                 'is_ERROR' => sub { "DUMMY" },
                 'is_ALL' => sub { "DUMMY" },
                 'WARN' => $VAR1->{'DEBUG'},
                 'INFO' => $VAR1->{'DEBUG'},
                 'num_appenders' => 0,
                 'is_FATAL' => sub { "DUMMY" },
                 'category' => 'autom_controller.log',
                 'ALL' => $VAR1->{'TRACE'}
               }, 'Log::Log4perl::Logger' );

https://rt.cpan.org/Public/Bug/Display.html?id=110512

in Log::Log4perl::Filter::Boolean line 54:

    my $filter = Log::Log4perl::Filter::by_name($1);
    die "Filter $filter required by Boolean filter, but not defined" 
        unless $filter;

Use of uninitialized value $filter in concatenation (.) or string at /path/to/Log/Log4perl/Filter/Boolean.pm line 55.
Filter required by Boolean filter, but not defined at /path/to/Log/Log4perl/Filter/Boolean.pm line 55.

i guess $1 containes the name of the filter.

You have ease_init
Log::Log4perl->easy_init( { level => $DEBUG,
file => ">>test.log",
category => "Bar::Twix",
layout => '%F{1}-%L-%M: %m%n' },
{ level => $DEBUG,
file => "STDOUT",
category => "Bar::Mars",
layout => '%m%n' },
);
it will be very good to allow to add appenders in such way.
Log::Log4perl->add_appender( { ... } ); --- everything that easy_init do, except reseting current configuration

Hello,

Attached are two test cases:

• testing console only (works fine)
• testing console + mail (crashed when initializing Log4perl object)

I updated Log4perl and Specio (see $VERSION values) and still get the crash:

PERL5LIB=$HOME/lib/perl/share/perl perl console-and-mail-log4perl.pl
$Log::Log4perl::VERSION=1.54
$Specio::VERSION=0.47
Validation failed for type named Bool declared in package Specio::Library::Builtins (/home/sblondeel/lib/perl/share/perl/5.28.1/Specio/Library/Builtins.pm) at line 69 in sub named (eval) with value 100

Trace begun at Specio::Exception->new line 57
Specio::Exception::throw('Specio::Exception', 'message', 'Validation failed for type named Bool declared in package Specio::Library::Builtins (/home/sblondeel/lib/perl/share/perl/5.28.1/Specio/Library/Builtins.pm) at line 69 in sub named (eval) with value 100', 'type', 'Specio::Constraint::Simple=HASH(0x5654cdc94ab0)', 'value', 100) called at (eval 150) line 79
Eval::Closure::Sandbox_4::ANON('min_level', 'debug', 'name', 'mail', 'buffered', 100, 'subject', 'Log4perl speaking', 'to', 'sblondeel+log4perl@localhost', 'l4p_post_config_subs', 'ARRAY(0x5654cd5116a8)', 'l4p_depends_on', 'ARRAY(0x5654cd50cee8)', 'Threshold', 'WARN') called at /usr/share/perl5/Log/Dispatch/Email.pm line 39
Log::Dispatch::Email::new('Log::Dispatch::Email::MailSend', 'min_level', 'debug', 'name', 'mail', 'buffered', 100, 'subject', 'Log4perl speaking', 'to', 'sblondeel+log4perl@localhost', 'l4p_post_config_subs', 'ARRAY(0x5654cd5116a8)', 'l4p_depends_on', 'ARRAY(0x5654cd50cee8)', 'Threshold', 'WARN') called at /home/sblondeel/lib/perl/share/perl/5.28.1/Log/Log4perl/Appender.pm line 83
Log::Log4perl::Appender::new('Log::Log4perl::Appender', 'Log::Dispatch::Email::MailSend', 'name', 'mail', 'l4p_post_config_subs', 'ARRAY(0x5654cd5116a8)', 'l4p_depends_on', 'ARRAY(0x5654cd50cee8)', 'to', 'sblondeel+log4perl@localhost', 'subject', 'Log4perl speaking', 'Threshold', 'WARN', 'buffered', 100) called at /home/sblondeel/lib/perl/share/perl/5.28.1/Log/Log4perl/Config.pm line 413
Log::Log4perl::Config::create_appender_instance('HASH(0x5654cd404690)', 'mail', 'HASH(0x5654cd511678)', 'ARRAY(0x5654cd5116a8)', undef) called at /home/sblondeel/lib/perl/share/perl/5.28.1/Log/Log4perl/Config.pm line 305
Log::Log4perl::Config::_init('Log::Log4perl::Config', '/tmp/log4perl-console.conf') called at /home/sblondeel/lib/perl/share/perl/5.28.1/Log/Log4perl/Config.pm line 36
Log::Log4perl::Config::init('Log::Log4perl::Config', '/tmp/log4perl-console.conf') called at /home/sblondeel/lib/perl/share/perl/5.28.1/Log/Log4perl.pm line 253
Log::Log4perl::init('Log::Log4perl', '/tmp/log4perl-console.conf') called at console-and-mail-log4perl.pl line 36

console-and-mail-log4perl.pl.txt
console-log4perl.pl.txt

Just encountered a non-reproducible failing test - The previous test run succeeded, and there were no changes in the repository between the two runs.

make[2]: Entering directory `/var/hudson/jobs/workspace/.../Log-Log4perl-1.28'
PERL_DL_NONLAZY=1 /usr/bin/perl "-MExtUtils::Command::MM" "-e" "test_harness(0, 'blib/lib', 'blib/arch')" t/*.t

#   Failed test 'init-and-watch caller level third'
#   at t/027Watch2.t line 170.
#                   '2011/07/12 03:01:37 [undef] [undef]> third 
# '
#     doesn't match '(?-xism:027Watch2.t 168> third)'

#   Failed test 'init-and-watch caller level third'
#   at t/027Watch2.t line 181.
#                   '2011/07/12 03:01:39 [undef] [undef]> third 
# '
#     doesn't match '(?-xism:027Watch2.t 179> third)'
# Looks like you failed 2 tests of 20.

Using logconfess() ends in logging every part of the stacktrace in a single line:

2017/09/15 09:09:05 ich sterbe! at test_logfatal.pl.pm line 13.
2017/09/15 09:09:05     class1::foo("class1") called at test_logfatal.pl.pm line 21
2017/09/15 09:09:05     class2::foo("class2") called at test_logfatal.pl.pm line 28
2017/09/15 09:09:05     class3::foo("class3") called at test_logfatal.pl.pm line 39
2017/09/15 09:09:05     eval {...} called at test_logfatal.pl.pm line 39

Here is the example code:

use strict;
use warnings;

package class1;
   use Log::Log4perl qw(get_logger);
    sub foo() {
        my $logger = get_logger();
        $logger->logconfess("ich sterbe!");
    }

package class2;
    sub foo() { class1->foo(); }

package class3;
    sub foo() { class2->foo(); }

package main;
    use Carp;
    use Log::Log4perl qw(:easy);
    Log::Log4perl->easy_init({level => Log::Log4perl::Level->INFO_INT});
    my $logger = get_logger();
    eval { class3->foo() };
    if ($@) {
    ... 
    }

Using an email-appender this behaviour results in sending one email for every line of the stacktrace. Not nice.

How can I force logconfess to write one logmessage with stacktrace instead of multiple lines?
At the end I want to get only one email for the whole logmessage.

Tried using cpanm.

t/025CustLevels.t ......... ok

#   Failed test 'header_text'
#   at t/026FileApp.t line 459.
#          got: 'This is a nice header.
# This is a nice header.
# DEBUG - waah!
# '
#     expected: 'This is a nice header.
# DEBUG - waah!
# '
# Looks like you failed 1 test of 27.
t/026FileApp.t ............ 

Seems like a place where I'd be safe to use --force so low urgency. The line in question seems to be

is($content, "This is a nice header.\nDEBUG - waah!\n", "header_text");

So it's likely a \n vs \r\n thing.

I see where Sys::Syslog supports a host options on the setlogsock() call, and I see where Log::Dispatch::Syslog lets you pass an arrayref for the socket option that it will pass through to Sys::Syslog::setlogsock(). However, in looking at the code for Log::Log4perl::JavaMap::SyslogAppender, it doesn't look like it does anything with the $socket option/variable (either in terms of initializing it or using it/passing it to Log::Dispatch::Syslog. Is this an oversight or am I missing something obvious? Thanks.

If you set syswrite=1 on the Log::Log4perl::Appender::File appender, the header_text option ceases to work. If you look at the code:

sub file_open {
    [...]
    if(defined $self->{header_text}) {
        [...]
        my $fh = $self->{fh};
        print $fh $self->{header_text};
    }
}

the cause is apparent. It is using print rather than syswrite, and you can't mix syswrite and STDIO on the same file descriptor.

Recommended fix would be to factor out the writter code from log() and call it from both log() and the above code.

Using Log4Perl 1.40 with Perl 5.16.2 results in the warning:

"close() on unopened filehandle FH at Log/Log4perl/Appender/File.pm line 257 during global destruction."

According to the Perl 5.16.2 documentation for perlobj:
"If your DESTROY method issues a warning during global destruction, the Perl interpreter will append the string " during global destruction" the warning."

It appears the global destruction phase in Perl automatically closes open file handles causing the DESTROY method to output the warning when it attempts to close the file handle.

$ perl -v
This is perl 5, version 16, subversion 3 (v5.16.3) built for x86_64-linux

Failed test 'gmtime != localtime'
at t/070UTCDate.t line 63.
got: '11:52:54
'
expected: anything else
Looks like you failed 1 test of 2.
t/070UTCDate.t ............
Dubious, test returned 1 (wstat 256, 0x100)
Failed 1/2 subtests

Test Summary Report
t/070UTCDate.t (Wstat: 256 Tests: 2 Failed: 1)
Failed test: 2
Non-zero exit status: 1
Files=73, Tests=718, 31 wallclock secs ( 0.22 usr 0.02 sys + 2.75 cusr 0.28 csys = 3.27 CPU)
Result: FAIL
Failed 1/73 test programs. 1/718 subtests failed.

Hi, is there a possibility tht log4perl is also affected by the CVE-2021-44228?

I couldn't find any reference to JNDI or something similar.

Thanks in advance!

More information about CVE-2021-44228 here: https://blog.cloudflare.com/inside-the-log4j2-vulnerability-cve-2021-44228/

A configuration like so will not apply the max_col_size option and truncate the 7th bind field [message]:

log4perl.appender.DBI.sql = INSERT INTO log(logDate, filename, lineNum, logLevel, ip, userNum,message) VALUES (?,?,?,?,?,?,?)
log4perl.appender.DBI.params.1 = %d{yyyy-MM-dd HH:mm:ss}
log4perl.appender.DBI.params.2 = %F
log4perl.appender.DBI.params.3 = %L
log4perl.appender.DBI.params.4 = %p
log4perl.appender.DBI.params.5 = %X{ip}
log4perl.appender.DBI.params.6 = %X{user}
log4perl.appender.DBI.usePreparedStmt = 1
log4perl.appender.DBI.layout = Log::Log4perl::Layout::NoopLayout
log4perl.appender.DBI.warp_message = 0
log4perl.appender.DBI.max_col_size = 10

You can see in the code that the max_col_size is never applied to the "leftovers".

If I change the order of my binds however the max_col_size will be applied to the message field -

log4perl.appender.DBI.sql = INSERT INTO log(logDate, filename, lineNum, logLevel, ip, message, usernum) VALUES (?,?,?,?,?,?,?)
log4perl.appender.DBI.params.1 = %d{yyyy-MM-dd HH:mm:ss}
log4perl.appender.DBI.params.2 = %F
log4perl.appender.DBI.params.3 = %L
log4perl.appender.DBI.params.4 = %p
log4perl.appender.DBI.params.5 = %X{ip}
log4perl.appender.DBI.params.7 = %X{user}
log4perl.appender.DBI.usePreparedStmt = 1
log4perl.appender.DBI.layout = Log::Log4perl::Layout::NoopLayout
log4perl.appender.DBI.warp_message = 0
log4perl.appender.DBI.max_col_size = 10

Easy to fix and make a PR but I'm not sure if I am missing something else with how things are meant to work.

not ok 23 - header_text
#   Failed test 'header_text'
#   at t\026FileApp.t line 460.
#          got: 'This is a nice header.
# This is a nice header.
# DEBUG - waah!
# '
#     expected: 'This is a nice header.
# DEBUG - waah!
# '

Looks like a double-write, but i expect it's just something about getting confused by \r.

The following snippet will generate an error like this:

Modification of a read-only value attempted at /usr/share/perl5/Log/Dispatch/Output.pm line 32.

Snippet:

#!/usr/bin/perl -w
use strict;
use Log::Log4perl;
BEGIN {
    my $config = q(
        log4perl.logger=WARN, Debug
        log4perl.appender.Debug=Log::Dispatch::File
        log4perl.appender.Debug.filename=/tmp/debug.log
        log4perl.appender.Debug.mode=append
        log4perl.appender.Debug.layout=Log::Log4perl::Layout::SimpleLayout
    );
    Log::Log4perl::init(\$config);
    my $logger = Log::Log4perl->get_logger('module');
    $SIG{__DIE__} = sub {
        my $err = join("", @_);
        chomp $err;
        $logger->fatal($err);
    };
}
# die "I'm dying";
my $foo = $nonExistingVar;

If instead one enables the die line, and comments out the $nonExistingVar line, it works as expected, and the error gets put in the log.

This is caused by this bug in Params::Validate
https://rt.cpan.org/Public/Bug/Display.html?id=60467
Params::Validate is called by Log::Dispatch, which Log::Log4perl uses. So this but doesn't originate in Log4perl, I just saw it in Log4perl and wanted to mention it here, so that others won't go hunting like I had to. Go ahead and mark it as invalid or whatever similar state is appropriate for github.

I think there is already a PR for attempting to fix abort w/ Log::Log4perl::Catalyst. Albeit, I wanted to create an issue item for discussion, prior to a merge. This issue is also on the heel of using Catalyst::Plugin::Static::Simple.

It would appear, that abort does not work in the expected fashion of Catalyst::Log, rather it clears all of the appender's buffers when abort is called, when it should be at time = _flush(). Since there is no checking of $self->{abort} in flush, flush could have buffers which were populated after abort was called. This functionally seems to ignore abort's expected outcome. Currently, abort is more akin to a 'clear_buffers' type of function.

If I'm understanding the module correctly, would it be best to make a call to abort more of a setter, which flush then checks and operates on?

I'm thinking something like:

##################################################
sub _flush {
##################################################
    my ($self) = @_;

    for my $appender (values %Log::Log4perl::Logger::APPENDER_BY_NAME) {
        next if $appender->{name} !~ /_$CATALYST_APPENDER_SUFFIX$/;

        if ($self->{abort}) {
            $appender->{appender}{buffer} = [];
        }
        else {
            $appender->flush();
        }
    }

    $self->abort(undef);
}

##################################################
sub abort {
##################################################
    my $self = shift;

    $self->{abort} = $_[0] if @_;

    return $self->{abort};
}

Thanks, @mschilli for producing this wonder module.
Pinging @bokutin

Hi, I am using property configuration. And now I need to use dots in names for some fields. For example:

JsonLayout.field.browser.name = Firefox

In this case I want to get field like that:

field->{'browser.name'} == 'Firefox'

So I propose to use some char sequence as dot. For example if we gonna use '~1' char sequence as dot, than configuration, which will look like this:

JsonLayout.field.browser~1name = Firefox

And field hash will look like this:

field->{'browser.name'} == 'Firefox'

Can we do this? I can create pull request for this, if you like this idea

I honestly don't understand why this warning is being generated - I've run the code through a debugger and that variable appears to be initialized. But here's a simple test program to generate it, if anyone wants to troubleshoot it.

use Log::Log4perl;

my $config = q(
log4perl.rootLogger = DEBUG, screen
log4perl.appender.screen = Log::Log4perl::Appender::Screen
log4perl.appender.screen.stderr = 0
log4perl.appender.screen.layout = Log::Log4perl::Layout::SimpleLayout
);

Log::Log4perl->init( $config );

my $logger = Log::Log4perl->get_logger();

$logger->debug("JOIN_MSG_ARRAY_CHAR: '", defined $Log::Log4perl::JOIN_MSG_ARRAY_CHAR ? $Log::Log4perl::JOIN_MSG_ARRAY_CHAR : "[undefined]", "'");

$logger->debug("Test: ", undef);

Config info for my setup...

Summary of my perl5 (revision 5 version 14 subversion 2) configuration:

Platform:
osname=linux, osvers=2.6.18-274.12.1.el5, archname=x86_64-linux
uname='linux hostname 2.6.18-274.12.1.el5 #1 smp tue nov 29 13:37:46 est 2011 x86_64 x86_64 x86_64 gnulinux '
config_args='-de -Dprefix=/home/dh/perl5/perlbrew/perls/perl-5.14.2'
hint=recommended, useposix=true, d_sigaction=define
useithreads=undef, usemultiplicity=undef
useperlio=define, d_sfio=undef, uselargefiles=define, usesocks=undef
use64bitint=define, use64bitall=define, uselongdouble=undef
usemymalloc=n, bincompat5005=undef
Compiler:
cc='cc', ccflags ='-fno-strict-aliasing -pipe -fstack-protector -I/usr/local/include -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64',
optimize='-O2',
cppflags='-fno-strict-aliasing -pipe -fstack-protector -I/usr/local/include'
ccversion='', gccversion='4.1.2 20080704 (Red Hat 4.1.2-51)', gccosandvers=''
intsize=4, longsize=8, ptrsize=8, doublesize=8, byteorder=12345678
d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=16
ivtype='long', ivsize=8, nvtype='double', nvsize=8, Off_t='off_t', lseeksize=8
alignbytes=8, prototype=define
Linker and Libraries:
ld='cc', ldflags =' -fstack-protector -L/usr/local/lib'
libpth=/usr/local/lib /lib /usr/lib /lib64 /usr/lib64 /usr/local/lib64
libs=-lnsl -ldl -lm -lcrypt -lutil -lc
perllibs=-lnsl -ldl -lm -lcrypt -lutil -lc
libc=/lib/libc-2.5.so, so=so, useshrplib=false, libperl=libperl.a
gnulibc_version='2.5'
Dynamic Linking:
dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags='-Wl,-E'
cccdlflags='-fPIC', lddlflags='-shared -O2 -L/usr/local/lib -fstack-protector'

Characteristics of this binary (from libperl):
Compile-time options: PERL_DONT_CREATE_GVSV PERL_MALLOC_WRAP
PERL_PRESERVE_IVUV USE_64_BIT_ALL USE_64_BIT_INT
USE_LARGE_FILES USE_PERLIO USE_PERL_ATOF
Built under linux
Compiled at Jan 18 2012 17:34:52
%ENV:
PERLBREW_HOME="/home/dh/.perlbrew"
PERLBREW_PATH="/home/dh/perl5/perlbrew/bin:/home/dhagan/perl5/perlbrew/perls/perl-5.14.2/bin"
PERLBREW_PERL="perl-5.14.2"
PERLBREW_ROOT="/home/dh/perl5/perlbrew"
PERLBREW_VERSION="0.28"
@inc:
/home/dh/perl5/perlbrew/perls/perl-5.14.2/lib/site_perl/5.14.2/x86_64-linux
/home/dh/perl5/perlbrew/perls/perl-5.14.2/lib/site_perl/5.14.2
/home/dh/perl5/perlbrew/perls/perl-5.14.2/lib/5.14.2/x86_64-linux
/home/dh/perl5/perlbrew/perls/perl-5.14.2/lib/5.14.2
.

Log::Log4perl version 1.35 from cpan.

Would it be too much to add autoflush to easy_init?

To get automatic flushing atm, I have to write a config, which I know isn't the end of the world, but it doesn't fit well with my lazy use of :easy.

If you write message to logfile (File appender) and an exeption raised, then the application failed. But it's wrong. The application designed for solve some problems, not for writing to log. So it should continue to solve this problems, even if writing to log fails.

Well I propose replacing die to warn in method log of appender File. (Or adding the option that will switch die to warn.)

Hi,

We have a system which forks children and we found out that sometimes log4perl messages are interleaved (especially for long messages) so we added the "Synchronized" Appenders the the logfiles and created a different semaphore (4 char long .key) for each and every appender file based logger.

At first tests it looked perfectly ok, but once we put the code on our QA testing system it started to fail miserable, we had strange lockups all over the place and as I have not really found out how that semaphores stuff is working I also feel unable to fix this issue. But I think it seems somehow the locks don't get released but I don't even know how to trace this.

BTW: We are using Log4perl 1.46 provided by centos7.

Successfully installed Log-Log4perl-1.46
1 distribution installed
sherlock$ perl -e 'use Log::Log4perl::Appender;'
Can't locate object method "new" via package "Log::Log4perl::Appender" at /home/matthewt/perl5/lib/perl5/Log/Log4perl/Logger.pm line 33.
Compilation failed in require at /home/matthewt/perl5/lib/perl5/Log/Log4perl/Config.pm line 8.
BEGIN failed--compilation aborted at /home/matthewt/perl5/lib/perl5/Log/Log4perl/Config.pm line 8.
Compilation failed in require at /home/matthewt/perl5/lib/perl5/Log/Log4perl/Appender.pm line 9.
BEGIN failed--compilation aborted at /home/matthewt/perl5/lib/perl5/Log/Log4perl/Appender.pm line 9.
Compilation failed in require at -e line 1.
BEGIN failed--compilation aborted at -e line 1.

The problem here is Appender loads Config loads Logger and then Logger tries to ->new on Appender - but because Logger's require of Appender has been ignored as already in progress, Appender's new method doesn't exist yet.

Require loops BAD :)

(also this particular require loop is the cause of http://stackoverflow.com/questions/31319263/is-it-possible-to-fatpack-script-using-loglog4perl-using-appfatpacker )

I was poking around inside the guts of Log::Log4perl and noticed this:

sub cleanup {
    # Delete all loggers
    foreach my $loggername (keys %$LOGGERS_BY_NAME) {
        $LOGGERS_BY_NAME->{$loggername}->DESTROY();
        delete $LOGGERS_BY_NAME->{$loggername};
    }

The explicit call to DESTROY strikes me as an overly aggressive cleanup. If the logger is no longer in use, no longer referenced elsewhere, DESTROY will be called automatically when it's deleted from %LOGGERS_BY_NAME. If the logger IS still referenced, then some code somewhere is left with a busted logger object.

This makes cleanup unusable for long running processes to clean out the cache of unused loggers. See http://stackoverflow.com/questions/5914088/disposing-of-log4perl-logger-when-i-no-longer-need-it

Is there another reason for this? Perhaps to break a circular reference? It was added in 079329e but no rationale is given.

Since Log::Log4perl::Logger->cleanup is undocumented, and its only use is in an END block, and all it does is disassemble some hashes and call DESTROY on some objects that are about to be destroyed anyway... why does it exist at all?

In a related note, Log::Log4perl::Logger->DESTROY doesn't appear to do anything useful. It deletes things that will be automatically cleaned up in object destruction. Is that circular reference defense?

Hello

I am getting this error on perl 5.18.1:

Can't close log/file.log (Bad file descriptor) at /usr/lib/perl5/site_perl/5.18.1/Log/Log4perl/Appender/File.pm line 282

However, it does not happen on earlier perl versions. Is there any way around this?

This is what the configuration file looks like:

log4perl.category.Foo.Foo1=INFO, LOGFILE
log4perl.category.Foo.Foo2=INFO, LOGFILE
log4perl.category.Foo.Foo3=INFO, LOGFILE

log4perl.category.modules=FATAL, LOGFILE
log4perl.category.Bar.Bar1=DEBUG, LOGFILE2

log4perl.appender.LOGFILE=Log::Log4perl::Appender::File
log4perl.appender.LOGFILE.filename=sub { logfile(); };
log4perl.appender.LOGFILE.mode=append

log4perl.appender.LOGFILE.layout=PatternLayout
log4perl.appender.LOGFILE.layout.ConversionPattern=[%d{dd/MMM HH:mm:ss.SSS}] %P|%c{1}:%L/%p - %m%n

log4perl.appender.LOGFILE2=Log::Log4perl::Appender::File
log4perl.appender.LOGFILE2.filename=sub { logfile('logfile2'); };
log4perl.appender.LOGFILE2.mode=append
log4perl.appender.LOGFILE2.layout=PatternLayout
log4perl.appender.LOGFILE2.layout.ConversionPattern=[%d{dd/MMM HH:mm:ss.SSS}] %P|%c{1}:%L/%p - %m%n

https://rt.cpan.org/Public/Bug/Display.html?id=110513

I use 2 boolean filters to combine simple regex-ignore filters (and chained them too):

log4perl.filter.AbortUserProtected = sub { m!test a! }
log4perl.filter.AbortUserInactive = sub { m!test b! }
log4perl.filter.AbortProjectInactive = sub { m!test c! }
log4perl.filter.ProblemNewState = sub { m!test d! }
log4perl.filter.ProblemPremiumProject = sub { m!test e! }
log4perl.filter.ProblemInactiveProject = sub { m!test f! }
log4perl.filter.IgnoreTicket6851 = Log::Log4perl::Filter::Boolean
log4perl.filter.IgnoreTicket6851.logic = AbortUserProtected || AbortUserInactive || AbortProjectInactive || ProblemNewState || ProblemPremiumProject || ProblemInactiveProject

log4perl.filter.WrongContentLength = sub { m!test 1! }
log4perl.filter.SessionMismatch = sub { m!test 2! }
log4perl.filter.SessionTooLarge = sub { m!test 3! }
log4perl.filter.InvalidBoundary = sub { m!test 4! }
log4perl.filter.InvalidFieldName = sub { m!test 5! }
log4perl.filter.InvalidUnicode = sub { m!test 6! }
log4perl.filter.IgnoreUnwanted = Log::Log4perl::Filter::Boolean
log4perl.filter.IgnoreUnwanted.logic = !WrongContentLength && !SessionMismatch && !SessionTooLarge && !InvalidBoundary && !InvalidFieldName && !InvalidUnicode && !IgnoreTicket6851

log4perl.appender.PanicApp.Filter = IgnoreUnwanted

in ~50% the loading of filters failed due to the following error:

Filter IgnoreTicket6851 required by Boolean filter, but not defined at /path/to/Log/Log4perl/Filter/Boolean.pm line 55.

After setting _INTERNAL_DEBUG => 1 in Log::Log4perl::Filter::Boolean i see the problem:

Compiling '!WrongContentLength && !SessionMismatch && !SessionTooLarge && !InvalidBoundary && !InvalidFieldName && !InvalidUnicode && !IgnoreTicket6851'
Filter IgnoreTicket6851 required by Boolean filter, but not defined at /path/to/Log/Log4perl/Filter/Boolean.pm line 55.

VS

Compiling 'AbortUserProtected || AbortUserInactive || AbortProjectInactive || ProblemNewState || ProblemPremiumProject || ProblemInactiveProject'
func= sub {
my($AbortProjectInactive, $AbortUserProtected, $AbortUserInactive, $ProblemNewState, $ProblemPremiumProject, $ProblemInactiveProject) = @_;
&$AbortUserProtected || &$AbortUserInactive || &$AbortProjectInactive || &$ProblemNewState || &$ProblemPremiumProject || &$ProblemInactiveProject;
}

Compiling '!WrongContentLength && !SessionMismatch && !SessionTooLarge && !InvalidBoundary && !InvalidFieldName && !InvalidUnicode && !IgnoreTicket6851'
func= sub {
my($InvalidFieldName, $SessionTooLarge, $WrongContentLength, $IgnoreTicket6851, $SessionMismatch, $InvalidBoundary, $InvalidUnicode) = @_;
!&$WrongContentLength && !&$SessionMismatch && !&$SessionTooLarge && !&$InvalidBoundary && !&$InvalidFieldName && !&$InvalidUnicode && !&$IgnoreTicket6851;
}

The order of the boolean filters is not picked from the configuration. It is by random.

in your Log::Log4perl->get_logger you may initialize:

my $level =  $Log::Log4perl::caller_depth;

That will allow this to work:

$SIG{ __WARN__ } =  sub {
    local $Log::Log4perl::caller_depth =  $Log::Log4perl::caller_depth + 1;
    my $logger =  Log::Log4perl->get_logger;
    $logger->warn( '__WARN__ ', $Log::Log4perl::caller_depth, @_ );
};

With that init the get_logger will return logger with category where warn is called instead of package where $SIG{ WARN } is defined;

Also you can think more deeply. It seems, to my mind, you can escape from $WRAPPERS_REGISTERED. Users just required to localize $Log::Log4perl::caller_depth as I did in my example

Hi,

I have the following

use Log::Log4perl;

my $conf = q(
        log4perl.category                  = DEBUG, SYSLOG, Logfile
        log4perl.appender.SYSLOG           = Log::Dispatch::Syslog
        log4perl.appender.SYSLOG.layout    = Log::Log4perl::Layout::SimpleLayout
        log4perl.appender.Logfile          = Log::Log4perl::Appender::File
        log4perl.appender.Logfile.filename = /tmp/test.log
        log4perl.appender.Logfile.layout    = Log::Log4perl::Layout::SimpleLayout
);

Log::Log4perl::init(\$conf);
my $logger = Log::Log4perl->get_logger();
$logger->error("logging...");

in an SVN pre-commit hook.

While it logs fine to the logfile, I do not get anything into syslog (rsyslogd precisely).

Running the hook on the commandline makes it log to syslog as expected, so I guess it is some problem with the environment.

Any ideas on how I could get this fixed?

Thanks a lot,
Sven

Using the file appender and a filename such as "пример.log" on Windows results in:

Can't open ??????.log (Invalid argument) at C:\...lib/Log/Log4perl/Appender/File.pm line 151.

It's fine with common Latin1 things but not Cyrillic etc. Is there a way to do this? In the application that uses this, I had to resort to Win32::Unicode::File in other places as this seems to be the only way to read/write files with such glyphs on Windows?

Log::Log4perl curently supports only the pound sign "#" to introduce comments.

Log::Log4perl's config file format is similar to an INI file and many INI files accept the semi-colon ";" as a comment character.

Also, Log::Log4perl is based on log4j which also supports the exclamation point "!" for comments.

I've looked at Log::Log4perl::Config::PropertyConfigurator which I believe is responsible for interpreting the syntax and I'm willing to do the work and add tests if anyone else thinks these additions would be useful.

The NAME in the POD is 'Log::Log4perl::Appender::ScreenColoredLevel' but the module name is 'Log::Log4perl::Appender::ScreenColoredLevels'. It's only a single character change in documentation. I'll submit a PR for it.

The t/026FileApp.t should probably skip for $^O eq 'cygwin' where it is currently skipping for $^O eq 'MSWin32.

I was able to get make test to pass by adding three instances of: || $^O eq 'cygwin'

Use log4perl with perl 5.16.1, with -w option, perl complains such like:

defined(@array) is deprecated at /perl-lib-path/lib/Log/Log4perl/Config.pm line 864, line 558.
(Maybe you should just omit the defined()?)

There are following code found arround 864.

863 # give back 'undef' instead of an empty arrayref
864 unless( defined @log::Log4perl::ALLOWED_CODE_OPS_IN_CONFIG_FILE ) {
865 return;
866 }

So it should be:

864 unless( @log::Log4perl::ALLOWED_CODE_OPS_IN_CONFIG_FILE ) {

or

864 unless( scalar(@log::Log4perl::ALLOWED_CODE_OPS_IN_CONFIG_FILE) ) {

Every argument to easy_init() should be either an integer (a log level value) or a hashref containing logger configuration options. It would be nice if it complained loudly if it got anything else.

Recently, I saw someone calling it like this:

easy_init( level => $WARN, format => ' ... ' ); # Not a hashref

The level parameter seemed to work, but the format was ignored. The fix was simple (just put all of the arguments within { ... }) but it would have been easier to find if the function had emitted some kind of warning when receiving invalid parameters.

I'll submit a pull request for this soon.

Please release the fix to CPAN, so i won't have to be angry at you twice. ;)

Hi,

So I came across this when I tried to use log4perl without initializing it (I wanted warnings and deaths, and when the modules user was using log4perl it all to be logged as well). The logdie and associated methods all die regardless of log level but the warn versions all require log4perl to be configured to log the message of that level before it will issue the warn statement. This seems wrong to me as I thought the intention of these methods was was to log your warnings as opposed to warn your log messages.

Originally I was just going to fork and put in a pull request for this and let that be accepted or rejected, but after I started working on it I found that t/024WarnDieCarp.t explicitly tests for the warnings not being made when the log level isn't high enough, so now I'm thinking this is intended behavior and just a really odd design decision.

So I'm keen to have a version of logwarn that warns regardless of log levels or initialization either by repairing the existing methods or implementing some new methods. I'm eager to do the work for either solution if you guys are happy to see either implemented.

So let me know whether either of these is ok or if I'm just confused.

Thanks
-Chris

Particularly when I am debugging a module that I haven't maintained before, I'd like to automatically instrument all the subroutines. Here's what I'd like to do:

package Foo::Bar;

use Log::Log4perl qw(:easy);

sub A {}

sub B {}

Log::Log4perl::auto_instrument();
1;

This would look through the symbol table for Foo::Bar and replace each subroutine something like this:

*new_A = \&A;
sub A {
   DEBUG "entering A, arguments are : " . join(' ', @_);
  new_A(@_);
  DEBUG "leaving A";
}

Mike, I wanted to get your thoughts before contributing any code changes.

I ran in the same bug as Siarhei Kuchynski:
The following code in line 64 of Log::Log4perl::Util::Semaphore should fix this:
64 defined($self->{id} = semget( $self->{ikey}, 1, 0 ))

He observes:
"When a semaphore with specified key (0x6f6e616e) and semid = 0 already
exists, semget fails for this semaphore:

bash-4.0# ipcs -s

Verberge zitierten Text
------ Semaphore Arrays --------

key semid owner perms nsems

0x6f6e616e 0 root 777 1

with the following error message

semget(1869504878) failed: at
/usr/share/perl5/vendor_perl//Log/Log4perl/Util/Semaphore.pm line 64.

This is caused by line 64 of Log::Log4perl::Util::Semaphore.pm

63 print "Semaphore '$self->{key}' already exists\n" if INTERNAL_DEBUG;

64 $self->{id} = semget( $self->{ikey}, 1, 0 )

65 or die "semget($self->{ikey}) failed: $!";

semget returns ID 0 for the key 1869504878 and dies, though 0 should be
considered to be valid ID
According to http://perldoc.perl.org/functions/semget.html:
semget KEY,NSEMS,FLAGS
Calls the System V IPC function semget(2). Returns the semaphore id, or the
undefined value on error.
It seems that init method should call die only if semget returns undefined
value, not zero.
"

At least CPAN.pm thinks that Log::Log4perl::Catalyst has no version:

cpan[1]> m Log::Log4perl::Catalyst
...
Module id = Log::Log4perl::Catalyst
    CPAN_USERID  MSCHILLI (Michael Schilli <[email protected]>)
    CPAN_VERSION undef
    CPAN_FILE    E/ET/ETJ/Log-Log4perl-1.53.tar.gz
    UPLOAD_DATE  2020-09-17
    MANPAGE      Log::Log4perl::Catalyst - Log::Log4perl Catalyst Module
    INST_FILE    /opt/perl-5.12.3/lib/site_perl/5.12.3/Log/Log4perl/Catalyst.pm
    INST_VERSION 1.49

Probably the reason is this line: https://metacpan.org/source/ETJ/Log-Log4perl-1.53/lib/Log/Log4perl/Catalyst.pm#L7
PAUSE looks only at the isolated $VERSION line when getting a module's version (for security reasons). It does not know anything about the Log::Log4perl module and the $VERSION value set there.

Possible fixes are:

• set a fixed version here
• create META.* files with a "provides" section

I've been struggling to understand how to use header_text.

For example, the following

#!/usr/bin/env perl
use strict;
use warnings;
use Log::Log4perl qw(get_logger :levels);

my $logger = get_logger();
$logger->level($INFO);

my $layout = Log::Log4perl::Layout::PatternLayout->new("%d %p: %m{indent}%n");
my $appender = Log::Log4perl::Appender->new(
    "Log::Dispatch::File",
    header_text => "header cmh",
    filename => "test.log",
    mode     => "write",
);

$appender->layout($layout);
$logger->add_appender($appender);

$logger->info("some information");

exit(0);

produces

2017/09/18 20:16:54 INFO: some information

and I was hoping that header cmh might appear in it.

Have I misunderstood header_text?

Log::Log4perl::DateFormat computes the time zone offset only once, so Lo4perl ends up logging incorrect datetimes when the object survives during time zone changes.

% faketime '2021-03-28 01:59:58' perl -MLog::Log4perl -E 'sub g {Log::Log4perl::DateFormat->new("yyyy-MM-ddTHH:mm:ss.SSSZ")}; my $outer = g(); for (1..5) { say join " ", $outer->format(time), g->format(time); sleep 1 }'
2021-03-28T01:59:58.000+0100 2021-03-28T01:59:58.000+0100
2021-03-28T01:59:59.000+0100 2021-03-28T01:59:59.000+0100
2021-03-28T03:00:00.000+0100 2021-03-28T03:00:00.000+0200
2021-03-28T03:00:01.000+0100 2021-03-28T03:00:01.000+0200
2021-03-28T03:00:02.000+0100 2021-03-28T03:00:02.000+0200

Hi,

I couldn't find any documentation on how to set the "undef_column_value".
It causes problems when trying to convert the output to JSON as my expected field type is an integer which could be NULL if not available, however Log::Log4perl::Layout::PatternLayout converts everything that's undef to a string, i.e. "[undef]".
Many thanks.

We should consider enforcing three args open in Log4perl

this is coming from sub file_open Log::Log4perl::Appender::File

     eval {
         if($self->{syswrite}) {
             sysopen $fh, "$self->{filename}", $sysmode or
                 die "Can't sysopen $self->{filename} ($!)";
         } else {
             open $fh, "$arrows$self->{filename}" or
                 die "Can't open $self->{filename} ($!)";
         }
     };

Hi,

with Perl 5.24, any log write will cause a warning if the options "utf8" and "syswrite" are used together:

syswrite() is deprecated on :utf8 handles at /usr/share/perl5/Log/Log4perl/Appender/File.pm line 272

See https://rt.perl.org/Public/Bug/Display.html?id=125760 for the change in Perl.

Something like the following will silence the warning:

--- File.pm.orig        2017-01-17 16:35:18.869755923 +0000
+++ File.pm     2017-01-17 16:46:59.621725047 +0000
@@ -10,6 +10,7 @@
 use Fcntl;
 use File::Path;
 use File::Spec::Functions qw(splitpath);
+use Encode                qw(encode_utf8);
 use constant _INTERNAL_DEBUG => 0;
 
 ##################################################
@@ -163,10 +164,6 @@
         binmode $self->{fh}, $self->{binmode};
     }
 
-    if (defined $self->{utf8}) {
-        binmode $self->{fh}, ":utf8";
-    }
-
     if(defined $self->{header_text}) {
         if( $self->{header_text} !~ /\n\Z/ ) {
             $self->{header_text} .= "\n";
@@ -268,11 +265,13 @@
 
     my $fh = $self->{fh};
 
+    my $msg = $self->{utf8} ? encode_utf8($params{message}) : $params{message}; 
+
     if($self->{syswrite}) {
-       defined (syswrite $fh, $params{message}) or
+       defined (syswrite $fh, $msg) or
            die "Cannot syswrite to '$self->{filename}': $!";
     } else {
-        print $fh $params{message} or
+        print $fh $msg or
             die "Cannot write to '$self->{filename}': $!";
     }
 }

encode_utf8() is ancient, so it should not cause portability issues.

I want to use the :easy interface and log to a file with Log::Dispatch::File::Stamped instead of File and log to STDERR with ScreenColoredLevels instead of Screen. Please consider adding the ability to specify the appender in the :easy interface.
I think issue #21 was asking something similar.

Log-Log4perl-1.54

Switching the log file name using the file_switch() method, creates a new logfile even if the create_at_logtime option is set to true. Maybe the line 271 in Log::Log4perl::Appender::File should be changed from

$self->file_open();

to

$self->file_open() unless $self->{create_at_logtime};