tags:

views:

126

answers:

3

I have a set of logging and debugging functions which I want to use across multiple modules / objects. I'd like to be able to turn them on / off globally using a command line switch.

The following code does this, however, I would like to be able to omit the package name and keep everything in a single file.

More specifically, I would like to import the logging functions names into each module so that they can be called without any package name qualification ( similar to a C++ use namespace; directive ) and I want to be able to enable / disable them globally from the script which uses them as in my example code below.

This is related to two previous questions I asked, here and here.

One other thing - I don't think I completely understand why the below code works.

#! /usr/bin/perl -w

use strict;
use Getopt::Long;

{
    package LogFuncs;

    use threads;
    use Time::HiRes qw( gettimeofday );

    # provide tcpdump style time stamp
    sub _gf_time {
        my ( $seconds, $microseconds ) = gettimeofday();
        my @time = localtime($seconds);

        return sprintf( "%02d:%02d:%02d.%06ld",
            $time[2], $time[1], $time[0], $microseconds );
    }

    sub logerr;

    sub compile {
        my %params = @_;

        *logerr = $params{do_logging}
            ? sub {
                my $msg = shift;
                warn _gf_time() . " Thread " . threads->tid() . ": $msg\n";
            }
            : sub { };
    }            
}

{
    package FooObj;

    sub new {
        my $class = shift;
        bless {}, $class; 
    };

    sub foo_work { 
        my $self = shift;
        # do some foo work
        LogFuncs::logerr($self);
    }
}

{
    package BarObj;

    sub new {
        my $class = shift;
        my $data  = { fooObj => FooObj->new() };
        bless $data, $class;
    }

    sub bar_work { 
        my $self = shift;
        $self->{fooObj}->foo_work();
        LogFuncs::logerr($self);
    }
}        

my $do_logging = 0;

GetOptions(
    "do_logging"    => \$do_logging,
);

LogFuncs::compile(do_logging => $do_logging);

my $bar = BarObj->new();
LogFuncs::logerr("Created $bar");
$bar->bar_work();
+5  A: 

If you want to keep everything in the same file, why not put the logger at the top in a file scoped lexical.

GetOptions( do_logging => \$do_logging );

my $logerr = $do_logging ? sub {logging_code_here()} : sub {};

$logerr is now available in any package defined after that point in the same file.

However, it is generally faster to structure your logging calls as follows:

my $logerr = sub { logging_code_here() };

$logerr->("some string $some_var") if $do_logging;

that way you avoid a subroutine call and the string argument to $logerr does not need to be calculated if logging is off.

You can also setup logging levels:

$logerr->("starting loop")     if $do_logging;

for (@big_array) {
    $logerr->("processing $_") if $do_logging > 1;
    ...
}

EDIT: While I don't think its the best practice, based on your comments, here is what you are probably looking for (a pragma):

use 5.010;
use warnings;
use strict;
BEGIN {  # compile time
    $INC{'log.pm'}++;  # block 'require log;'
    package log;
    sub is_active {(caller 1)[10]{log}}  # test the hints hash
    sub import {
        $^H{log} = 1;  # set the hints hash for 'log'
        my $logmsg = (caller).'::logmsg';  # name of caller's sub
        no strict 'refs';
        *$logmsg = sub {print "logging: @_\n" if is_active}  # install sub
            unless *{$logmsg}{CODE}; # unless we did already
    }
    sub unimport {
        $^H{log} = 0;  # unset the hints hash
    }
}

package MyPkg;

use log;
logmsg 'hello, world!';

{
  no log;
  logmsg 'nope, not here';
}

logmsg 'back again';
Eric Strom
@Eric Strom: But then wouldn't I need to reference package main to pull them into my object packages? As in `main::$logerr->("processing $_") if $do_logging > 1;`. The whole point is I'm trying to be concise and reduce the amount of typing and clutter in the code. For different logging / debug levels I simply have different functions, i.e. `loginfo1`, `loginfo2`, etc.. I would think that Perl is smart enough to optimize away a call to an empty function when logging is turned off. Thanks, but I don't think your solution meets my requirements.
Robert S. Barnes
@Robert S. Barnes => No, that is not the way `my` variables are scoped. Lexicals are not members of a package, but of a scope level, so if a lexical variable is defined at the root scope of a file, it will be visible in every package/block below it in the same file. Additionally, I don't think perl will optimize away the sub call, and calculating the message text before the sub call can be slow (for example if the logging code is in a tight inner loop). by moving the check outside the sub and into the calling code, you could prevent a great deal of unnecessary computation at debug level 0.
Eric Strom
@Eric Strom: Thanks for the clarification on visibility. However, when I tried putting the log function at global scope in main it wasn't visible in the packages below it. Are you saying a `my` variable would be visible while one without the my declaration wouldn't? Regarding performance of one vs. the other the only real way to know is testing it.
Robert S. Barnes
yes, only `my` variables are not package scoped.
Eric Strom
@Eric Strom: Wow, that is some fugly scary looking code. It might be what I'm looking for, although I tried running it and it gets a syntax error on line 6. I don't suppose you could explain what's going on in the code, and why you consider it to be bad practice?
Robert S. Barnes
@Eric Strom: I tested the speed of the two approaches by looping around the `$bar->bar_work()` call 10 million times and found that with logging turned off the "compile" approach took 26.9 user seconds and your `$logerr->("processing $_") if $do_logging` approach took 20.07 user seconds.
Robert S. Barnes
@Robert S. Barnes => could you post the error you are getting?
Eric Strom
@Robert S. Barnes => the hints hash portion of caller was added in v5.10, it doesn't look like there was a way to do this without XS before then.
Eric Strom
@Eric Strom: `syntax error at debug_module2.pl line 6, near "]{log"` I'm using Perl 5.8.8
Robert S. Barnes
@Robert S. Barnes => yep, lexically scoped user pragmas were added in 5.10, you could simulate the effect in 5.8.8 with `local`, but it would be a bit more verbose than `use log;`
Eric Strom
+3  A: 

