pileofrogs has asked for the wisdom of the Perl Monks concerning the following question:

Ok, this might be wierd or stupid.

I wrote a simple verbosity output handling sub that checks a global verbosity level and outputs to stdout. After profiling my script I realised that a huge amount of time was spent calling this function (I used it a lot) even when it wouldn't do anything because the global verbosity was so low.

So, I thought, OK I'll just use m4 and put a macro in my code so I can put syntax similer to how I called my sub into the perl code and run it through the m4 processor to get perl with the verbosity output logic written out every time. Now, there is no subroutine overhead...

However! I'm now writing in two languages, perl and m4. The way I have it set up, it looks deceptively like perl, but it isn't. The m4 interpreter does things I don't expect from time to time, so I'm looking for alternatives.

So! My questions for ye monks are:

Is there a way in perl to replace a call to a subroutine with inline code?

Is doing this actually improving my performance?

Does anyone have a better idea?

Details and examples below...

My script has the global $verbosity which is set by command line args.

Here's the subrutine version:

sub v_print { my $volume = shift; my $message = shift; if ( $volume >= $verbosity ) { print $message; } }

Called like this

v_print(1,"Holy Crap = $holy_crap\n");

Call that a zillion times in a performance sensitive script and it eats up a lot of resources.

So, I wrote this little bit of m4:

