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   #TODO having an instance of an object in the remote interpreter causes it to hang
 147   #on exit intermitently or leave a zombie laying around frequently - not a bug limited
 148   #to log forwarding
 149   router()->_forward_destination($controller_info{router}) if $ENV{OBJECT_REMOTE_LOG_FORWARDING};
 150 }
 151
 152 1;
 153
 154 __END__
 155
 156 =head1 NAME
 157
 158 Object::Remote::Logging - Logging subsystem for Object::Remote
 159
 160 =head1 SYNOPSIS
 161
 162   use Object::Remote::Logging qw( :log :dlog :elog :flog arg_levels router );
 163
 164   @levels = qw( trace debug verbose info warn error fatal );
 165   @levels = arg_levels(); #same result
 166
 167   $ENV{OBJECT_REMOTE_LOG_LEVEL} = 'trace'; #or other level name
 168   $ENV{OBJECT_REMOTE_LOG_FORMAT} = '%l %t: %p::%m %s'; #and more
 169   $ENV{OBJECT_REMOTE_LOG_SELECTIONS} = 'Object::Remote::Logging Some::Other::Subclass';
 170   $ENV{OBJECT_REMOTE_LOG_SELECTIONS} = '* -Object::Remote::Logging';
 171   $ENV{OBJECT_REMOTE_LOG_FORWARDING} = 0 || 1; #default 0
 172
 173   log_info { 'Trace log event' };
 174   Dlog_verbose { "Debug event with Data::Dumper::Concise: $_" } { foo => 'bar' };
 175   Elog_error { 'Error event that calls die() with this string' };
 176   Flog_fatal { 'Fatal event calls warn() then exit()' } 1;
 177
 178 =head1 DESCRIPTION
 179
 180 This is the logging framework for Object::Remote implemented as a subclass of
 181 L<Log::Contextual> with a slightly incompatible API. This system allows
 182 developers using Object::Remote and end users of that software to control
 183 Object::Remote logging so operation can be tracked if needed. This is also
 184 the API used to generate log messages inside the Object::Remote source code.
 185
 186 The rest of the logging system comes from L<Object::Remote::Logging::Logger>
 187 which implements log rendering and output and L<Object::Remote::Logging::Router>
 188 which delivers log events to the loggers.
 189
 190 =head1 USAGE
 191
 192 Object::Remote logging is not enabled by default. If you need to immediately start
 193 debugging set the OBJECT_REMOTE_LOG_LEVEL environment variable to either 'trace'
 194 or 'debug'. This will enable logging to STDERR on the local and all remote Perl
 195 interpreters. By default STDERR for all remote interpreters is passed through
 196 unmodified so this is sufficient to receive logs generated anywhere Object::Remote
 197 is running.
 198
 199 Every time the local interpreter creates a new Object::Remote::Connection the connection
 200 is given an id that is unique to that connection on the local interpreter. The connection
 201 id and other metadata is available in the log output via a log format string that can
 202 be set via the OBJECT_REMOTE_LOG_FORMAT environment variable. The format string and
 203 available metadata is documented in L<Object::Remote::Logging::Logger>. Setting this
 204 environment variable on the local interpreter will cause it to be propagated to the
 205 remote interpreter so all logs will be formated the same way.
 206
 207 This class is designed so any module can create their own logging sub-class using it.
 208 With out any additional configuration the consumers of this logging class will
 209 automatically be enabled via OBJECT_REMOTE_LOG_LEVEL and formated with
 210 OBJECT_REMOTE_LOG_FORMAT but those additional log messages are not sent to STDERR.
 211 By setting the  OBJECT_REMOTE_LOG_SELECTIONS environment variable to a list of
 212 class names seperated by spaces then logs generated by packages that use those classes
 213 will be sent to STDERR. If the asterisk character (*) is used in the place of a class
 214 name then all class names will be selected by default instead of ignored. An individual
 215 class name can be turned off by prefixing the name with a hypen character (-). This is
 216 also a configuration item that is forwarded to the remote interpreters so all logging
 217 is consistent.
 218
 219 Regardless of OBJECT_REMOTE_LOG_LEVEL the logging system is still active and loggers
 220 can access the stream of log messages to format and output them. Internally
 221 OBJECT_REMOTE_LOG_LEVEL causes an L<Object::Remote::Logging::Logger> to be built
 222 and connected to the L<Object::Remote::Logging::Router> instance. It is also possible
 223 to manually build a logger instance and connect it to the router. See the documentation
 224 for the logger and router classes.
 225
 226 The logging system also supports a method of forwarding log messages from remote
 227 interpreters to the local interpreter. Forwarded log messages are generated in the
 228 remote interpreter and the logger for the message is invoked in the local interpreter.
 229 Sub-classes of Object::Remote::Logging will have log messages forwarded automatically.
 230 Loggers receive forwarded log messages exactly the same way as non-forwarded messages
 231 except a forwarded message includes extra metadata about the remote interpreter. Log
 232 forwarding is not currently enabled by default; to enable it set the
 233 OBJECT_REMOTE_LOG_FORWARDING environment variable to 1. See L<Object::Remote::Logging::Router>.
 234
 235 =head1 EXPORTABLE SUBROUTINES
 236
 237 =over 4
 238
 239 =item arg_levels
 240
 241 Returns an array reference that contains the ordered list of level names
 242 with the lowest log level first and the highest log level last.
 243
 244 =item router
 245
 246 Returns the instance of L<Object::Remote::Logging::Router> that is in use. The router
 247 instance is used in combination with L<Object::Remote::Logging::Logger> objects to
 248 select then render and output log messages.
 249
 250 =item log_<level> and Dlog_<level>
 251
 252 These methods come direct from L<Log::Contextual>; see that documentation for a
 253 complete reference. For each of the log level names there are subroutines with the log_
 254 and Dlog_ prefix that will generate the log message. The first argument is a code block
 255 that returns the log message contents and the optional further arguments are both passed
 256 to the block as the argument list and returned from the log method as a list.
 257
 258   log_trace { "A fine log message $_[0] " } 'if I do say so myself';
 259   %hash = Dlog_trace { "Very handy: $_" } ( foo => 'bar' );
 260
 261 =item logS_<level> and DlogS_<level>
 262
 263 Works just like log_ and Dlog_ except returns only the first argument as a scalar value.
 264
 265   my $beverage = log_info { "Customer ordered $_[0]" } 'Coffee';
 266
 267 =item Elog_<level>
 268
 269 Log an event and then generate an exception by calling die() with the log message.
 270
 271   Elog_error { "Could not open file: $!" };
 272
 273 =item Flog_<level>
 274
 275 Log the event, generate a warning with the log message, then call exit(). The exit
 276 value will default to 1 or can be specified as an argument.
 277
 278   Flog_fatal { 'Could not lock resource' } 3;
 279
 280 =back
 281
 282 =head1 LEVEL NAMES
 283
 284 Object::Remote uses an ordered list of log level names with the lowest level
 285 first and the highest level last. The list of level names can be accessed via
 286 the arg_levels method which is exportable to the consumer of this class. The log
 287 level names are:
 288
 289 =over 4
 290
 291 =item trace
 292
 293 As much information about operation as possible including multiple line dumps of
 294 large content. Tripple verbose operation (-v -v -v).
 295
 296 =item debug
 297
 298 Messages about operations that could hang as well as internal state changes,
 299 results from method invocations, and information useful when looking for faults.
 300 Double verbose operation (-v -v).
 301
 302 =item verbose
 303
 304 Additional optional messages to the user that can be enabled at their will. Single
 305 verbose operation (-v).
 306
 307 =item info
 308
 309 Messages from normal operation that are intended to be displayed to the end
 310 user if quiet operation is not indicated and more verbose operation is not
 311 in effect.
 312
 313 =item warn
 314
 315 Something wasn't supposed to happen but did. Operation was not impacted but
 316 otherwise the event is noteworthy. Single quiet operation (-q).
 317
 318 =item error
 319
 320 Something went wrong. Operation of the system may continue but some operation
 321 has most definitely failed. Double quiet operation (-q -q).
 322
 323 =item fatal
 324
 325 Something went wrong and recovery is not possible. The system should stop operating
 326 as soon as possible. Tripple quiet operation (-q -q -q).
 327
 328 =back