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