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