[ViewVC] Diff of: cvs/AnyEvent/lib/AnyEvent/Log.pm

Comparing AnyEvent/lib/AnyEvent/Log.pm (file contents):
Revision 1.1 by root, Mon Aug 15 23:21:09 2011 UTC vs.
Revision 1.41 by root, Thu Sep 1 04:07:18 2011 UTC

…		…
2		2
3	AnyEvent::Log - simple logging "framework"	3	AnyEvent::Log - simple logging "framework"
4		4
5	=head1 SYNOPSIS	5	=head1 SYNOPSIS
6		6
		7	Simple uses:
		8
		9	use AnyEvent;
		10
		11	AE::log debug => "hit my knee";
		12	AE::log warn => "it's a bit too hot";
		13	AE::log error => "the flag was false!";
		14	AE::log fatal => "the bit toggled! run!"; # never returns
		15
		16	# available log levels in order:
		17	# fatal alert critical error warn note info debug trace
		18
		19	"Complex" uses (for speed sensitive code):
		20
7	use AnyEvent::Log;	21	use AnyEvent::Log;
8		22
		23	my $tracer = AnyEvent::Log::logger trace => \$my $trace;
		24
		25	$tracer->("i am here") if $trace;
		26	$tracer->(sub { "lots of data: " . Dumper $self }) if $trace;
		27
		28	Configuration (also look at the EXAMPLES section):
		29
		30	# set logging for the current package to errors and higher only
		31	AnyEvent::Log::ctx->level ("error");
		32
		33	# set logging level to suppress anything below "notice"
		34	$AnyEvent::Log::FILTER->level ("notice");
		35
		36	# send all critical and higher priority messages to syslog,
		37	# regardless of (most) other settings
		38	$AnyEvent::Log::COLLECT->attach (new AnyEvent::Log::Ctx
		39	level => "critical",
		40	log_to_syslog => "user",
		41	);
		42
9	=head1 DESCRIPTION	43	=head1 DESCRIPTION
10		44
		45	This module implements a relatively simple "logging framework". It doesn't
		46	attempt to be "the" logging solution or even "a" logging solution for
		47	AnyEvent - AnyEvent simply creates logging messages internally, and this
		48	module more or less exposes the mechanism, with some extra spiff to allow
		49	using it from other modules as well.
		50
		51	Remember that the default verbosity level is C<0> (C<off>), so nothing
		52	will be logged, unless you set C<PERL_ANYEVENT_VERBOSE> to a higher number
		53	before starting your program, or change the logging level at runtime with
		54	something like:
		55
		56	use AnyEvent::Log;
		57	$AnyEvent::Log::FILTER->level ("info");
		58
		59	The design goal behind this module was to keep it simple (and small),
		60	but make it powerful enough to be potentially useful for any module, and
		61	extensive enough for the most common tasks, such as logging to multiple
		62	targets, or being able to log into a database.
		63
		64	The module is also usable before AnyEvent itself is initialised, in which
		65	case some of the functionality might be reduced.
		66
		67	The amount of documentation might indicate otherwise, but the runtime part
		68	of the module is still just below 300 lines of code.
		69
		70	=head1 LOGGING LEVELS
		71
		72	Logging levels in this module range from C<1> (highest priority) to C<9>
		73	(lowest priority). Note that the lowest numerical value is the highest
		74	priority, so when this document says "higher priority" it means "lower
		75	numerical value".
		76
		77	Instead of specifying levels by name you can also specify them by aliases:
		78
		79	LVL NAME SYSLOG PERL NOTE
		80	1 fatal emerg exit aborts program!
		81	2 alert
		82	3 critical crit
		83	4 error err die
		84	5 warn warning
		85	6 note notice
		86	7 info
		87	8 debug
		88	9 trace
		89
		90	As you can see, some logging levels have multiple aliases - the first one
		91	is the "official" name, the second one the "syslog" name (if it differs)
		92	and the third one the "perl" name, suggesting (only!) that you log C<die>
		93	messages at C<error> priority.
		94
		95	You can normally only log a single message at highest priority level
		96	(C<1>, C<fatal>), because logging a fatal message will also quit the
		97	program - so use it sparingly :)
		98
		99	Some methods also offer some extra levels, such as C<0>, C<off>, C<none>
		100	or C<all> - these are only valid in the methods they are documented for.
		101
11	=head1 FUNCTIONS	102	=head1 LOGGING FUNCTIONS
		103
		104	These functions allow you to log messages. They always use the caller's
		105	package as a "logging context". Also, the main logging function C<log> is
		106	callable as C<AnyEvent::log> or C<AE::log> when the C<AnyEvent> module is
		107	loaded.
12		108
13	=over 4	109	=over 4
14		110
15	=cut	111	=cut
16		112
17	package AnyEvent::Log;	113	package AnyEvent::Log;
18		114
		115	use Carp ();
