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