Commit | Line | Data |
5e2b2229 |
1 | package Object::Remote::Logging; |
2 | |
4e446335 |
3 | use Moo; |
4 | use Scalar::Util qw(blessed); |
5 | use Object::Remote::Logging::Logger; |
f4a85080 |
6 | use Exporter::Declare; |
663fb34f |
7 | use Carp qw(carp croak); |
5e2b2229 |
8 | |
4e446335 |
9 | extends 'Log::Contextual'; |
5e2b2229 |
10 | |
663fb34f |
11 | exports(qw( ____ router arg_levels )); |
12 | #exception log - log a message then die with that message |
13 | export_tag elog => ('____'); |
14 | #fatal log - log a message then call exit(1) |
15 | export_tag flog => ('____'); |
f4a85080 |
16 | |
4e446335 |
17 | sub router { |
c0b2df05 |
18 | our $Router_Instance ||= do { |
19 | require Object::Remote::Logging::Router; |
20 | Object::Remote::Logging::Router->new; |
21 | } |
4e446335 |
22 | } |
5e2b2229 |
23 | |
9de32e1d |
24 | #log level descriptions |
25 | #info - standard log level - normal program output for the end user |
26 | #warn - output for program that is executing quietly |
27 | #error - output for program that is running more quietly |
28 | #fatal - it is not possible to continue execution; this level is as quiet as is possible |
29 | #verbose - output for program executing verbosely (-v) |
30 | #debug - output for program running more verbosely (-v -v) |
31 | #trace - output for program running extremely verbosely (-v -v -v) |
4e446335 |
32 | sub arg_levels { |
9de32e1d |
33 | #the order of the log levels is significant with the |
34 | #most verbose level being first in the list and the |
35 | #most quiet as the last item |
36 | return [qw( trace debug verbose info warn error fatal )]; |
4a9fa1a5 |
37 | } |
5e2b2229 |
38 | |
663fb34f |
39 | sub before_import { |
40 | my ($class, $importer, $spec) = @_; |
41 | my $router = $class->router; |
c2a69537 |
42 | our $DID_INIT; |
663fb34f |
43 | |
c2a69537 |
44 | unless($DID_INIT) { |
45 | $DID_INIT = 1; |
46 | init_logging(); |
47 | } |
48 | |
663fb34f |
49 | $class->SUPER::before_import($importer, $spec); |
50 | |
51 | my @levels = @{$class->arg_levels($spec->config->{levels})}; |
52 | for my $level (@levels) { |
53 | if ($spec->config->{elog}) { |
54 | $spec->add_export("&Elog_$level", sub (&) { |
55 | my ($code, @args) = @_; |
56 | $router->handle_log_request({ |
57 | controller => $class, |
58 | package => scalar(caller), |
59 | caller_level => 1, |
60 | level => $level, |
61 | }, $code); |
62 | #TODO this should get fed into a logger so it can be formatted |
63 | croak $code->(); |
64 | }); |
65 | } |
66 | if ($spec->config->{flog}) { |
67 | #TODO that prototype isn't right |
68 | $spec->add_export("&Flog_$level", sub (&@) { |
69 | my ($code, $exit_value) = @_; |
70 | $exit_value = 1 unless defined $exit_value; |
455d031c |
71 | #don't let it going wrong stop us from calling exit() |
72 | eval { $router->handle_log_request({ |
663fb34f |
73 | controller => $class, |
74 | package => scalar(caller), |
75 | caller_level => 1, |
76 | level => $level, |
455d031c |
77 | }, $code) }; |
5cd5276e |
78 | warn "could not deliver log event during Flog_$level: $@" if $@; |
d672a9bf |
79 | eval { carp $code->() }; |
5cd5276e |
80 | warn "could not emit warning during Flog_$level: $@" if $@; |
663fb34f |
81 | exit($exit_value); |
82 | }); |
83 | } |
84 | } |
85 | } |
86 | |
ae198201 |
87 | sub _parse_selections { |
88 | my ($selections_string) = @_; |
89 | my %log_ok; |
90 | |
91 | #example string: |
92 | #" * -Object::Remote::Logging Foo::Bar::Baz " |
93 | foreach(split(/\s+/, $selections_string)) { |
94 | next if $_ eq ''; |
95 | if ($_ eq '*') { |
96 | $log_ok{$_} = 1; |
97 | } elsif (s/^-//) { |
98 | $log_ok{$_} = 0; |
99 | } else { |
100 | $log_ok{$_} = 1; |
101 | } |
102 | } |
103 | |
104 | return %log_ok; |
105 | } |
106 | |
4e446335 |
107 | #this is invoked on all nodes |
4a9fa1a5 |
108 | sub init_logging { |
c0b2df05 |
109 | my $level = $ENV{OBJECT_REMOTE_LOG_LEVEL}; |
0fe333eb |
110 | my $format = $ENV{OBJECT_REMOTE_LOG_FORMAT}; |
eb49c7df |
111 | my $selections = $ENV{OBJECT_REMOTE_LOG_SELECTIONS}; |
112 | my %controller_should_log; |
5cd5276e |
113 | |
c0b2df05 |
114 | return unless defined $level; |
0fe333eb |
115 | $format = "[%l %r] %s" unless defined $format; |
eb49c7df |
116 | $selections = __PACKAGE__ unless defined $selections; |
ae198201 |
117 | %controller_should_log = _parse_selections($selections); |
f1d70835 |
118 | |
119 | { |
120 | no warnings 'once'; |
121 | if (defined $Object::Remote::FatNode::REMOTE_NODE) { |
122 | #the connection id for the remote node comes in later |
123 | #as the controlling node inits remote logging |
124 | router()->_remote_metadata({ connection_id => undef }); |
125 | } |
126 | } |
127 | |
c0b2df05 |
128 | my $logger = Object::Remote::Logging::Logger->new( |
0fe333eb |
129 | min_level => lc($level), format => $format, |
c0b2df05 |
130 | level_names => Object::Remote::Logging::arg_levels(), |
131 | ); |
132 | |
c0b2df05 |
133 | router()->connect(sub { |
eb49c7df |
134 | my $controller = $_[1]->{controller}; |
ae198201 |
135 | my $will_log = $controller_should_log{$controller}; |
136 | |
137 | $will_log = $controller_should_log{'*'} unless defined $will_log; |
138 | |
139 | return unless $will_log; |
c0b2df05 |
140 | #skip things from remote hosts because they log to STDERR |
141 | #when OBJECT_REMOTE_LOG_LEVEL is in effect |
142 | return if $_[1]->{remote}->{connection_id}; |
143 | $logger |
144 | }); |
4a9fa1a5 |
145 | } |
146 | |
4e446335 |
147 | #this is invoked by the controlling node |
148 | #on the remote nodes |
f1d70835 |
149 | sub init_remote_logging { |
4e446335 |
150 | my ($self, %controller_info) = @_; |
151 | |
f1d70835 |
152 | router()->_remote_metadata(\%controller_info); |
f048e6df |
153 | #TODO having an instance of an object in the remote interpreter causes it to hang |
154 | #on exit intermitently or leave a zombie laying around frequently - not a bug limited |
155 | #to log forwarding |
466ee2c4 |
156 | router()->_forward_destination($controller_info{router}) if $ENV{OBJECT_REMOTE_LOG_FORWARDING}; |
4a9fa1a5 |
157 | } |
5e2b2229 |
158 | |
159 | 1; |
455d031c |
160 | |
d672a9bf |
161 | __END__ |
162 | |
163 | =head1 NAME |
164 | |
165 | Object::Remote::Logging - Logging subsystem for Object::Remote |
166 | |
167 | =head1 SYNOPSIS |
168 | |
169 | use Object::Remote::Logging qw( :log :dlog :elog :flog arg_levels router ); |
170 | |
171 | @levels = qw( trace debug verbose info warn error fatal ); |
172 | @levels = arg_levels(); #same result |
173 | |
174 | $ENV{OBJECT_REMOTE_LOG_LEVEL} = 'trace'; #or other level name |
175 | $ENV{OBJECT_REMOTE_LOG_FORMAT} = '%l %t: %p::%m %s'; #and more |
d672a9bf |
176 | $ENV{OBJECT_REMOTE_LOG_SELECTIONS} = 'Object::Remote::Logging Some::Other::Subclass'; |
ae198201 |
177 | $ENV{OBJECT_REMOTE_LOG_SELECTIONS} = '* -Object::Remote::Logging'; |
455d031c |
178 | $ENV{OBJECT_REMOTE_LOG_FORWARDING} = 0 || 1; #default 0 |
d672a9bf |
179 | |
180 | log_info { 'Trace log event' }; |
181 | Dlog_verbose { "Debug event with Data::Dumper::Concise: $_" } { foo => 'bar' }; |
182 | Elog_error { 'Error event that calls die() with this string' }; |
183 | Flog_fatal { 'Fatal event calls warn() then exit()' } 1; |
184 | |
185 | =head1 DESCRIPTION |
186 | |
187 | This is the logging framework for Object::Remote implemented as a subclass of |
188 | L<Log::Contextual> with a slightly incompatible API. This system allows |
189 | developers using Object::Remote and end users of that software to control |
190 | Object::Remote logging so operation can be tracked if needed. This is also |
191 | the API used to generate log messages inside the Object::Remote source code. |
192 | |
193 | The rest of the logging system comes from L<Object::Remote::Logging::Logger> |
194 | which implements log rendering and output and L<Object::Remote::Logging::Router> |
195 | which delivers log events to the loggers. |
196 | |
455d031c |
197 | =head1 USAGE |
198 | |
199 | Object::Remote logging is not enabled by default. If you need to immediately start |
200 | debugging set the OBJECT_REMOTE_LOG_LEVEL environment variable to either 'trace' |
201 | or 'debug'. This will enable logging to STDERR on the local and all remote Perl |
202 | interpreters. By default STDERR for all remote interpreters is passed through |
203 | unmodified so this is sufficient to receive logs generated anywhere Object::Remote |
204 | is running. |
205 | |
206 | Every time the local interpreter creates a new Object::Remote::Connection the connection |
207 | is given an id that is unique to that connection on the local interpreter. The connection |
208 | id and other metadata is available in the log output via a log format string that can |
209 | be set via the OBJECT_REMOTE_LOG_FORMAT environment variable. The format string and |
210 | available metadata is documented in L<Object::Remote::Logging::Logger>. Setting this |
211 | environment variable on the local interpreter will cause it to be propagated to the |
212 | remote interpreter so all logs will be formated the same way. |
213 | |
214 | This class is designed so any module can create their own logging sub-class using it. |
f21127fd |
215 | With out any additional configuration the consumers of this logging class will |
216 | automatically be enabled via OBJECT_REMOTE_LOG_LEVEL and formated with |
217 | OBJECT_REMOTE_LOG_FORMAT but those additional log messages are not sent to STDERR. |
218 | By setting the OBJECT_REMOTE_LOG_SELECTIONS environment variable to a list of |
219 | class names seperated by spaces then logs generated by packages that use those classes |
ae198201 |
220 | will be sent to STDERR. If the asterisk character (*) is used in the place of a class |
221 | name then all class names will be selected by default instead of ignored. An individual |
222 | class name can be turned off by prefixing the name with a hypen character (-). This is |
223 | also a configuration item that is forwarded to the remote interpreters so all logging |
224 | is consistent. |
455d031c |
225 | |
226 | Regardless of OBJECT_REMOTE_LOG_LEVEL the logging system is still active and loggers |
227 | can access the stream of log messages to format and output them. Internally |
228 | OBJECT_REMOTE_LOG_LEVEL causes an L<Object::Remote::Logging::Logger> to be built |
229 | and connected to the L<Object::Remote::Logging::Router> instance. It is also possible |
230 | to manually build a logger instance and connect it to the router. See the documentation |
f21127fd |
231 | for the logger and router classes. |
455d031c |
232 | |
233 | The logging system also supports a method of forwarding log messages from remote |
234 | interpreters to the local interpreter. Forwarded log messages are generated in the |
235 | remote interpreter and the logger for the message is invoked in the local interpreter. |
236 | Sub-classes of Object::Remote::Logging will have log messages forwarded automatically. |
237 | Loggers receive forwarded log messages exactly the same way as non-forwarded messages |
238 | except a forwarded message includes extra metadata about the remote interpreter. Log |
239 | forwarding is not currently enabled by default; to enable it set the |
240 | OBJECT_REMOTE_LOG_FORWARDING environment variable to 1. See L<Object::Remote::Logging::Router>. |
241 | |
d672a9bf |
242 | =head1 EXPORTABLE SUBROUTINES |
243 | |
244 | =over 4 |
245 | |
246 | =item arg_levels |
247 | |
248 | Returns an array reference that contains the ordered list of level names |
249 | with the lowest log level first and the highest log level last. |
250 | |
251 | =item router |
252 | |
253 | Returns the instance of L<Object::Remote::Logging::Router> that is in use. The router |
254 | instance is used in combination with L<Object::Remote::Logging::Logger> objects to |
255 | select then render and output log messages. |
256 | |
257 | =item log_<level> and Dlog_<level> |
258 | |
259 | These methods come direct from L<Log::Contextual>; see that documentation for a |
260 | complete reference. For each of the log level names there are subroutines with the log_ |
261 | and Dlog_ prefix that will generate the log message. The first argument is a code block |
262 | that returns the log message contents and the optional further arguments are both passed |
263 | to the block as the argument list and returned from the log method as a list. |
264 | |
265 | log_trace { "A fine log message $_[0] " } 'if I do say so myself'; |
455d031c |
266 | %hash = Dlog_trace { "Very handy: $_" } ( foo => 'bar' ); |
d672a9bf |
267 | |
268 | =item logS_<level> and DlogS_<level> |
269 | |
270 | Works just like log_ and Dlog_ except returns only the first argument as a scalar value. |
271 | |
272 | my $beverage = log_info { "Customer ordered $_[0]" } 'Coffee'; |
273 | |
274 | =item Elog_<level> |
275 | |
276 | Log an event and then generate an exception by calling die() with the log message. |
277 | |
278 | Elog_error { "Could not open file: $!" }; |
279 | |
280 | =item Flog_<level> |
281 | |
282 | Log the event, generate a warning with the log message, then call exit(). The exit |
283 | value will default to 1 or can be specified as an argument. |
284 | |
285 | Flog_fatal { 'Could not lock resource' } 3; |
286 | |
287 | =back |
288 | |
289 | =head1 LEVEL NAMES |
290 | |
293fb1ee |
291 | Object::Remote uses an ordered list of log level names with the lowest level |
292 | first and the highest level last. The list of level names can be accessed via |
d672a9bf |
293 | the arg_levels method which is exportable to the consumer of this class. The log |
294 | level names are: |
295 | |
296 | =over 4 |
297 | |
298 | =item trace |
299 | |
300 | As much information about operation as possible including multiple line dumps of |
301 | large content. Tripple verbose operation (-v -v -v). |
302 | |
303 | =item debug |
304 | |
305 | Messages about operations that could hang as well as internal state changes, |
306 | results from method invocations, and information useful when looking for faults. |
307 | Double verbose operation (-v -v). |
308 | |
309 | =item verbose |
310 | |
311 | Additional optional messages to the user that can be enabled at their will. Single |
312 | verbose operation (-v). |
313 | |
314 | =item info |
315 | |
316 | Messages from normal operation that are intended to be displayed to the end |
317 | user if quiet operation is not indicated and more verbose operation is not |
318 | in effect. |
319 | |
320 | =item warn |
321 | |
322 | Something wasn't supposed to happen but did. Operation was not impacted but |
323 | otherwise the event is noteworthy. Single quiet operation (-q). |
324 | |
325 | =item error |
326 | |
327 | Something went wrong. Operation of the system may continue but some operation |
328 | has most definitely failed. Double quiet operation (-q -q). |
329 | |
330 | =item fatal |
331 | |
332 | Something went wrong and recovery is not possible. The system should stop operating |
333 | as soon as possible. Tripple quiet operation (-q -q -q). |
334 | |
335 | =back |