/ 
No-Worries-1.4
River stage one • 7 direct dependents • 8 total dependents
/ No::Worries::Log

NAME

No::Worries::Log - logging without worries

SYNOPSIS

use No::Worries::Log qw(*);

# log an information level message with sprintf()-like syntax
log_info("accepted connection from %s:%d", inet_ntoa($addr), $port);

# log expensive debugging information only if needed
if (log_wants_debug()) {
    $string = ... whatever ...
    log_debug($string, { component => "webui" });
}

# log a low-level trace: this is cheap and can be added in many places
sub foo () {
    log_trace();
    ... code...
}

# specify the filter to use: debug messages from web* components
log_filter(<<EOT);
    debug component=~^web
EOT

DESCRIPTION

This module eases information logging by providing convenient functions to log and filter information. All the functions die() on error.

It provides five main functions to submit information to be logged:

  • log_error(ARGUMENTS): for error information

  • log_warning(ARGUMENTS): for warning information

  • log_info(ARGUMENTS): for (normal) information

  • log_debug(ARGUMENTS): for debugging information

  • log_trace(): for a low level trace

The supplied information is structured and can contain extra attributes (key/value pairs) like in the SYNOPSIS example.

If the information passes through the filter, it is given to the handler for logging.

ATTRIBUTES

An information "object" always contains the following attributes:

  • level: the information level as error, warning, info, debug or trace

  • time: Unix time indicating when the information got submitted

  • caller: the name of the caller's subroutine or main

  • file: the file path

  • line: the line number

  • program: the program name, as known by the No::Worries module

  • host: the host name, see $No::Worries::HostName

  • pid: the process identifier

  • tid: the thread identifier (in case threads are used)

  • message: the formatted message string

In addition, extra attributes can be given when calling log_error(), log_warning(), log_info() or log_debug().

These attributes are mainly used for filtering (see next section) but can also be used for formatting.

FILTER

The filter defines which information should be logged (i.e. given to the handler) or not. It can be controlled via the log_filter() and log_configure() functions.

The filter is described via a multi-line string. Each line is made of one or more space separated expressions that must be all true. A filter matches if any of its lines matches. Empty lines and comments are allowed for readability.

A filter expression can be either error, warning, info, debug or trace (meaning that the level must match it) or of the form {attr}{op}{value} where {attr} is the attribute name, {op} is the operation (either =~, !~, ==, !=, <, <=, > or >=) and value is the value to use for the test (either an integer, a string or a regular expression).

If the value is not an integer, it will be treated like the contents of a double quoted string or a regular expression, so escape sequences will be honored. For parsing reasons (expressions are space separated), the value cannot contain space characters. If you need some, they have to be escaped like in the examples below.

Here are commented examples:

# comments start with a 'hash' sign
# all info level
info

# debug level with messages matching "permission denied"
# (expressions are space separated so the space must be escaped)
debug message=~permission\x20denied

# debug level from any subroutine in Foo::Bar on host "venus"
debug caller=~^Foo::Bar:: host==venus

# trace level at the end of the file foo.pm
trace file=/full/path/foo.pm line>999

Note: user-supplied attributes can also be used in filters. If they are not defined, the match will fail. For instance:

# we want to see only debug messages with a low karma
log_filter("debug karma<=42");
# the following will be logged
log_debug("yes", { karma => 7 });
# the following will not be logged
log_debug("no", { karma => 1999 });
log_debug("no");

You can also use an alternative syntax with explicit or and and. This is very convenient to fit the filter in a single line (for instance when given on the command line). For instance:

# multi-line style filter
info
debug caller==main

is equivalent to:

info or debug and caller==main

HANDLER

If the information successfully passes through the filter it is given to the handler, i.e. the code reference stored in $No::Worries::Log::Handler.

The default handler prints compact yet user friendly output to STDOUT (info level) or STDERR (otherwise).

The No::Worries::Syslog module contains a similar handler to log information to syslog.

Here is how to change the variable to a handler that dumps all the information attributes to STDERR:

$No::Worries::Log::Handler = \&No::Worries::Log::log2dump;

