change log init to be entirely with in object::remote::logging
[scpubgit/Object-Remote.git] / lib / Object / Remote /
5e2b2229 1package Object::Remote::Logging;
4e446335 3use Moo;
4use Scalar::Util qw(blessed);
5use Object::Remote::Logging::Logger;
f4a85080 6use Exporter::Declare;
663fb34f 7use Carp qw(carp croak);
5e2b2229 8
4e446335 9extends 'Log::Contextual';
5e2b2229 10
663fb34f 11exports(qw( ____ router arg_levels ));
12#exception log - log a message then die with that message
13export_tag elog => ('____');
14#fatal log - log a message then call exit(1)
15export_tag flog => ('____');
f4a85080 16
4e446335 17sub 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 32sub 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 39sub 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 }
663fb34f 49 $class->SUPER::before_import($importer, $spec);
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 }
ae198201 87sub _parse_selections {
88 my ($selections_string) = @_;
89 my %log_ok;
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 }
104 return %log_ok;
4e446335 107#this is invoked on all nodes
4a9fa1a5 108sub 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);
eb49c7df 118
c0b2df05 119 my $logger = Object::Remote::Logging::Logger->new(
0fe333eb 120 min_level => lc($level), format => $format,
c0b2df05 121 level_names => Object::Remote::Logging::arg_levels(),
122 );
c0b2df05 124 router()->connect(sub {
eb49c7df 125 my $controller = $_[1]->{controller};
ae198201 126 my $will_log = $controller_should_log{$controller};
128 $will_log = $controller_should_log{'*'} unless defined $will_log;
130 return unless $will_log;
c0b2df05 131 #skip things from remote hosts because they log to STDERR
132 #when OBJECT_REMOTE_LOG_LEVEL is in effect
133 return if $_[1]->{remote}->{connection_id};
134 $logger
135 });
4a9fa1a5 136}
4e446335 138#this is invoked by the controlling node
139#on the remote nodes
4a9fa1a5 140sub init_logging_forwarding {
4e446335 141 my ($self, %controller_info) = @_;
143 router()->_remote_metadata({ connection_id => $controller_info{connection_id} });
f048e6df 144 #TODO having an instance of an object in the remote interpreter causes it to hang
145 #on exit intermitently or leave a zombie laying around frequently - not a bug limited
146 #to log forwarding
466ee2c4 147 router()->_forward_destination($controller_info{router}) if $ENV{OBJECT_REMOTE_LOG_FORWARDING};
4a9fa1a5 148}
5e2b2229 149
455d031c 151
d672a9bf 152__END__
154=head1 NAME
156Object::Remote::Logging - Logging subsystem for Object::Remote
158=head1 SYNOPSIS
160 use Object::Remote::Logging qw( :log :dlog :elog :flog arg_levels router );
162 @levels = qw( trace debug verbose info warn error fatal );
163 @levels = arg_levels(); #same result
165 $ENV{OBJECT_REMOTE_LOG_LEVEL} = 'trace'; #or other level name
166 $ENV{OBJECT_REMOTE_LOG_FORMAT} = '%l %t: %p::%m %s'; #and more
d672a9bf 167 $ENV{OBJECT_REMOTE_LOG_SELECTIONS} = 'Object::Remote::Logging Some::Other::Subclass';
ae198201 168 $ENV{OBJECT_REMOTE_LOG_SELECTIONS} = '* -Object::Remote::Logging';
455d031c 169 $ENV{OBJECT_REMOTE_LOG_FORWARDING} = 0 || 1; #default 0
d672a9bf 170
171 log_info { 'Trace log event' };
172 Dlog_verbose { "Debug event with Data::Dumper::Concise: $_" } { foo => 'bar' };
173 Elog_error { 'Error event that calls die() with this string' };
174 Flog_fatal { 'Fatal event calls warn() then exit()' } 1;
178This is the logging framework for Object::Remote implemented as a subclass of
179L<Log::Contextual> with a slightly incompatible API. This system allows
180developers using Object::Remote and end users of that software to control
181Object::Remote logging so operation can be tracked if needed. This is also
182the API used to generate log messages inside the Object::Remote source code.
184The rest of the logging system comes from L<Object::Remote::Logging::Logger>
185which implements log rendering and output and L<Object::Remote::Logging::Router>
186which delivers log events to the loggers.
455d031c 188=head1 USAGE
190Object::Remote logging is not enabled by default. If you need to immediately start
191debugging set the OBJECT_REMOTE_LOG_LEVEL environment variable to either 'trace'
192or 'debug'. This will enable logging to STDERR on the local and all remote Perl
193interpreters. By default STDERR for all remote interpreters is passed through
194unmodified so this is sufficient to receive logs generated anywhere Object::Remote
195is running.
197Every time the local interpreter creates a new Object::Remote::Connection the connection
198is given an id that is unique to that connection on the local interpreter. The connection
199id and other metadata is available in the log output via a log format string that can
200be set via the OBJECT_REMOTE_LOG_FORMAT environment variable. The format string and
201available metadata is documented in L<Object::Remote::Logging::Logger>. Setting this
202environment variable on the local interpreter will cause it to be propagated to the
203remote interpreter so all logs will be formated the same way.
205This class is designed so any module can create their own logging sub-class using it.
f21127fd 206With out any additional configuration the consumers of this logging class will
207automatically be enabled via OBJECT_REMOTE_LOG_LEVEL and formated with
208OBJECT_REMOTE_LOG_FORMAT but those additional log messages are not sent to STDERR.
209By setting the OBJECT_REMOTE_LOG_SELECTIONS environment variable to a list of
210class names seperated by spaces then logs generated by packages that use those classes
ae198201 211will be sent to STDERR. If the asterisk character (*) is used in the place of a class
212name then all class names will be selected by default instead of ignored. An individual
213class name can be turned off by prefixing the name with a hypen character (-). This is
214also a configuration item that is forwarded to the remote interpreters so all logging
215is consistent.
455d031c 216
217Regardless of OBJECT_REMOTE_LOG_LEVEL the logging system is still active and loggers
218can access the stream of log messages to format and output them. Internally
219OBJECT_REMOTE_LOG_LEVEL causes an L<Object::Remote::Logging::Logger> to be built
220and connected to the L<Object::Remote::Logging::Router> instance. It is also possible
221to manually build a logger instance and connect it to the router. See the documentation
f21127fd 222for the logger and router classes.
455d031c 223
224The logging system also supports a method of forwarding log messages from remote
225interpreters to the local interpreter. Forwarded log messages are generated in the
226remote interpreter and the logger for the message is invoked in the local interpreter.
227Sub-classes of Object::Remote::Logging will have log messages forwarded automatically.
228Loggers receive forwarded log messages exactly the same way as non-forwarded messages
229except a forwarded message includes extra metadata about the remote interpreter. Log
230forwarding is not currently enabled by default; to enable it set the
231OBJECT_REMOTE_LOG_FORWARDING environment variable to 1. See L<Object::Remote::Logging::Router>.
235=over 4
237=item arg_levels
239Returns an array reference that contains the ordered list of level names
240with the lowest log level first and the highest log level last.
242=item router
244Returns the instance of L<Object::Remote::Logging::Router> that is in use. The router
245instance is used in combination with L<Object::Remote::Logging::Logger> objects to
246select then render and output log messages.
248=item log_<level> and Dlog_<level>
250These methods come direct from L<Log::Contextual>; see that documentation for a
251complete reference. For each of the log level names there are subroutines with the log_
252and Dlog_ prefix that will generate the log message. The first argument is a code block
253that returns the log message contents and the optional further arguments are both passed
254to the block as the argument list and returned from the log method as a list.
256 log_trace { "A fine log message $_[0] " } 'if I do say so myself';
455d031c 257 %hash = Dlog_trace { "Very handy: $_" } ( foo => 'bar' );
d672a9bf 258
259=item logS_<level> and DlogS_<level>
261Works just like log_ and Dlog_ except returns only the first argument as a scalar value.
263 my $beverage = log_info { "Customer ordered $_[0]" } 'Coffee';
265=item Elog_<level>
267Log an event and then generate an exception by calling die() with the log message.
269 Elog_error { "Could not open file: $!" };
271=item Flog_<level>
273Log the event, generate a warning with the log message, then call exit(). The exit
274value will default to 1 or can be specified as an argument.
276 Flog_fatal { 'Could not lock resource' } 3;
280=head1 LEVEL NAMES
293fb1ee 282Object::Remote uses an ordered list of log level names with the lowest level
283first and the highest level last. The list of level names can be accessed via
d672a9bf 284the arg_levels method which is exportable to the consumer of this class. The log
285level names are:
287=over 4
289=item trace
291As much information about operation as possible including multiple line dumps of
292large content. Tripple verbose operation (-v -v -v).
294=item debug
296Messages about operations that could hang as well as internal state changes,
297results from method invocations, and information useful when looking for faults.
298Double verbose operation (-v -v).
300=item verbose
302Additional optional messages to the user that can be enabled at their will. Single
303verbose operation (-v).
305=item info
307Messages from normal operation that are intended to be displayed to the end
308user if quiet operation is not indicated and more verbose operation is not
309in effect.
311=item warn
313Something wasn't supposed to happen but did. Operation was not impacted but
314otherwise the event is noteworthy. Single quiet operation (-q).
316=item error
318Something went wrong. Operation of the system may continue but some operation
319has most definitely failed. Double quiet operation (-q -q).
321=item fatal
323Something went wrong and recovery is not possible. The system should stop operating
324as soon as possible. Tripple quiet operation (-q -q -q).