Log::Any can inject messages into log router and acts as full class citizen in loggin...
[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 #this is invoked on all nodes
82 sub init_logging {
83   my $level = $ENV{OBJECT_REMOTE_LOG_LEVEL};
84   my $format = $ENV{OBJECT_REMOTE_LOG_FORMAT};
85   my $selections = $ENV{OBJECT_REMOTE_LOG_SELECTIONS};
86   my %controller_should_log;
87
88   eval { 
89     require Log::Any::Adapter;
90     require Object::Remote::Logging::LogAnyInjector;
91     Log::Any::Adapter->set('+Object::Remote::Logging::LogAnyInjector');
92   };
93
94   return unless defined $level;
95   $format = "[%l %r] %s" unless defined $format;
96   $selections = __PACKAGE__ unless defined $selections;
97   %controller_should_log = map { $_ => 1 } split(' ', $selections);
98   
99   my $logger = Object::Remote::Logging::Logger->new(
100     min_level => lc($level), format => $format,
101     level_names => Object::Remote::Logging::arg_levels(),
102   );
103
104   router()->connect(sub { 
105     my $controller = $_[1]->{controller};
106     return unless $controller_should_log{'*'} || $controller_should_log{$controller};
107     #skip things from remote hosts because they log to STDERR
108     #when OBJECT_REMOTE_LOG_LEVEL is in effect
109     return if $_[1]->{remote}->{connection_id};
110     $logger
111   });
112 }
113
114 #this is invoked by the controlling node
115 #on the remote nodes
116 sub init_logging_forwarding {
117   my ($self, %controller_info) = @_;
118   
119   router()->_remote_metadata({ connection_id => $controller_info{connection_id} });
120   router()->_forward_destination($controller_info{router}) if $ENV{OBJECT_REMOTE_LOG_FORWARDING};
121 }
122
123 1;
124
125 __END__
126
127 =head1 NAME
128
129 Object::Remote::Logging - Logging subsystem for Object::Remote
130
131 =head1 SYNOPSIS
132
133   use Object::Remote::Logging qw( :log :dlog :elog :flog arg_levels router );
134   
135   @levels = qw( trace debug verbose info warn error fatal );
136   @levels = arg_levels(); #same result
137   
138   $ENV{OBJECT_REMOTE_LOG_LEVEL} = 'trace'; #or other level name
139   $ENV{OBJECT_REMOTE_LOG_FORMAT} = '%l %t: %p::%m %s'; #and more
140   $ENV{OBJECT_REMOTE_LOG_SELECTIONS} = 'Object::Remote::Logging Some::Other::Subclass';
141   $ENV{OBJECT_REMOTE_LOG_FORWARDING} = 0 || 1; #default 0
142   
143   log_info { 'Trace log event' };
144   Dlog_verbose { "Debug event with Data::Dumper::Concise: $_" } { foo => 'bar' };
145   Elog_error { 'Error event that calls die() with this string' };
146   Flog_fatal { 'Fatal event calls warn() then exit()' } 1;
147
148 =head1 DESCRIPTION
149
150 This is the logging framework for Object::Remote implemented as a subclass of
151 L<Log::Contextual> with a slightly incompatible API. This system allows 
152 developers using Object::Remote and end users of that software to control
153 Object::Remote logging so operation can be tracked if needed. This is also
154 the API used to generate log messages inside the Object::Remote source code.
155
156 The rest of the logging system comes from L<Object::Remote::Logging::Logger>
157 which implements log rendering and output and L<Object::Remote::Logging::Router>
158 which delivers log events to the loggers.
159
160 =head1 USAGE
161
162 Object::Remote logging is not enabled by default. If you need to immediately start
163 debugging set the OBJECT_REMOTE_LOG_LEVEL environment variable to either 'trace'
164 or 'debug'. This will enable logging to STDERR on the local and all remote Perl 
165 interpreters. By default STDERR for all remote interpreters is passed through
166 unmodified so this is sufficient to receive logs generated anywhere Object::Remote
167 is running.
168
169 Every time the local interpreter creates a new Object::Remote::Connection the connection
170 is given an id that is unique to that connection on the local interpreter. The connection
171 id and other metadata is available in the log output via a log format string that can
172 be set via the OBJECT_REMOTE_LOG_FORMAT environment variable. The format string and
173 available metadata is documented in L<Object::Remote::Logging::Logger>. Setting this
174 environment variable on the local interpreter will cause it to be propagated to the 
175 remote interpreter so all logs will be formated the same way.
176
177 This class is designed so any module can create their own logging sub-class using it.
178 With out any additional configuration the consumers of this logging class will
179 automatically be enabled via OBJECT_REMOTE_LOG_LEVEL and formated with 
180 OBJECT_REMOTE_LOG_FORMAT but those additional log messages are not sent to STDERR. 
181 By setting the  OBJECT_REMOTE_LOG_SELECTIONS environment variable to a list of
182 class names seperated by spaces then logs generated by packages that use those classes
183 will be sent to STDERR. This is also a configuration item that is forwarded to the
184 remote interpreters so all logging is consistent.
185
186 Regardless of OBJECT_REMOTE_LOG_LEVEL the logging system is still active and loggers
187 can access the stream of log messages to format and output them. Internally
188 OBJECT_REMOTE_LOG_LEVEL causes an L<Object::Remote::Logging::Logger> to be built
189 and connected to the L<Object::Remote::Logging::Router> instance. It is also possible
190 to manually build a logger instance and connect it to the router. See the documentation
191 for the logger and router classes.
192
193 The logging system also supports a method of forwarding log messages from remote
194 interpreters to the local interpreter. Forwarded log messages are generated in the
195 remote interpreter and the logger for the message is invoked in the local interpreter.
196 Sub-classes of Object::Remote::Logging will have log messages forwarded automatically.
197 Loggers receive forwarded log messages exactly the same way as non-forwarded messages
198 except a forwarded message includes extra metadata about the remote interpreter. Log
199 forwarding is not currently enabled by default; to enable it set the 
200 OBJECT_REMOTE_LOG_FORWARDING environment variable to 1. See L<Object::Remote::Logging::Router>.
201
202 =head1 EXPORTABLE SUBROUTINES
203
204 =over 4
205
206 =item arg_levels
207
208 Returns an array reference that contains the ordered list of level names
209 with the lowest log level first and the highest log level last.
210
211 =item router
212
213 Returns the instance of L<Object::Remote::Logging::Router> that is in use. The router
214 instance is used in combination with L<Object::Remote::Logging::Logger> objects to
215 select then render and output log messages.
216
217 =item log_<level> and Dlog_<level>
218
219 These methods come direct from L<Log::Contextual>; see that documentation for a 
220 complete reference. For each of the log level names there are subroutines with the log_
221 and Dlog_ prefix that will generate the log message. The first argument is a code block
222 that returns the log message contents and the optional further arguments are both passed
223 to the block as the argument list and returned from the log method as a list.
224
225   log_trace { "A fine log message $_[0] " } 'if I do say so myself';
226   %hash = Dlog_trace { "Very handy: $_" } ( foo => 'bar' );
227
228 =item logS_<level> and DlogS_<level>
229
230 Works just like log_ and Dlog_ except returns only the first argument as a scalar value.
231
232   my $beverage = log_info { "Customer ordered $_[0]" } 'Coffee';
233
234 =item Elog_<level>
235
236 Log an event and then generate an exception by calling die() with the log message.
237
238   Elog_error { "Could not open file: $!" };
239
240 =item Flog_<level>
241
242 Log the event, generate a warning with the log message, then call exit(). The exit
243 value will default to 1 or can be specified as an argument.
244
245   Flog_fatal { 'Could not lock resource' } 3;
246
247 =back
248
249 =head1 LEVEL NAMES
250
251 Object::Remote uses an ordered list of log level names with the minimum level
252 first and the maximum level last. The list of level names can be accessed via
253 the arg_levels method which is exportable to the consumer of this class. The log
254 level names are:
255
256 =over 4
257
258 =item trace
259
260 As much information about operation as possible including multiple line dumps of
261 large content. Tripple verbose operation (-v -v -v).
262
263 =item debug
264
265 Messages about operations that could hang as well as internal state changes, 
266 results from method invocations, and information useful when looking for faults.
267 Double verbose operation (-v -v).
268
269 =item verbose
270
271 Additional optional messages to the user that can be enabled at their will. Single
272 verbose operation (-v).
273
274 =item info
275
276 Messages from normal operation that are intended to be displayed to the end
277 user if quiet operation is not indicated and more verbose operation is not
278 in effect.
279
280 =item warn
281
282 Something wasn't supposed to happen but did. Operation was not impacted but
283 otherwise the event is noteworthy. Single quiet operation (-q).
284
285 =item error
286
287 Something went wrong. Operation of the system may continue but some operation
288 has most definitely failed. Double quiet operation (-q -q).
289
290 =item fatal
291
292 Something went wrong and recovery is not possible. The system should stop operating
293 as soon as possible. Tripple quiet operation (-q -q -q).
294
295 =back