19	use POSIX ();	116	use POSIX ();
20		117
21	use AnyEvent (); BEGIN { AnyEvent::common_sense }	118	use AnyEvent (); BEGIN { AnyEvent::common_sense }
		119	#use AnyEvent::Util (); need to load this in a delayed fashion, as it uses AE::log
		120
		121	our $VERSION = $AnyEvent::VERSION;
		122
		123	our ($COLLECT, $FILTER, $LOG);
		124
		125	our ($now_int, $now_str1, $now_str2);
		126
		127	# Format Time, not public - yet?
		128	sub ft($) {
		129	my $i = int $_[0];
		130	my $f = sprintf "%06d", 1e6 * ($_[0] - $i);
		131
		132	($now_int, $now_str1, $now_str2) = ($i, split /\x01/, POSIX::strftime "%Y-%m-%d %H:%M:%S.\x01 %z", localtime $i)
		133	if $now_int != $i;
		134
		135	"$now_str1$f$now_str2"
		136	}
		137
		138	our %CTX; # all package contexts
		139
		140	# creates a default package context object for the given package
		141	sub _pkg_ctx($) {
		142	my $ctx = bless [$_[0], (1 << 10) - 1 - 1, {}], "AnyEvent::Log::Ctx";
		143
		144	# link "parent" package
		145	my $parent = $_[0] =~ /^(.+)::/
		146	? $CTX{$1} \|\|= &_pkg_ctx ("$1")
		147	: $COLLECT;
		148
		149	$ctx->[2]{$parent+0} = $parent;
		150
		151	$ctx
		152	}
		153
		154	=item AnyEvent::Log::log $level, $msg[, @args]
		155
		156	Requests logging of the given C<$msg> with the given log level, and
		157	returns true if the message was logged I<somewhere>.
		158
		159	For loglevel C<fatal>, the program will abort.
		160
		161	If only a C<$msg> is given, it is logged as-is. With extra C<@args>, the
		162	C<$msg> is interpreted as an sprintf format string.
		163
		164	The C<$msg> should not end with C<\n>, but may if that is convenient for
		165	you. Also, multiline messages are handled properly.
		166
		167	Last not least, C<$msg> might be a code reference, in which case it is
		168	supposed to return the message. It will be called only then the message
		169	actually gets logged, which is useful if it is costly to create the
		170	message in the first place.
		171
		172	Whether the given message will be logged depends on the maximum log level
		173	and the caller's package. The return value can be used to ensure that
		174	messages or not "lost" - for example, when L<AnyEvent::Debug> detects a
		175	runtime error it tries to log it at C<die> level, but if that message is
		176	lost it simply uses warn.
		177
		178	Note that you can (and should) call this function as C<AnyEvent::log> or
		179	C<AE::log>, without C<use>-ing this module if possible (i.e. you don't
		180	need any additional functionality), as those functions will load the
		181	logging module on demand only. They are also much shorter to write.
		182
		183	Also, if you optionally generate a lot of debug messages (such as when
		184	tracing some code), you should look into using a logger callback and a
		185	boolean enabler (see C<logger>, below).
		186
		187	Example: log something at error level.
		188
		189	AE::log error => "something";
		190
		191	Example: use printf-formatting.
		192
		193	AE::log info => "%5d %-10.10s %s", $index, $category, $msg;
		194
		195	Example: only generate a costly dump when the message is actually being logged.
		196
		197	AE::log debug => sub { require Data::Dump; Data::Dump::dump \%cache };
		198
		199	=cut
		200
		201	# also allow syslog equivalent names
		202	our %STR2LEVEL = (
		203	fatal => 1, emerg => 1, exit => 1,
		204	alert => 2,
		205	critical => 3, crit => 3,
		206	error => 4, err => 4, die => 4,
		207	warn => 5, warning => 5,
		208	note => 6, notice => 6,
		209	info => 7,
		210	debug => 8,
		211	trace => 9,
		212	);
		213
		214	our $TIME_EXACT;
		215
		216	sub exact_time($) {
		217	$TIME_EXACT = shift;
		218	*_ts = $AnyEvent::MODEL
		219	? $TIME_EXACT ? \&AE::now : \&AE::time
		220	: sub () { $TIME_EXACT ? do { require Time::HiRes; Time::HiRes::time () } : time };
		221	}
		222
		223	BEGIN {
		224	exact_time 0;
		225	}
		226
		227	AnyEvent::post_detect {
		228	exact_time $TIME_EXACT;
		229	};
		230
		231	our @LEVEL2STR = qw(0 fatal alert crit error warn note info debug trace);
		232
		233	# time, ctx, level, msg
		234	sub _format($$$$) {
		235	my $ts = ft $_[0];
		236	my $ct = " ";
		237
		238	my @res;
		239
		240	for (split /\n/, sprintf "%-5s %s: %s", $LEVEL2STR[$_[2]], $_[1][0], $_[3]) {
		241	push @res, "$ts$ct$_\n";
		242	$ct = " + ";
		243	}
		244
		245	join "", @res
		246	}
		247
		248	sub _log {
		249	my ($ctx, $level, $format, @args) = @_;
		250
		251	$level = $level > 0 && $level <= 9
		252	? $level+0
		253	: $STR2LEVEL{$level} \|\| Carp::croak "$level: not a valid logging level, caught";
		254
		255	my $mask = 1 << $level;
		256
		257	my ($success, %seen, @ctx, $now, $fmt);
		258
		259	do
		260	{
		261	# skip if masked
		262	if ($ctx->[1] & $mask && !$seen{$ctx+0}++) {
		263	if ($ctx->[3]) {
		264	# logging target found
		265
		266	# now get raw message, unless we have it already
		267	unless ($now) {
		268	$format = $format->() if ref $format;
		269	$format = sprintf $format, @args if @args;
		270	$format =~ s/\n$//;
		271	$now = _ts;
		272	};
		273
		274	# format msg
		275	my $str = $ctx->[4]
		276	? $ctx->[4]($now, $_[0], $level, $format)
		277	: ($fmt \|\|= _format $now, $_[0], $level, $format);
		278
		279	$success = 1;
		280
		281	$ctx->[3]($str)
		282	or push @ctx, values %{ $ctx->[2] }; # not consumed - propagate
		283	} else {
		284	push @ctx, values %{ $ctx->[2] }; # not masked - propagate
		285	}
		286	}
		287	}
		288	while $ctx = pop @ctx;
		289
		290	exit 1 if $level <= 1;
		291
		292	$success
		293	}
		294
		295	sub log($$;@) {
		296	_log
		297	$CTX{ (caller)[0] } \|\|= _pkg_ctx +(caller)[0],
		298	@_;
		299	}
		300
		301	AnyEvent::log = AE::log = \&log;
		302
		303	=item $logger = AnyEvent::Log::logger $level[, \$enabled]
		304
		305	Creates a code reference that, when called, acts as if the
		306	C<AnyEvent::Log::log> function was called at this point with the given
		307	level. C<$logger> is passed a C<$msg> and optional C<@args>, just as with
		308	the C<AnyEvent::Log::log> function:
		309
		310	my $debug_log = AnyEvent::Log::logger "debug";
		311
		312	$debug_log->("debug here");
		313	$debug_log->("%06d emails processed", 12345);
		314	$debug_log->(sub { $obj->as_string });
		315
		316	The idea behind this function is to decide whether to log before actually
		317	logging - when the C<logger> function is called once, but the returned
		318	logger callback often, then this can be a tremendous speed win.
		319
		320	Despite this speed advantage, changes in logging configuration will
		321	still be reflected by the logger callback, even if configuration changes
		322	I<after> it was created.
		323
		324	To further speed up logging, you can bind a scalar variable to the logger,
		325	which contains true if the logger should be called or not - if it is
		326	false, calling the logger can be safely skipped. This variable will be
		327	updated as long as C<$logger> is alive.
		328
		329	Full example:
		330
		331	# near the init section
		332	use AnyEvent::Log;
		333
		334	my $debug_log = AnyEvent:Log::logger debug => \my $debug;
		335
		336	# and later in your program
		337	$debug_log->("yo, stuff here") if $debug;
		338
		339	$debug and $debug_log->("123");
		340
		341	=cut
		342
		343	our %LOGGER;
		344
		345	# re-assess logging status for all loggers
		346	sub _reassess {
		347	local $SIG{__DIE__};
		348	my $die = sub { die };
		349
		350	for (@_ ? $LOGGER{$_[0]} : values %LOGGER) {
		351	my ($ctx, $level, $renabled) = @$_;
		352
		353	# to detect whether a message would be logged, we actually
		354	# try to log one and die. this isn't fast, but we can be
		355	# sure that the logging decision is correct :)
		356
		357	$$renabled = !eval {
		358	_log $ctx, $level, $die;
		359
		360	1
		361	};
		362	}
		363	}
		364
		365	sub _logger {
		366	my ($ctx, $level, $renabled) = @_;
		367
		368	$$renabled = 1;
		369
		370	my $logger = [$ctx, $level, $renabled];
		371
		372	$LOGGER{$logger+0} = $logger;
		373
		374	_reassess $logger+0;
		375
		376	require AnyEvent::Util;
		377	my $guard = AnyEvent::Util::guard (sub {
		378	# "clean up"
		379	delete $LOGGER{$logger+0};
		380	});
		381
		382	sub {
		383	$guard if 0; # keep guard alive, but don't cause runtime overhead
		384
		385	_log $ctx, $level, @_
		386	if $$renabled;
		387	}
		388	}
		389
		390	sub logger($;$) {
		391	_logger
		392	$CTX{ (caller)[0] } \|\|= _pkg_ctx +(caller)[0],
		393	@_
		394	}
		395
		396	=item AnyEvent::Log::exact_time $on
		397
		398	By default, C<AnyEvent::Log> will use C<AE::now>, i.e. the cached
		399	eventloop time, for the log timestamps. After calling this function with a
		400	true value it will instead resort to C<AE::time>, i.e. fetch the current
		401	time on each log message. This only makes a difference for event loops
		402	that actually cache the time (such as L<EV> or L<AnyEvent::Loop>).
		403
		404	This setting can be changed at any time by calling this function.
		405
		406	Since C<AnyEvent::Log> has to work even before the L<AnyEvent> has been
		407	initialised, this switch will also decide whether to use C<CORE::time> or
		408	C<Time::HiRes::time> when logging a message before L<AnyEvent> becomes
		409	available.
		410
		411	=back
		412
		413	=head1 LOGGING CONTEXTS
		414
		415	This module associates every log message with a so-called I<logging
		416	context>, based on the package of the caller. Every perl package has its
		417	own logging context.
		418
		419	A logging context has three major responsibilities: filtering, logging and
		420	propagating the message.
		421
		422	For the first purpose, filtering, each context has a set of logging
		423	levels, called the log level mask. Messages not in the set will be ignored
		424	by this context (masked).
		425
		426	For logging, the context stores a formatting callback (which takes the
		427	timestamp, context, level and string message and formats it in the way
		428	it should be logged) and a logging callback (which is responsible for
		429	actually logging the formatted message and telling C<AnyEvent::Log>
		430	whether it has consumed the message, or whether it should be propagated).
		431
		432	For propagation, a context can have any number of attached I<slave
		433	contexts>. Any message that is neither masked by the logging mask nor
		434	masked by the logging callback returning true will be passed to all slave
		435	contexts.
		436
		437	Each call to a logging function will log the message at most once per
		438	context, so it does not matter (much) if there are cycles or if the
		439	message can arrive at the same context via multiple paths.
		440
		441	=head2 DEFAULTS
		442
		443	By default, all logging contexts have an full set of log levels ("all"), a
		444	disabled logging callback and the default formatting callback.
		445
		446	Package contexts have the package name as logging title by default.
		447
		448	They have exactly one slave - the context of the "parent" package. The
		449	parent package is simply defined to be the package name without the last
		450	component, i.e. C<AnyEvent::Debug::Wrapped> becomes C<AnyEvent::Debug>,
		451	and C<AnyEvent> becomes ... C<$AnyEvent::Log::COLLECT> which is the
		452	exception of the rule - just like the "parent" of any single-component
		453	package name in Perl is C<main>, the default slave of any top-level
		454	package context is C<$AnyEvent::Log::COLLECT>.
		455
		456	Since perl packages form only an approximate hierarchy, this slave
		457	context can of course be removed.
		458
		459	All other (anonymous) contexts have no slaves and an empty title by
		460	default.
		461
		462	When the module is loaded it creates the C<$AnyEvent::Log::LOG> logging
		463	context that simply logs everything via C<warn>, without propagating
		464	anything anywhere by default. The purpose of this context is to provide
		465	a convenient place to override the global logging target or to attach
		466	additional log targets. It's not meant for filtering.
		467
		468	It then creates the C<$AnyEvent::Log::FILTER> context whose
		469	purpose is to suppress all messages with priority higher
		470	than C<$ENV{PERL_ANYEVENT_VERBOSE}>. It then attached the
		471	C<$AnyEvent::Log::LOG> context to it. The purpose of the filter context
		472	is to simply provide filtering according to some global log level.
		473
		474	Finally it creates the top-level package context C<$AnyEvent::Log::COLLECT>
		475	and attaches the C<$AnyEvent::Log::FILTER> context to it, but otherwise
		476	leaves it at default config. Its purpose is simply to collect all log
		477	messages system-wide.
		478
		479	The hierarchy is then:
		480
		481	any package, eventually -> $COLLECT -> $FILTER -> $LOG
		482
		483	The effect of all this is that log messages, by default, wander up to the
		484	C<$AnyEvent::Log::COLLECT> context where all messages normally end up,
		485	from there to C<$AnyEvent::Log::FILTER> where log messages with lower
		486	priority then C<$ENV{PERL_ANYEVENT_VERBOSE}> will be filtered out and then
		487	to the C<$AnyEvent::Log::LOG> context to be passed to C<warn>.
		488
		489	This makes it easy to set a global logging level (by modifying $FILTER),
		490	but still allow other contexts to send, for example, their debug and trace
		491	messages to the $LOG target despite the global logging level, or to attach
		492	additional log targets that log messages, regardless of the global logging
		493	level.
		494
		495	It also makes it easy to modify the default warn-logger ($LOG) to
		496	something that logs to a file, or to attach additional logging targets
		497	(such as loggign to a file) by attaching it to $FILTER.
		498
		499	=head2 CREATING/FINDING/DESTROYING CONTEXTS
		500
		501	=over 4
		502
		503	=item $ctx = AnyEvent::Log::ctx [$pkg]
		504
		505	This function creates or returns a logging context (which is an object).
		506
		507	If a package name is given, then the context for that packlage is
		508	returned. If it is called without any arguments, then the context for the
		509	callers package is returned (i.e. the same context as a C<AE::log> call
		510	would use).
		511
		512	If C<undef> is given, then it creates a new anonymous context that is not
		513	tied to any package and is destroyed when no longer referenced.
		514
		515	=cut
		516
		517	sub ctx(;$) {
		518	my $pkg = @_ ? shift : (caller)[0];
		519
		520	ref $pkg
		521	? $pkg
		522	: defined $pkg
		523	? $CTX{$pkg} \|\|= AnyEvent::Log::_pkg_ctx $pkg
		524	: bless [undef, (1 << 10) - 1 - 1], "AnyEvent::Log::Ctx"
		525	}
		526
		527	=item AnyEvent::Log::reset
		528
		529	Resets all package contexts and recreates the default hierarchy if
		530	necessary, i.e. resets the logging subsystem to defaults, as much as
		531	possible. This process keeps references to contexts held by other parts of
		532	the program intact.
		533
		534	This can be used to implement config-file (re-)loading: before loading a
		535	configuration, reset all contexts.
		536
		537	=cut
		538
		539	sub reset {
		540	# hard to kill complex data structures
		541	# we "recreate" all package loggers and reset the hierarchy
		542	while (my ($k, $v) = each %CTX) {
		543	@$v = ($k, (1 << 10) - 1 - 1, { });
		544
		545	$v->attach ($k =~ /^(.+)::/ ? $CTX{$1} : $AnyEvent::Log::COLLECT);
		546	}
		547
		548	@$_ = ($_->[0], (1 << 10) - 1 - 1)
		549	for $LOG, $FILTER, $COLLECT;
		550
		551	#$LOG->slaves;
		552	$LOG->title ('$AnyEvent::Log::LOG');
		553	$LOG->log_to_warn;
		554
		555	$FILTER->slaves ($LOG);
		556	$FILTER->title ('$AnyEvent::Log::FILTER');
		557	$FILTER->level ($AnyEvent::VERBOSE);
		558
		559	$COLLECT->slaves ($FILTER);
		560	$COLLECT->title ('$AnyEvent::Log::COLLECT');
		561
		562	_reassess;
		563	}
		564
		565	# create the default logger contexts
		566	$LOG = ctx undef;
		567	$FILTER = ctx undef;
		568	$COLLECT = ctx undef;
		569
		570	AnyEvent::Log::reset;
		571
		572	# hello, CPAN, please catch me
		573	package AnyEvent::Log::LOG;
		574	package AE::Log::LOG;
		575	package AnyEvent::Log::FILTER;
		576	package AE::Log::FILTER;
		577	package AnyEvent::Log::COLLECT;
		578	package AE::Log::COLLECT;
		579
		580	package AnyEvent::Log::Ctx;
		581
		582	# 0 1 2 3 4
		583	# [$title, $level, %$slaves, &$logcb, &$fmtcb]
		584
		585	=item $ctx = new AnyEvent::Log::Ctx methodname => param...
		586
		587	This is a convenience constructor that makes it simpler to construct
		588	anonymous logging contexts.
		589
		590	Each key-value pair results in an invocation of the method of the same
		591	name as the key with the value as parameter, unless the value is an
		592	arrayref, in which case it calls the method with the contents of the
		593	array. The methods are called in the same order as specified.
		594
		595	Example: create a new logging context and set both the default logging
		596	level, some slave contexts and a logging callback.
		597
		598	$ctx = new AnyEvent::Log::Ctx
		599	title => "dubious messages",
		600	level => "error",
		601	log_cb => sub { print STDOUT shift; 0 },
		602	slaves => [$ctx1, $ctx, $ctx2],
		603	;
		604
		605	=back
		606
		607	=cut
		608
		609	sub new {
		610	my $class = shift;
		611
		612	my $ctx = AnyEvent::Log::ctx undef;
		613
		614	while (@_) {
		615	my ($k, $v) = splice @_, 0, 2;
		616	$ctx->$k (ref $v eq "ARRAY" ? @$v : $v);
		617	}
		618
		619	bless $ctx, $class # do we really support subclassing, hmm?
		620	}
		621
		622
		623	=head2 CONFIGURING A LOG CONTEXT
		624
		625	The following methods can be used to configure the logging context.
		626
		627	=over 4
		628
		629	=item $ctx->title ([$new_title])
		630
		631	Returns the title of the logging context - this is the package name, for
		632	package contexts, and a user defined string for all others.
		633
		634	If C<$new_title> is given, then it replaces the package name or title.
		635
		636	=cut
		637
		638	sub title {
		639	$_[0][0] = $_[1] if @_ > 1;
		640	$_[0][0]
		641	}
		642
		643	=back
		644
		645	=head3 LOGGING LEVELS
		646
		647	The following methods deal with the logging level set associated with the
		648	log context.
		649
		650	The most common method to use is probably C<< $ctx->level ($level) >>,
		651	which configures the specified and any higher priority levels.
		652
		653	All functions which accept a list of levels also accept the special string
		654	C<all> which expands to all logging levels.
		655
		656	=over 4
		657
		658	=item $ctx->levels ($level[, $level...)
		659
		660	Enables logging for the given levels and disables it for all others.
		661
		662	=item $ctx->level ($level)
		663
		664	Enables logging for the given level and all lower level (higher priority)
		665	ones. In addition to normal logging levels, specifying a level of C<0> or
		666	C<off> disables all logging for this level.
		667
		668	Example: log warnings, errors and higher priority messages.
		669
		670	$ctx->level ("warn");
		671	$ctx->level (5); # same thing, just numeric
		672
		673	=item $ctx->enable ($level[, $level...])
		674
		675	Enables logging for the given levels, leaving all others unchanged.
		676
		677	=item $ctx->disable ($level[, $level...])
		678
		679	Disables logging for the given levels, leaving all others unchanged.
		680
		681	=cut
		682
		683	sub _lvl_lst {
		684	map {
		685	$_ > 0 && $_ <= 9 ? $_+0
		686	: $_ eq "all" ? (1 .. 9)
		687	: $STR2LEVEL{$_} \|\| Carp::croak "$_: not a valid logging level, caught"
		688	} @_
		689	}
		690
		691	our $NOP_CB = sub { 0 };
		692
		693	sub levels {
		694	my $ctx = shift;
		695	$ctx->[1] = 0;
		696	$ctx->[1] \|= 1 << $_
		697	for &_lvl_lst;
		698	AnyEvent::Log::_reassess;
		699	}
		700
		701	sub level {
		702	my $ctx = shift;
		703	my $lvl = $_[0] =~ /^(?:0\|off\|none)$/ ? 0 : (_lvl_lst $_[0])[-1];
		704
		705	$ctx->[1] = ((1 << $lvl) - 1) << 1;
		706	AnyEvent::Log::_reassess;
		707	}
		708
		709	sub enable {
		710	my $ctx = shift;
		711	$ctx->[1] \|= 1 << $_
		712	for &_lvl_lst;
		713	AnyEvent::Log::_reassess;
		714	}
		715
		716	sub disable {
		717	my $ctx = shift;
		718	$ctx->[1] &= ~(1 << $_)
		719	for &_lvl_lst;
		720	AnyEvent::Log::_reassess;
		721	}
		722
		723	=back
		724
		725	=head3 SLAVE CONTEXTS
		726
		727	The following methods attach and detach another logging context to a
		728	logging context.
		729
		730	Log messages are propagated to all slave contexts, unless the logging
		731	callback consumes the message.
		732
		733	=over 4
		734
		735	=item $ctx->attach ($ctx2[, $ctx3...])
		736
		737	Attaches the given contexts as slaves to this context. It is not an error
		738	to add a context twice (the second add will be ignored).
		739
		740	A context can be specified either as package name or as a context object.
		741
		742	=item $ctx->detach ($ctx2[, $ctx3...])
		743
		744	Removes the given slaves from this context - it's not an error to attempt
		745	to remove a context that hasn't been added.
		746
		747	A context can be specified either as package name or as a context object.
		748
		749	=item $ctx->slaves ($ctx2[, $ctx3...])
		750
		751	Replaces all slaves attached to this context by the ones given.
		752
		753	=cut
		754
		755	sub attach {
		756	my $ctx = shift;
		757
		758	$ctx->[2]{$_+0} = $_
		759	for map { AnyEvent::Log::ctx $_ } @_;
		760	}
		761
		762	sub detach {
		763	my $ctx = shift;
		764
		765	delete $ctx->[2]{$_+0}
		766	for map { AnyEvent::Log::ctx $_ } @_;
		767	}
		768
		769	sub slaves {
		770	undef $_[0][2];
		771	&attach;
		772	}
		773
		774	=back
		775
		776	=head3 LOG TARGETS
		777
		778	The following methods configure how the logging context actually does
		779	the logging (which consists of formatting the message and printing it or
		780	whatever it wants to do with it).
		781
		782	=over 4
		783
		784	=item $ctx->log_cb ($cb->($str)
		785
		786	Replaces the logging callback on the context (C<undef> disables the
		787	logging callback).
		788
		789	The logging callback is responsible for handling formatted log messages
		790	(see C<fmt_cb> below) - normally simple text strings that end with a
		791	newline (and are possibly multiline themselves).
		792
		793	It also has to return true iff it has consumed the log message, and false
		794	if it hasn't. Consuming a message means that it will not be sent to any
		795	slave context. When in doubt, return C<0> from your logging callback.
		796
		797	Example: a very simple logging callback, simply dump the message to STDOUT
		798	and do not consume it.
		799
		800	$ctx->log_cb (sub { print STDERR shift; 0 });
		801
		802	You can filter messages by having a log callback that simply returns C<1>
		803	and does not do anything with the message, but this counts as "message
		804	being logged" and might not be very efficient.
		805
		806	Example: propagate all messages except for log levels "debug" and
		807	"trace". The messages will still be generated, though, which can slow down
		808	your program.
		809
		810	$ctx->levels ("debug", "trace");
		811	$ctx->log_cb (sub { 1 }); # do not log, but eat debug and trace messages
		812
		813	=item $ctx->fmt_cb ($fmt_cb->($timestamp, $orig_ctx, $level, $message))
		814
		815	Replaces the formatting callback on the context (C<undef> restores the
		816	default formatter).
		817
		818	The callback is passed the (possibly fractional) timestamp, the original
		819	logging context, the (numeric) logging level and the raw message string
		820	and needs to return a formatted log message. In most cases this will be a
		821	string, but it could just as well be an array reference that just stores
		822	the values.
		823
		824	If, for some reason, you want to use C<caller> to find out more baout the
		825	logger then you should walk up the call stack until you are no longer
		826	inside the C<AnyEvent::Log> package.
		827
		828	Example: format just the raw message, with numeric log level in angle
		829	brackets.
		830
		831	$ctx->fmt_cb (sub {
		832	my ($time, $ctx, $lvl, $msg) = @_;
		833
		834	"<$lvl>$msg\n"
		835	});
		836
		837	Example: return an array reference with just the log values, and use
		838	C<PApp::SQL::sql_exec> to store the emssage in a database.
		839
		840	$ctx->fmt_cb (sub { \@_ });
		841	$ctx->log_cb (sub {
		842	my ($msg) = @_;
		843
		844	sql_exec "insert into log (when, subsys, prio, msg) values (?, ?, ?, ?)",
		845	$msg->[0] + 0,
		846	"$msg->[1]",
		847	$msg->[2] + 0,
		848	"$msg->[3]";
		849
		850	0
		851	});
		852
		853	=item $ctx->log_to_warn
		854
		855	Sets the C<log_cb> to simply use C<CORE::warn> to report any messages
		856	(usually this logs to STDERR).
		857
		858	=item $ctx->log_to_file ($path)
		859
		860	Sets the C<log_cb> to log to a file (by appending), unbuffered.
		861
		862	=item $ctx->log_to_path ($path)
		863
		864	Same as C<< ->log_to_file >>, but opens the file for each message. This
		865	is much slower, but allows you to change/move/rename/delete the file at
		866	basically any time.
		867
		868	Needless(?) to say, if you do not want to be bitten by some evil person
		869	calling C<chdir>, the path should be absolute. Doesn't help with
		870	C<chroot>, but hey...
		871
		872	=item $ctx->log_to_syslog ([$facility])
		873
		874	Logs all messages via L<Sys::Syslog>, mapping C<trace> to C<debug> and
		875	all the others in the obvious way. If specified, then the C<$facility> is
		876	used as the facility (C<user>, C<auth>, C<local0> and so on). The default
		877	facility is C<user>.
		878
		879	Note that this function also sets a C<fmt_cb> - the logging part requires
		880	an array reference with [$level, $str] as input.
		881
		882	=cut
		883
		884	sub log_cb {
		885	my ($ctx, $cb) = @_;
		886
		887	$ctx->[3] = $cb;
		888	}
		889
		890	sub fmt_cb {
		891	my ($ctx, $cb) = @_;
		892
		893	$ctx->[4] = $cb;
		894	}
		895
		896	sub log_to_warn {
		897	my ($ctx, $path) = @_;
		898
		899	$ctx->log_cb (sub {
		900	warn shift;
		901	0
		902	});
		903	}
		904
		905	sub log_to_file {
		906	my ($ctx, $path) = @_;
		907
		908	open my $fh, ">>", $path
		909	or die "$path: $!";
		910
		911	$ctx->log_cb (sub {
		912	syswrite $fh, shift;
		913	0
		914	});
		915	}
		916
		917	sub log_to_path {
		918	my ($ctx, $path) = @_;
		919
		920	$ctx->log_cb (sub {
		921	open my $fh, ">>", $path
		922	or die "$path: $!";
		923
		924	syswrite $fh, shift;
		925	0
		926	});
		927	}
		928
		929	sub log_to_syslog {
		930	my ($ctx, $facility) = @_;
		931
		932	require Sys::Syslog;
		933
		934	$ctx->fmt_cb (sub {
		935	my $str = $_[3];
		936	$str =~ s/\n(?=.)/\n+ /g;
		937
		938	[$_[2], "($_[1][0]) $str"]
		939	});
		940
		941	$facility \|\|= "user";
		942
		943	$ctx->log_cb (sub {
		944	my $lvl = $_[0][0] < 9 ? $_[0][0] : 8;
		945
		946	Sys::Syslog::syslog ("$facility\|" . ($lvl - 1), $_)
		947	for split /\n/, $_[0][1];
		948
		949	0
		950	});
		951	}
		952
		953	=back
		954
		955	=head3 MESSAGE LOGGING
		956
		957	These methods allow you to log messages directly to a context, without
		958	going via your package context.
		959
		960	=over 4
		961
		962	=item $ctx->log ($level, $msg[, @params])
		963
		964	Same as C<AnyEvent::Log::log>, but uses the given context as log context.
		965
		966	=item $logger = $ctx->logger ($level[, \$enabled])
		967
		968	Same as C<AnyEvent::Log::logger>, but uses the given context as log
		969	context.
		970
		971	=cut
		972
		973	*log = \&AnyEvent::Log::_log;
		974	*logger = \&AnyEvent::Log::_logger;
		975
		976	=back
		977
		978	=cut
		979
		980	package AnyEvent::Log;
		981
		982	=head1 CONFIGURATION VIA $ENV{PERL_ANYEVENT_LOG}
		983
		984	Logging can also be configured by setting the environment variable
		985	C<PERL_ANYEVENT_LOG> (or C<AE_LOG>).
		986
		987	The value consists of one or more logging context specifications separated
		988	by C<:> or whitespace. Each logging specification in turn starts with a
		989	context name, followed by C<=>, followed by zero or more comma-separated
		990	configuration directives, here are some examples:
		991
		992	# set default logging level
		993	filter=warn
		994
		995	# log to file instead of to stderr
		996	log=file=/tmp/mylog
		997
		998	# log to file in addition to stderr
		999	log=+%file:%file=file=/tmp/mylog
		1000
		1001	# enable debug log messages, log warnings and above to syslog
		1002	filter=debug:log=+%warnings:%warnings=warn,syslog=LOG_LOCAL0
		1003
		1004	# log trace messages (only) from AnyEvent::Debug to file
		1005	AnyEvent::Debug=+%trace:%trace=only,trace,file=/tmp/tracelog
		1006
		1007	A context name in the log specification can be any of the following:
		1008
		1009	=over 4
		1010
		1011	=item C<collect>, C<filter>, C<log>
		1012
		1013	Correspond to the three predefined C<$AnyEvent::Log::COLLECT>,
		1014	C<AnyEvent::Log::FILTER> and C<$AnyEvent::Log::LOG> contexts.
		1015
		1016	=item C<%name>
		1017
		1018	Context names starting with a C<%> are anonymous contexts created when the
		1019	name is first mentioned. The difference to package contexts is that by
		1020	default they have no attached slaves.
		1021
		1022	=item a perl package name
		1023
		1024	Any other string references the logging context associated with the given
		1025	Perl C<package>. In the unlikely case where you want to specify a package
		1026	context that matches on of the other context name forms, you can add a
		1027	C<::> to the package name to force interpretation as a package.
		1028
		1029	=back
		1030
		1031	The configuration specifications can be any number of the following:
		1032
		1033	=over 4
		1034
		1035	=item C<stderr>
		1036
		1037	Configures the context to use Perl's C<warn> function (which typically
		1038	logs to C<STDERR>). Works like C<log_to_warn>.
		1039
		1040	=item C<file=>I<path>
		1041
		1042	Configures the context to log to a file with the given path. Works like
		1043	C<log_to_file>.
		1044
		1045	=item C<path=>I<path>
		1046
		1047	Configures the context to log to a file with the given path. Works like
		1048	C<log_to_path>.
		1049
		1050	=item C<syslog> or C<syslog=>I<expr>
		1051
		1052	Configures the context to log to syslog. If I<expr> is given, then it is
		1053	evaluated in the L<Sys::Syslog> package, so you could use:
		1054
		1055	log=syslog=LOG_LOCAL0
		1056
		1057	=item C<nolog>
		1058
		1059	Configures the context to not log anything by itself, which is the
		1060	default. Same as C<< $ctx->log_cb (undef) >>.
		1061
		1062	=item C<0> or C<off>
		1063
		1064	Sets the logging level of the context ot C<0>, i.e. all messages will be
		1065	filtered out.
		1066
		1067	=item C<all>
		1068
		1069	Enables all logging levels, i.e. filtering will effectively be switched
		1070	off (the default).
		1071
		1072	=item C<only>
		1073
		1074	Disables all logging levels, and changes the interpretation of following
		1075	level specifications to enable the specified level only.
		1076
		1077	Example: only enable debug messages for a context.
		1078
		1079	context=only,debug
		1080
		1081	=item C<except>
		1082
		1083	Enables all logging levels, and changes the interpretation of following
		1084	level specifications to disable that level. Rarely used.
		1085
		1086	Example: enable all logging levels except fatal and trace (this is rather
		1087	nonsensical).
		1088
		1089	filter=exept,fatal,trace
		1090
		1091	=item C<level>
		1092
		1093	Enables all logging levels, and changes the interpretation of following
		1094	level specifications to be "that level or any higher priority
		1095	message". This is the default.
		1096
		1097	Example: log anything at or above warn level.
		1098
		1099	filter=warn
		1100
		1101	# or, more verbose
		1102	filter=only,level,warn
		1103
		1104	=item C<1>..C<9> or a logging level name (C<error>, C<debug> etc.)
		1105
		1106	A numeric loglevel or the name of a loglevel will be interpreted according
		1107	to the most recent C<only>, C<except> or C<level> directive. By default,
		1108	specifying a logging level enables that and any higher priority messages.
		1109
		1110	=item C<+>I<context>
		1111
		1112	Attaches the named context as slave to the context.
		1113
		1114	=item C<+>
		1115
		1116	A line C<+> detaches all contexts, i.e. clears the slave list from the
		1117	context. Anonymous (C<%name>) contexts have no attached slaves by default,
		1118	but package contexts have the parent context as slave by default.
		1119
		1120	Example: log messages from My::Module to a file, do not send them to the
		1121	default log collector.
		1122
		1123	My::Module=+,file=/tmp/mymodulelog
		1124
		1125	=back
		1126
		1127	Any character can be escaped by prefixing it with a C<\> (backslash), as
		1128	usual, so to log to a file containing a comma, colon, backslash and some
		1129	spaces in the filename, you would do this:
		1130
		1131	PERL_ANYEVENT_LOG='log=file=/some\ \:file\ with\,\ \\-escapes'
		1132
		1133	Since whitespace (which includes newlines) is allowed, it is fine to
		1134	specify multiple lines in C<PERL_ANYEVENT_LOG>, e.g.:
		1135
		1136	PERL_ANYEVENT_LOG="
		1137	filter=warn
		1138	AnyEvent::Debug=+%trace
		1139	%trace=only,trace,+log
		1140	" myprog
		1141
		1142	Also, in the unlikely case when you want to concatenate specifications,
		1143	use whitespace as separator, as C<::> will be interpreted as part of a
		1144	module name, an empty spec with two separators:
		1145
		1146	PERL_ANYEVENT_LOG="$PERL_ANYEVENT_LOG MyMod=debug"
		1147
		1148	=cut
		1149
		1150	for (my $spec = $ENV{PERL_ANYEVENT_LOG}) {
		1151	my %anon;
		1152
		1153	my $pkg = sub {
		1154	$_[0] eq "log" ? $LOG
		1155	: $_[0] eq "filter" ? $FILTER
		1156	: $_[0] eq "collect" ? $COLLECT
		1157	: $_[0] =~ /^%(.+)$/ ? ($anon{$1} \|\|= ctx undef)
		1158	: $_[0] =~ /^(.*?)(?:::)?$/ ? ctx "$1" # egad :/
		1159	: die # never reached?
		1160	};
		1161
		1162	/\G[[:space:]]+/gc; # skip initial whitespace
		1163
		1164	while (/\G((?:[^:=[:space:]]+\|::\|\\.)+)=/gc) {
		1165	my $ctx = $pkg->($1);
		1166	my $level = "level";
		1167
		1168	while (/\G((?:[^,:[:space:]]+\|::\|\\.)+)/gc) {
		1169	for ("$1") {
		1170	if ($_ eq "stderr" ) { $ctx->log_to_warn;
		1171	} elsif (/^file=(.+)/ ) { $ctx->log_to_file ("$1");
		1172	} elsif (/^path=(.+)/ ) { $ctx->log_to_path ("$1");
		1173	} elsif (/syslog(?:=(.*))?/ ) { require Sys::Syslog; $ctx->log_to_syslog ($1);
		1174	} elsif ($_ eq "nolog" ) { $ctx->log_cb (undef);
		1175	} elsif (/^\+(.+)$/ ) { $ctx->attach ($pkg->("$1"));
		1176	} elsif ($_ eq "+" ) { $ctx->slaves;
		1177	} elsif ($_ eq "off" or $_ eq "0") { $ctx->level (0);
		1178	} elsif ($_ eq "all" ) { $ctx->level ("all");
		1179	} elsif ($_ eq "level" ) { $ctx->level ("all"); $level = "level";
		1180	} elsif ($_ eq "only" ) { $ctx->level ("off"); $level = "enable";
		1181	} elsif ($_ eq "except" ) { $ctx->level ("all"); $level = "disable";
		1182	} elsif (/^\d$/ ) { $ctx->$level ($_);
		1183	} elsif (exists $STR2LEVEL{$_} ) { $ctx->$level ($_);
		1184	} else { die "PERL_ANYEVENT_LOG ($spec): parse error at '$_'\n";
		1185	}
		1186	}
		1187
		1188	/\G,/gc or last;
		1189	}
		1190
		1191	/\G[:[:space:]]+/gc or last;
		1192	}
		1193
		1194	/\G[[:space:]]+/gc; # skip trailing whitespace
		1195
		1196	if (/\G(.+)/g) {
		1197	die "PERL_ANYEVENT_LOG ($spec): parse error at '$1'\n";
		1198	}
		1199	}
22		1200
23	1;	1201	1;
		1202
		1203	=head1 EXAMPLES
		1204
		1205	This section shows some common configurations, both as code, and as
		1206	C<PERL_ANYEVENT_LOG> string.
		1207
		1208	=over 4
		1209
		1210	=item Setting the global logging level.
		1211
		1212	Either put C<PERL_ANYEVENT_VERBOSE=><number> into your environment before
		1213	running your program, use C<PERL_ANYEVENT_LOG> or modify the log level of
		1214	the root context at runtime:
		1215
		1216	PERL_ANYEVENT_VERBOSE=5 ./myprog
		1217
		1218	PERL_ANYEVENT_LOG=log=warn
		1219
		1220	$AnyEvent::Log::FILTER->level ("warn");
		1221
		1222	=item Append all messages to a file instead of sending them to STDERR.
		1223
		1224	This is affected by the global logging level.
		1225
		1226	$AnyEvent::Log::LOG->log_to_file ($path);
		1227
		1228	PERL_ANYEVENT_LOG=log=file=/some/path
		1229
		1230	=item Write all messages with priority C<error> and higher to a file.
		1231
		1232	This writes them only when the global logging level allows it, because
		1233	it is attached to the default context which is invoked I<after> global
		1234	filtering.
		1235
		1236	$AnyEvent::Log::FILTER->attach
		1237	new AnyEvent::Log::Ctx log_to_file => $path);
		1238
		1239	PERL_ANYEVENT_LOG=filter=+%filelogger:%filelogger=file=/some/path
		1240
		1241	This writes them regardless of the global logging level, because it is
		1242	attached to the toplevel context, which receives all messages I<before>
		1243	the global filtering.
		1244
		1245	$AnyEvent::Log::COLLECT->attach (
		1246	new AnyEvent::Log::Ctx log_to_file => $path);
		1247
		1248	PERL_ANYEVENT_LOG=%filelogger=file=/some/path:collect=+%filelogger
		1249
		1250	In both cases, messages are still written to STDERR.
		1251
		1252	=item Write trace messages (only) from L<AnyEvent::Debug> to the default logging target(s).
		1253
		1254	Attach the C<$AnyEvent::Log::LOG> context to the C<AnyEvent::Debug>
		1255	context - this simply circumvents the global filtering for trace messages.
		1256
		1257	my $debug = AnyEvent::Debug->AnyEvent::Log::ctx;
		1258	$debug->attach ($AnyEvent::Log::LOG);
		1259
		1260	PERL_ANYEVENT_LOG=AnyEvent::Debug=+log
		1261
		1262	This of course works for any package, not just L<AnyEvent::Debug>, but
		1263	assumes the log level for AnyEvent::Debug hasn't been changed from the
		1264	default.
24		1265
25	=back	1266	=back
26		1267
27	=head1 AUTHOR	1268	=head1 AUTHOR
28		1269
29	Marc Lehmann <schmorp@schmorp.de>	1270	Marc Lehmann <schmorp@schmorp.de>
30	http://home.schmorp.de/	1271	http://home.schmorp.de/
31		1272
32	=cut	1273	=cut
		1274

Diff Legend

-–
+Removed lines
-+
+Added lines
-<
+Changed lines
->
+Changed lines

Comparing AnyEvent/lib/AnyEvent/Log.pm (file contents): Revision 1.1 by root, Mon Aug 15 23:21:09 2011 UTC vs. Revision 1.41 by root, Thu Sep 1 04:07:18 2011 UTC

Diff Legend

Comparing AnyEvent/lib/AnyEvent/Log.pm (file contents):
Revision 1.1 by root, Mon Aug 15 23:21:09 2011 UTC vs.
Revision 1.41 by root, Thu Sep 1 04:07:18 2011 UTC