The same can be achived at module loading time by using for instance:

use No::Worries::Log qw(* log2dump);

You can put your own code in $No::Worries::Log::Handler. It will be called with a single argument: the structured information as a hash reference. This can be useful for ad-hoc filtering or to do something else that logging to STDOUT/STDERR or syslog.

FUNCTIONS

This module provides the following functions (none of them being exported by default):

log_filter(FILTER)

use the given filter (string) to configure what should gets logged or not

log_configure(PATH)

use the given path (file) to configure what should gets logged or not; this reads the file if needed (i.e. if it changed since last time) and calls log_filter()

log_wants_error()

return true if the current filter may pass error level information

log_wants_warning()

return true if the current filter may pass warning level information

log_wants_info()

return true if the current filter may pass info level information

log_wants_debug()

return true if the current filter may pass debug level information

log_wants_trace()

return true if the current filter may pass trace level information

log_error(ARGUMENTS)

give an error level information to the module to get logged if the current filter lets it pass; see below for its ARGUMENTS

log_warning(ARGUMENTS)

give a warning level information to the module to get logged if the current filter lets it pass; see below for its ARGUMENTS

log_info(ARGUMENTS)

give an info level information to the module to get logged if the current filter lets it pass; see below for its ARGUMENTS

log_debug(ARGUMENTS)

give a debug level information to the module to get logged if the current filter lets it pass; see below for its ARGUMENTS

log_trace()

give a trace level information to the module to get logged if the current filter lets it pass; the trace information contains the name of the caller subroutine, the file path and the line number

log2std(INFO)

handler for $No::Worries::Log::Handler to send information to STDOUT/STDERR in a compact yet user friendly way; this is not exported and must be called explicitly

log2dump(INFO)

handler for $No::Worries::Log::Handler that dumps all the information attributes to STDERR; this is not exported and must be called explicitly

USAGE

log_error(), log_warning(), log_info() and log_debug() can be called in different ways:

  • log_xxx(): no arguments, same as giving an empty string

  • log_xxx("string"): the message will be the given string

  • log_xxx("format", @args): the message will be the result of sprintf()

  • log_xxx(\&code): the message will be the return value of the code

  • log_xxx(\&code, @args): idem but also supplying arguments to give

In addition, in all cases, an optional last argument containing user-supplied attributes can be given as a hash reference. For instance:

log_info("foo is %s", $foo, { component => "webui" });

Note that the following:

log_debug(\&dump_hash, \%big_hash);

will treat the last argument as being the attributes hash. If this is not what you want, you should supply an empty attributes hash so that \%big_hash gets interpreted as an argument to give to dump_hash():

log_debug(\&dump_hash, \%big_hash, {});

With the sprintf() style usage, you can supply string references as arguments. They will be replaced by the corresponding attributes. For instance:

log_debug("unexpected data: %s [line %d]", $data, \"line");

The usages with a code reference are useful for expensive operations that you want to perform only when you are pretty sure that the information will be logged. The code reference will be called only after an initial filtering. For instance:

# expensive code to return a message to maybe log
sub dump_state ($) {
    my($data) = @_;
    ... heavy work ...
    return(... something ...);
}
# subroutine that may want to dump its state
sub foo () {
    ... some code ...
    log_debug(\&dump_state, $some_data);
    ... some code ...
}
# filter that only cares about debug information from main::bar
log_filter("debug caller==main::bar");
# the following will not call dump_state()
foo();

GLOBAL VARIABLES

This module uses the following global variables (none of them being exported):

$Handler

the subroutine (code reference) to call for every information that successfully passes through the filter, the default is normally \&No::Worries::Log::log2std() (see below)

ENVIRONMENT VARIABLES

This module uses the NO_WORRIES environment variable to find out which handler to use by default. Supported values are:

log2std

use No::Worries::Log::log2std() (this is the default anyway)

log2dump

use No::Worries::Log::log2dump()

SEE ALSO

No::Worries, No::Worries::Syslog.

AUTHOR

Lionel Cons http://cern.ch/lionel.cons

Copyright (C) CERN 2012-2016