ViewVC Help

View File | Revision Log | Show Annotations | Download File

/cvs/AnyEvent/lib/AnyEvent/Log.pm

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

Diff Legend

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