… | |
… | |
37 | |
37 | |
38 | use Carp (); |
38 | use Carp (); |
39 | use POSIX (); |
39 | use POSIX (); |
40 | |
40 | |
41 | use AnyEvent (); BEGIN { AnyEvent::common_sense } |
41 | use AnyEvent (); BEGIN { AnyEvent::common_sense } |
|
|
42 | use AnyEvent::Util (); |
42 | |
43 | |
43 | our ($now_int, $now_str1, $now_str2); |
44 | our ($now_int, $now_str1, $now_str2); |
44 | |
45 | |
45 | # Format Time, not public - yet? |
46 | # Format Time, not public - yet? |
46 | sub ft($) { |
47 | sub ft($) { |
… | |
… | |
51 | if $now_int != $i; |
52 | if $now_int != $i; |
52 | |
53 | |
53 | "$now_str1$f$now_str2" |
54 | "$now_str1$f$now_str2" |
54 | } |
55 | } |
55 | |
56 | |
|
|
57 | our %CFG; #TODO |
|
|
58 | |
56 | =item AnyEvent::Log::log $level, $msg[, @args] |
59 | =item AnyEvent::Log::log $level, $msg[, @args] |
57 | |
60 | |
58 | Requests logging of the given C<$msg> with the given log level (1..9). |
61 | Requests logging of the given C<$msg> with the given log level (1..9). |
59 | You can also use the following strings as log level: C<fatal> (1), |
62 | You can also use the following strings as log level: C<fatal> (1), |
60 | C<alert> (2), C<critical> (3), C<error> (4), C<warn> (5), C<note> (6), |
63 | C<alert> (2), C<critical> (3), C<error> (4), C<warn> (5), C<note> (6), |
… | |
… | |
66 | C<$msg> is interpreted as an sprintf format string. |
69 | C<$msg> is interpreted as an sprintf format string. |
67 | |
70 | |
68 | The C<$msg> should not end with C<\n>, but may if that is convenient for |
71 | The C<$msg> should not end with C<\n>, but may if that is convenient for |
69 | you. Also, multiline messages are handled properly. |
72 | you. Also, multiline messages are handled properly. |
70 | |
73 | |
71 | In addition, for possible future expansion, C<$msg> must not start with an |
74 | Last not least, C<$msg> might be a code reference, in which case it is |
72 | angle bracket (C<< < >>). |
75 | supposed to return the message. It will be called only then the message |
|
|
76 | actually gets logged, which is useful if it is costly to create the |
|
|
77 | message in the first place. |
73 | |
78 | |
74 | Whether the given message will be logged depends on the maximum log level |
79 | Whether the given message will be logged depends on the maximum log level |
75 | and the caller's package. |
80 | and the caller's package. |
76 | |
81 | |
77 | Note that you can (and should) call this function as C<AnyEvent::log> or |
82 | Note that you can (and should) call this function as C<AnyEvent::log> or |
78 | C<AE::log>, without C<use>-ing this module if possible, as those functions |
83 | C<AE::log>, without C<use>-ing this module if possible, as those functions |
79 | will laod the logging module on demand only. |
84 | will laod the logging module on demand only. |
|
|
85 | |
|
|
86 | Example: log something at error level. |
|
|
87 | |
|
|
88 | AE::log error => "something"; |
|
|
89 | |
|
|
90 | Example: use printf-formatting. |
|
|
91 | |
|
|
92 | AE::log info => "%5d %-10.10s %s", $index, $category, $msg; |
|
|
93 | |
|
|
94 | Example: only generate a costly dump when the message is actually being logged. |
|
|
95 | |
|
|
96 | AE::log debug => sub { require Data::Dump; Data::Dump::dump \%cache }; |
80 | |
97 | |
81 | =cut |
98 | =cut |
82 | |
99 | |
83 | # also allow syslog equivalent names |
100 | # also allow syslog equivalent names |
84 | our %STR2LEVEL = ( |
101 | our %STR2LEVEL = ( |
… | |
… | |
93 | trace => 9, |
110 | trace => 9, |
94 | ); |
111 | ); |
95 | |
112 | |
96 | our @LEVEL2STR = qw(0 fatal alert crit error warn note info debug trace); |
113 | our @LEVEL2STR = qw(0 fatal alert crit error warn note info debug trace); |
97 | |
114 | |
98 | sub log($$;@) { |
115 | sub _log { |
99 | my ($targ, $msg, @args) = @_; |
116 | my ($pkg, $targ, $msg, @args) = @_; |
100 | |
117 | |
101 | my $level = ref $targ ? die "Can't use reference as logging level (yet)" |
118 | my $level = ref $targ ? die "Can't use reference as logging level (yet)" |
102 | : $targ > 0 && $targ <= 9 ? $targ+0 |
119 | : $targ > 0 && $targ <= 9 ? $targ+0 |
103 | : $STR2LEVEL{$targ} || Carp::croak "$targ: not a valid logging level, caught"; |
120 | : $STR2LEVEL{$targ} || Carp::croak "$targ: not a valid logging level, caught"; |
104 | |
121 | |
105 | return if $level > $AnyEvent::VERBOSE; |
122 | return if $level > $AnyEvent::VERBOSE; |
106 | |
123 | |
107 | my $pkg = (caller)[0]; |
124 | $msg = $msg->() if ref $msg; |
108 | |
|
|
109 | $msg = sprintf $msg, @args if @args; |
125 | $msg = sprintf $msg, @args if @args; |
110 | $msg =~ s/\n$//; |
126 | $msg =~ s/\n$//; |
111 | |
127 | |
112 | # now we have a message, log it |
128 | # now we have a message, log it |
113 | #TODO: could do LOTS of stuff here, and should, at least in some later version |
129 | #TODO: could do LOTS of stuff here, and should, at least in some later version |
114 | |
130 | |
115 | $msg = sprintf "%5s (%s) %s", $LEVEL2STR[$level], $pkg, $msg; |
131 | $msg = sprintf "%5s %s: %s", $LEVEL2STR[$level], $pkg, $msg; |
116 | my $pfx = ft AE::now; |
132 | my $pfx = ft AE::now; |
117 | |
133 | |
118 | for (split /\n/, $msg) { |
134 | for (split /\n/, $msg) { |
119 | printf STDERR "$pfx $_\n"; |
135 | printf STDERR "$pfx $_\n"; |
120 | $pfx = "\t"; |
136 | $pfx = "\t"; |
121 | } |
137 | } |
122 | |
138 | |
123 | exit 1 if $level <= 1; |
139 | exit 1 if $level <= 1; |
124 | } |
140 | } |
125 | |
141 | |
|
|
142 | sub log($$;@) { |
|
|
143 | _log +(caller)[0], @_; |
|
|
144 | } |
|
|
145 | |
126 | *AnyEvent::log = *AE::log = \&log; |
146 | *AnyEvent::log = *AE::log = \&log; |
|
|
147 | |
|
|
148 | =item $logger = AnyEvent::Log::logger $level[, \$enabled] |
|
|
149 | |
|
|
150 | Creates a code reference that, when called, acts as if the |
|
|
151 | C<AnyEvent::Log::log> function was called at this point with the givne |
|
|
152 | level. C<$logger> is passed a C<$msg> and optional C<@args>, just as with |
|
|
153 | the C<AnyEvent::Log::log> function: |
|
|
154 | |
|
|
155 | my $debug_log = AnyEvent::Log::logger "debug"; |
|
|
156 | |
|
|
157 | $debug_log->("debug here"); |
|
|
158 | $debug_log->("%06d emails processed", 12345); |
|
|
159 | $debug_log->(sub { $obj->as_string }); |
|
|
160 | |
|
|
161 | The idea behind this function is to decide whether to log before actually |
|
|
162 | logging - when the C<logger> function is called once, but the returned |
|
|
163 | logger callback often, then this can be a tremendous speed win. |
|
|
164 | |
|
|
165 | Despite this speed advantage, changes in logging configuration will |
|
|
166 | still be reflected by the logger callback, even if configuration changes |
|
|
167 | I<after> it was created. |
|
|
168 | |
|
|
169 | To further speed up logging, you can bind a scalar variable to the logger, |
|
|
170 | which contains true if the logger should be called or not - if it is |
|
|
171 | false, calling the logger can be safely skipped. This variable will be |
|
|
172 | updated as long as C<$logger> is alive. |
|
|
173 | |
|
|
174 | Full example: |
|
|
175 | |
|
|
176 | # near the init section |
|
|
177 | use AnyEvent::Log; |
|
|
178 | |
|
|
179 | my $debug_log = AnyEvent:Log::logger debug => \my $debug; |
|
|
180 | |
|
|
181 | # and later in your program |
|
|
182 | $debug_log->("yo, stuff here") if $debug; |
|
|
183 | |
|
|
184 | $debug and $debug_log->("123"); |
|
|
185 | |
|
|
186 | Note: currently the enabled var is always true - that will be fixed in a |
|
|
187 | future version :) |
|
|
188 | |
|
|
189 | =cut |
|
|
190 | |
|
|
191 | our %LOGGER; |
|
|
192 | |
|
|
193 | # re-assess logging status for all loggers |
|
|
194 | sub _reassess { |
|
|
195 | for (@_ ? $LOGGER{$_[0]} : values %LOGGER) { |
|
|
196 | my ($pkg, $level, $renabled) = @$_; |
|
|
197 | |
|
|
198 | # to detetc whether a message would be logged, we # actually |
|
|
199 | # try to log one and die. this isn't # fast, but we can be |
|
|
200 | # sure that the logging decision is correct :) |
|
|
201 | |
|
|
202 | $$renabled = !eval { |
|
|
203 | local $SIG{__DIE__}; |
|
|
204 | |
|
|
205 | _log $pkg, $level, sub { die }; |
|
|
206 | |
|
|
207 | 1 |
|
|
208 | }; |
|
|
209 | |
|
|
210 | $$renabled = 1; # TODO |
|
|
211 | } |
|
|
212 | } |
|
|
213 | |
|
|
214 | sub logger($;$) { |
|
|
215 | my ($level, $renabled) = @_; |
|
|
216 | |
|
|
217 | $renabled ||= \my $enabled; |
|
|
218 | my $pkg = (caller)[0]; |
|
|
219 | |
|
|
220 | $$renabled = 1; |
|
|
221 | |
|
|
222 | my $logger = [$pkg, $level, $renabled]; |
|
|
223 | |
|
|
224 | $LOGGER{$logger+0} = $logger; |
|
|
225 | |
|
|
226 | _reassess $logger+0; |
|
|
227 | |
|
|
228 | my $guard = AnyEvent::Util::guard { |
|
|
229 | # "clean up" |
|
|
230 | delete $LOGGER{$logger+0}; |
|
|
231 | }; |
|
|
232 | |
|
|
233 | sub { |
|
|
234 | $guard if 0; # keep guard alive, but don't cause runtime overhead |
|
|
235 | |
|
|
236 | _log $pkg, $level, @_ |
|
|
237 | if $$renabled; |
|
|
238 | } |
|
|
239 | } |
127 | |
240 | |
128 | #TODO |
241 | #TODO |
129 | |
242 | |
130 | =back |
243 | =back |
131 | |
244 | |