define(`v_print',`print $2 if $verbose >= $1')dnl

..and commented out the subrutine definition for v_print. Now, after running m4,

 v_print(1,"Holy Crap = $holy_crap\n");

...looks like...

print "Holy Crap = $holy_crap\n" if $verbose >= 1;

Only one of the many problems is that,

v_print(1,"Foo = $foo, Bar = $bar, Baz = $baz");

Turns into:

print "Foo = $foo if $verbose >= 1;

Thanks to how m4 handles quotes differently from perl...

Yes, that doesn't look like much of a savings in charcters typed, but this is a somewhat simplified example. The original also handled some logging and a few other features, so v_print(1,"Holy Crap = $holy_crap\n") is actually a lot shorter than the code produced by m4.

Update

It looks like Filter::cpp is the winner. The only way it could be better would be if the C preprocessor macros didn't use the same character as perl comments...

Replies are listed 'Best First'.
Re: Macro in perl code?
by shmem (Chancellor) on Oct 16, 2007 at 18:43 UTC
    Use a subroutine with an empty prototype which return a constant (that's what the constant module does):
    perl -MO=Deparse,-x,-p -e 'sub verbose() { 0 } print "guggug!\n" if ve +rbose;' sub verbose () { 0 } '???'; -e syntax OK
    perl -MO=Deparse,-x,-p -e 'sub verbose() { 0 } if(verbose){ print "gug +gug!\n"};' sub verbose () { 0 } '???'; -e syntax OK

    The '???'; statements stand for bits of code that have been optimized away; those will have no impact on performance. If the compiler sees such a constant returning sub it can perform optimizations, eliminating code blocks whose execution is bound to the value of that constant.

    Besides, before shoehorning a perl script through m4, I'd rather look - though discouraged - at perl's -P switch. See perlrun.

    --shmem

    _($_=" "x(1<<5)."?\n".q·/)Oo.  G°\        /
                                  /\_¯/(q    /
    ----------------------------  \__(m.====·.(_("always off the crowd"))."·
    ");sub _{s./.($e="'Itrs `mnsgdq Gdbj O`qkdq")=~y/"-y/#-z/;$e.e && print}

      Sorry, I don't get it at all. Could you point me to some docs that explain this? I think I need to get more background..

        Constant functions (with the empty prototype) are discussed in perlsub.
        Constant Functions Functions with a prototype of "()" are potential candidates for inlining. If the result after optimization and constant folding is either a constant or a lexically-scoped scalar which has no other references, then it will be used in place of function calls made without "&". Calls made using "&" are never inlined. (See con- stant.pm for an easy way to declare most constants.)

        See e.g. The Optimizer and Preprocessor Pranks for more details.

        --shmem

        _($_=" "x(1<<5)."?\n".q·/)Oo.  G°\        /
                                      /\_¯/(q    /
        ----------------------------  \__(m.====·.(_("always off the crowd"))."·
        ");sub _{s./.($e="'Itrs `mnsgdq Gdbj O`qkdq")=~y/"-y/#-z/;$e.e && print}
Re: Macro in perl code?
by moritz (Cardinal) on Oct 16, 2007 at 18:06 UTC
    I don't have an answer to your question, just a remark.

    sub v_print { my $volume = shift; my $message = shift;
    modifies @_ although it doesn't have to. Changing that to my ($volume, $message) = @_; should speed it up a little bit.
      I don't know if there is any real value in benchmarking this because it may change from different vesion of Perl but the results would indicate that using shift is faster.
      #!/usr/bin/env perl use strict; use warnings; use Benchmark qw/ cmpthese /; cmpthese(10000000, { shift => sub { my $volume = shift; my $message = shift; }, inline => sub { my ($volume, $message) = @_ } } );
      And the output is -
      bruce:0:~/tmp $ ./p.pl Rate inline shift inline 3300330/s -- -29% shift 4629630/s 40% --
        Adding some overhead in the subroutine being called, the difference (if any) between the two approaches disappears altogether:
        $ cat 645237.pl use strict; use warnings; use Benchmark qw/ cmpthese /; use List::Util qw/ sum /; sub foo { my ($volume, $message) = @_; my @foo = ($volume .. $message); @foo = map { $_ ** 2 } @foo; return sum(@foo); } sub bar { my $volume = shift; my $message = shift; my @foo = ($volume .. $message); @foo = map { $_ ** 2 } @foo; return sum(@foo); } cmpthese(100_000, { shift => sub { foo(1, 100) }, inline => sub { bar(1, 100) }, } ); $ perl 645237.pl Rate inline shift inline 8396/s -- -0% shift 8403/s 0% --
        If your Benchmark shows your computer is able to perform an operation 3 million times pr. second, that's equivalent of a 1000 m2 highway sign saying: Don't optimize!

        Update: Changed code to supply arguments to functions as pointed out by bruceb3.

        --
        Andreas

      Actually, for some time I have used the following convention in object-oriented modules:

      sub func { my $self = shift; my ($param1, $param2, ..., $paramn) = @_; # ... }

      Motivation: you "slurp" the calling object, after which it is clearer which are actually parameters to the method.

      (Sorry for OT.)

      Update: changed "my func" to "sub func". Silly me.

      --
      print "Just Another Perl Adept\n";

Re: Macro in perl code?
by andreas1234567 (Vicar) on Oct 16, 2007 at 18:45 UTC
    I find this interesting. There's a related discussion in the Log::Log4perl documentation under section Penalties. The essence is that interpolation (of long arrays) and subroutine calls are relatively expensive in perl, while a simple if ($variable) { .. } is relatively cheap. You may consider not calling your logging subroutine at all unless logging is enabled:
    v_print ($message) if ( $volume >= $verbosity );

    Furthermore, a Benchmark of the code in question with and without debugging enabled would be interesting to see.

    --
    Andreas
      Here is a benchmark attempt for a few variations:
      #!/usr/bin/perl use strict; use warnings; use Benchmark; our $verbosity = 7; our $volume = 1; our $holy_crap = "Hmmmm.. here's the problem!"; timethese(10000000, { 'Name1' => ' v_print0( 1, "Holy Crap = holy_crap\n"); ', 'Name2' => ' v_print0( 1, "Holy Crap = $holy_crap\n"); ', 'Name3' => ' v_print1( 1, sub { "Holy Crap = holy_crap\n" } ); ' +, 'Name4' => ' v_print1( 1, sub { "Holy Crap = $holy_crap\n" } ); ' +, 'Name5' => ' v_print2( 1, \'"Holy Crap = holy_crap\n"\' ); ', 'Name6' => ' v_print2( 1, \'"Holy Crap = $holy_crap\n"\' ); ', 'Name7' => ' if ( $volume >= $verbosity ) { v_print3( "Holy Crap + $holy_crap\n" ) }; ', });
      And here the results:
      Benchmark: timing 10000000 iterations of Name1, Name2, Name3, Name4, N +ame5, Name6, Name7... Name1: 12 wallclock secs (11.24 usr + 0.01 sys = 11.25 CPU) @ 88 +8888.89/s (n=10000000) Name2: 16 wallclock secs (16.08 usr + 0.00 sys = 16.08 CPU) @ 62 +1890.55/s (n=10000000) Name3: 14 wallclock secs (13.93 usr + -0.01 sys = 13.92 CPU) @ 71 +8390.80/s (n=10000000) Name4: 13 wallclock secs (14.10 usr + 0.00 sys = 14.10 CPU) @ 70 +9219.86/s (n=10000000) Name5: 11 wallclock secs (11.26 usr + 0.00 sys = 11.26 CPU) @ 88 +8099.47/s (n=10000000) Name6: 12 wallclock secs (11.00 usr + 0.01 sys = 11.01 CPU) @ 90 +8265.21/s (n=10000000) Name7: 1 wallclock secs ( 1.24 usr + 0.00 sys = 1.24 CPU) @ 80 +64516.13/s (n=10000000)
      Conclusions seem to be, as you mentioned:
    • avoid calling subs in the first place, if possible
    • postpone string interpolation to happen only in the called sub, not before the call

    • The initial surprise diminished a bit after thinking about the benchmarks - but it's good to know it anyway;)
        One can improve performance even further by using constant.
        $ cat 645310.pl use strict; use warnings; use Benchmark qw/ cmpthese /; our $verbosity = 7; our $volume = 1; use constant VERBOSE => 0; cmpthese( -1, { 'Name7' => ' if ( $volume >= $verbosity ) { v_print3( "foo" ) }; ' +, 'Name8' => ' if ( VERBOSE ) { v_print3( "foo" ) }; ' +, } ); sub v_print3 { my $message = shift; print $message; } __END__ $ perl 645310.pl Rate Name7 Name8 Name7 9442579/s -- -74% Name8 35826879/s 279% --
        The whole subroutine call gets optimized away:
        $ perl -MO=Deparse,-x,-p -e 'use constant VERBOSE => 0; if ( VERBOSE ) + { v_print3( "foo" ) }; ' use constant ('VERBOSE', 0); '???'; -e syntax OK
        --
        Andreas
Re: Macro in perl code?
by perrin (Chancellor) on Oct 16, 2007 at 19:40 UTC
    Try searching for "pre-processor" to read some earlier discussions about this.
Re: Macro in perl code?
by djp (Hermit) on Oct 18, 2007 at 05:46 UTC
    For a different approach I suggest you consider Smart-Comments, which uses a source filter but does all the work for you. You don't even have to modify your code, you can turn smart comments on and even control the verbosity level at runtime via e.g.
    perl -MSmart::Comments myscript.pl perl -MSmart::Comments="####" myscript.pl
    See the documentation and Re^2: debug statements for details.
Re: Macro in perl code?
by bruceb3 (Pilgrim) on Oct 16, 2007 at 18:52 UTC
    You can have a look at the -P option to Perl to have your source run through the C preprocessor but the bundled documentation recommends that you don't. Or, you could have a go at using a source filter (perldoc perlfilter). Both options seem to have some gotchas.
Re: Macro in perl code?
by oha (Friar) on Oct 17, 2007 at 09:38 UTC
    None suggested to take care that print(ARGS) if COND has a side-effect: if COND is false ARGS will not be evaluated.

    This can make things faster, but see:

    sub verb { 1 } my $x = 1; print "debug ".$x++."\n" if verb;
    in this case, like in many others, by evaluating or not the args of print, means the value of $x is or isn't changed.

    Oha

Re: Macro in perl code?
by Limbic~Region (Chancellor) on Oct 17, 2007 at 15:04 UTC
Re: Macro in perl code?
by gamache (Friar) on Oct 17, 2007 at 15:46 UTC
    If you don't have any plans for a couple of years, you could wait around for Perl 6 with compile-time macros. I tend to want them more for clarity than performance purposes, but that's just me. You won't find me standing in the way of any Lisp feature making its way into Perl.