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 %controller_should_log;
  74
  75   unless (defined $ENV{OBJECT_REMOTE_LOG_FORWARDING} && $ENV{OBJECT_REMOTE_LOG_FORWARDING} ne '') {
  76     $ENV{OBJECT_REMOTE_LOG_FORWARDING} = 1;
  77   }
  78
  79   return unless defined $level && $level ne '';
  80   $format = "[%l %r] %s" unless defined $format;
  81   $selections = __PACKAGE__ unless defined $selections;
  82   %controller_should_log = _parse_selections($selections);
  83
  84   {
  85     no warnings 'once';
  86     if (defined $Object::Remote::FatNode::REMOTE_NODE) {
  87       #the connection id for the remote node comes in later
  88       #as the controlling node inits remote logging
  89       router()->_remote_metadata({ connection_id =>  undef });
  90     }
  91   }
  92
  93   my $logger = Object::Remote::Logging::Logger->new(
  94     min_level => lc($level), format => $format,
  95     level_names => Object::Remote::Logging::arg_levels(),
  96   );
  97
  98   router()->connect(sub {
  99     my $controller = $_[1]->{controller};
 100     my $will_log = $controller_should_log{$controller};
 101
 102     $will_log = $controller_should_log{'*'} unless defined $will_log;
 103
 104     return unless $will_log;
 105     #skip things from remote hosts because they log to STDERR
 106     #when OBJECT_REMOTE_LOG_LEVEL is in effect
 107     return if $_[1]->{remote}->{connection_id};
 108     $logger
 109   });
 110 }
 111
 112 #this is invoked by the controlling node
 113 #on the remote nodes
 114 sub init_remote_logging {
 115   my ($self, %controller_info) = @_;
 116
 117   router()->_remote_metadata(\%controller_info);
 118   #TODO having an instance of an object in the remote interpreter causes it to hang
 119   #on exit intermitently or leave a zombie laying around frequently - not a bug limited
 120   #to log forwarding
 121   router()->_forward_destination($controller_info{router}) if $ENV{OBJECT_REMOTE_LOG_FORWARDING};
 122 }
 123
 124 1;
 125
 126 __END__
 127
 128 =head1 NAME
 129
 130 Object::Remote::Logging - Logging subsystem for Object::Remote
 131
 132 =head1 SYNOPSIS
 133
 134   use Object::Remote::Logging qw( :log :dlog arg_levels router );
 135
 136   @levels = qw( trace debug verbose info warn error fatal );
 137   @levels = arg_levels(); #same result
 138
 139   $ENV{OBJECT_REMOTE_LOG_LEVEL} = 'trace'; #or other level name
 140   $ENV{OBJECT_REMOTE_LOG_FORMAT} = '%l %t: %p::%m %s'; #and more
 141   $ENV{OBJECT_REMOTE_LOG_SELECTIONS} = 'Object::Remote::Logging Some::Other::Subclass';
 142   $ENV{OBJECT_REMOTE_LOG_SELECTIONS} = '* -Object::Remote::Logging';
 143   $ENV{OBJECT_REMOTE_LOG_FORWARDING} = 0; #default 1
 144
 145   log_info { 'Trace log event' };
 146   Dlog_verbose { "Debug event with Data::Dumper::Concise: $_" } { foo => 'bar' };
 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. If the asterisk character (*) is used in the place of a class
 184 name then all class names will be selected by default instead of ignored. An individual
 185 class name can be turned off by prefixing the name with a hypen character (-). This is
 186 also a configuration item that is forwarded to the remote interpreters so all logging
 187 is consistent.
 188
 189 Regardless of OBJECT_REMOTE_LOG_LEVEL the logging system is still active and loggers
 190 can access the stream of log messages to format and output them. Internally
 191 OBJECT_REMOTE_LOG_LEVEL causes an L<Object::Remote::Logging::Logger> to be built
 192 and connected to the L<Object::Remote::Logging::Router> instance. It is also possible
 193 to manually build a logger instance and connect it to the router. See the documentation
 194 for the logger and router classes.
 195
 196 The logging system also supports a method of forwarding log messages from remote
 197 interpreters to the local interpreter. Forwarded log messages are generated in the
 198 remote interpreter and the logger for the message is invoked in the local interpreter.
 199 Sub-classes of Object::Remote::Logging will have log messages forwarded automatically.
 200 Loggers receive forwarded log messages exactly the same way as non-forwarded messages
 201 except a forwarded message includes extra metadata about the remote interpreter. Log
 202 forwarding is enabled by default but comes with a performance hit; to disable it set the
 203 OBJECT_REMOTE_LOG_FORWARDING environment variable to 0. See L<Object::Remote::Logging::Router>.
 204
 205 =head1 EXPORTABLE SUBROUTINES
 206
 207 =over 4
 208
 209 =item arg_levels
 210
 211 Returns an array reference that contains the ordered list of level names
 212 with the lowest log level first and the highest log level last.
 213
 214 =item router
 215
 216 Returns the instance of L<Object::Remote::Logging::Router> that is in use. The router
 217 instance is used in combination with L<Object::Remote::Logging::Logger> objects to
 218 select then render and output log messages.
 219
 220 =item log_<level> and Dlog_<level>
 221
 222 These methods come direct from L<Log::Contextual>; see that documentation for a
 223 complete reference. For each of the log level names there are subroutines with the log_
 224 and Dlog_ prefix that will generate the log message. The first argument is a code block
 225 that returns the log message contents and the optional further arguments are both passed
 226 to the block as the argument list and returned from the log method as a list.
 227
 228   log_trace { "A fine log message $_[0] " } 'if I do say so myself';
 229   %hash = Dlog_trace { "Very handy: $_" } ( foo => 'bar' );
 230
 231 =item logS_<level> and DlogS_<level>
 232
 233 Works just like log_ and Dlog_ except returns only the first argument as a scalar value.
 234
 235   my $beverage = logS_info { "Customer ordered $_[0]" } 'Coffee';
 236
 237 =back
 238
 239 =head1 LEVEL NAMES
 240
 241 Object::Remote uses an ordered list of log level names with the lowest level
 242 first and the highest level last. The list of level names can be accessed via
 243 the arg_levels method which is exportable to the consumer of this class. The log
 244 level names are:
 245
 246 =over 4
 247
 248 =item trace
 249
 250 As much information about operation as possible including multiple line dumps of
 251 large content. Tripple verbose operation (-v -v -v).
 252
 253 =item debug
 254
 255 Messages about operations that could hang as well as internal state changes,
 256 results from method invocations, and information useful when looking for faults.
 257 Double verbose operation (-v -v).
 258
 259 =item verbose
 260
 261 Additional optional messages to the user that can be enabled at their will. Single
 262 verbose operation (-v).
 263
 264 =item info
 265
 266 Messages from normal operation that are intended to be displayed to the end
 267 user if quiet operation is not indicated and more verbose operation is not
 268 in effect.
 269
 270 =item warn
 271
 272 Something wasn't supposed to happen but did. Operation was not impacted but
 273 otherwise the event is noteworthy. Single quiet operation (-q).
 274
 275 =item error
 276
 277 Something went wrong. Operation of the system may continue but some operation
 278 has most definitely failed. Double quiet operation (-q -q).
 279
 280 =item fatal
 281
 282 Something went wrong and recovery is not possible. The system should stop operating
 283 as soon as possible. Tripple quiet operation (-q -q -q).
 284
 285 =back