If you need to patch some logging methods (or do something else conditionally in a developer environment vs. production), you can put the code into the import() method of a package and use an argument in the use line to enable/disable it:

# this is in MyLogger.pm:
package MyLogger;

use strict; use warnings;
use Exporter;

our @EXPORT_OK = qw(logerr);

sub import
{
     my ($class, $debug) = @_;

     if ($debug)
     {
          # do whatever you need here - patch methods, turn up the log level to "everything", etc

          # imports logerr method
          MyLogger->export_to_level(1, 'logger');
     }
}

sub logerr
{
    # your patched method here..
}

1;

# (now in your application code...)
use MyLogger "debug";    # enables debugging mode
# or:
use MyLogger MyConfig::DEBUG;    # uses a debugging constant that you defined elsewhere
Ether
@Ether: This sounds promising. Would this allow me to turn logging on / off globally in the script which uses the various modules? How would this work if all the modules are defined in a single file? Could you give a more full example based on the code I provided in the post?
Robert S. Barnes
I have to say, this is much better than Eric Strom's idea.
Kinopiko
@Kinopiko: I'm just not completely sure how it works.
Robert S. Barnes
@Robert: I'm not quite sure what your code example is trying to do without more context, but you can import functions into your namespace using the `Exporter` package on CPAN -- I'll update my code to show an example.
Ether
@Kinopiko => care to explain why?
Eric Strom
I have used something like this in a project quite successfully. It works beautifully.
daotoad
+1  A: 

Below you will your code without an explicit package for the logging functions. I've renamed LogFuncs::compile to logerr:setup to be a bit more explicit and not pollute the main namespace. Everything in perl has a package, it's just main by default. I think the code you have before, with a package for the logging functions was actually cleaner, and lends itself to being split into a separate module easily, so it can be reused easier.

As for not understanding how the code works, I'm not sure how to address that, but only because you didn't identify any specifics of what you didn't understand. I'll assume you meant the packages. Perl packages can be viewed as namespaces, or classes. In the case of the LogFuncs package, you are using it as a namespace, and subs created in it are accessed as static class methods (to use some notation from other more traditional OO languages that may shine light on this). Package FooObj and BarObj are used more traditionally as objects by providing a constructor new(), and expecting subs within them to be called using object notation (->sub), automatically passing the object itself as the first parameter to the sub/method. The only thing defining a sub as a static class method or a object method is whether it expects to receive the object as the first parameter. As such, a little forethought and careful programming can produce subs that work for both, by correctly determining what the first passed parameter is and acting accordingly.

#! /usr/bin/perl -w

use strict;
use Getopt::Long;

use threads;
use Time::HiRes qw( gettimeofday );

# provide tcpdump style time stamp
sub _gf_time {
my ( $seconds, $microseconds ) = gettimeofday();
my @time = localtime($seconds);

return sprintf( "%02d:%02d:%02d.%06ld",
    $time[2], $time[1], $time[0], $microseconds );
}

sub logerr;

sub logerr_setup {
    my %params = @_;

    *logerr = $params{do_logging}
        ? sub {
            my $msg = shift;
            warn _gf_time() . " Thread " . threads->tid() . ": $msg\n";
        }
        : sub { };
    }

{
    package FooObj;

    sub new {
        my $class = shift;
        bless {}, $class;
    };

    sub foo_work {
        my $self = shift;
        # do some foo work
        main::logerr($self);
    }
}

{
    package BarObj;

    sub new {
        my $class = shift;
        my $data  = { fooObj => FooObj->new() };
        bless $data, $class;
    }

    sub bar_work {
        my $self = shift;
        $self->{fooObj}->foo_work();
        main::logerr($self);
    }
}

my $do_logging = 0;

GetOptions(
    "do_logging"    => \$do_logging,
);

logerr_setup(do_logging => $do_logging);

my $bar = BarObj->new();
logerr("Created $bar");
$bar->bar_work();
kbenson
@kbenson: +1 for the explanation. Effectively, what I want is the equivalent of a C++ `use namespace;` directive. I'd like to keep the logging functions in their own package, be able to reference them directly without **any** package name and turn them on / off globally from the main script. Right now I've got two out of three.
Robert S. Barnes
@Robert S. Barnes: look at the perldoc for Exporter, I think that's what you want. It allows you to define keywords that export part or all of your package namespace, or have some portions exported automatically. This is what's being used when you see a use syntax like use Time::HiRes 'time' to override the time() built-in to return hi resolution timing. It's exporting a new time() sub defined within the Time::HiRes namespace into main.
kbenson