Enchant closures for better debugging output

When you’re using code references heavily, you’re going to have a problem figuring out which one of them is having a problem. You define them in possibly several and far-flung parts of your program, but when it comes to using them, you don’t know which one you are using. You can’t really print its value like you would for a scalar, making it more difficult for you to debug things. You can dereference a scalar or an array to see what it is, but you can’t dereference a code reference without making it do something.

Consider this code, which defines a code reference along with other
references (also see Item 59. Compare reference types to prototypes). You can print the values in most reference types to see what they are, but you can’t do that directly with the code reference:

use v5.10;

my @array = ( \'xyz', [qw(a b c)], sub { say 'Buster' } );

foreach ( @array ) {
	say "$_";
	when( ref eq ref \ ''   ) { say "Scalar $$_" }
	when( ref eq ref []     ) { say "Array @$_" }
	when( ref eq ref sub {} ) { say "Sub ???" }
	}

When you dereference a value, nothing happens (aside from any tie magic). When you dereference a subroutine, you run its code with whatever arguments you give to it. If the subroutine needs arguments, which arguments would you use if you wanted to see what the subroutine would do?

There’s a clever way around this, first noted by Randal Schwartz in his Perlmonks post Track the filename/line number of an anonymous coderef. He proposed a new subroutine, main::Sub to use in place of the sub keyword.

BEGIN {
  package MagicalCoderef;

  use overload '""' => sub {
    require B;

    my $ref = shift;
    my $gv = B::svref_2object($ref)->GV;
    sprintf "%s:%d", $gv->FILE, $gv->LINE;
  };

  sub main::Sub (&) {
    return bless shift, __PACKAGE__;
  }
}

This technique actually made the code reference an object so he could overload stringification.

my $s = Sub { say +shift };
print "$s\n";

This stringified the code reference as the filename and line number where you created it:

/Users/Buster/Desktop/magic_coderef.pl:19

You can go farther than this, though, and make this a bit more useful. In response to Randal’s post, I suggested turning the idea inside-out. Instead of using Sub, I exposed the object creation. That way, you don’t have to worry about which package Sub might be in:

use v5.14;

package MagicalCodeRef 0.90 {
    use overload '""' => sub 
        {
        require B;

        my $ref = shift;
        my $gv = B::svref_2object($ref)->GV;
        sprintf "%s:%d", $gv->FILE, $gv->LINE;
        };

    sub enchant { bless $_[1], $_[0] }
    }

You can apply this magic to code references that you already have to get the same result (you could also do this with Sub, but it looks odd):

my $s = MagicalCodeRef->enchant( sub { say +shift } );
print "$s\n";

Still, that’s not good enough. You where where you created the subroutine, but that might not be enough information for you. You can use even more B magic. The B::Deparse module can decompile code to show you what perl thinks it is (we used this briefly in Item 7. Know which values are false and test them accordingly).

use v5.14;

package MagicalCodeRef 1.00 {
    use overload '""' => sub 
        {
        require B;
        
        my $ref = shift;
        my $gv = B::svref_2object($ref)->GV;

		require B::Deparse;
		my $deparse = B::Deparse->new;
		my $code = $deparse->coderef2text($ref);

        my $string = sprintf "---code ref---\n%s:%d\n%s\n---", 
        $gv->FILE, $gv->LINE, $code;
        
        };

    sub enchant { bless $_[1], $_[0] }
    }

With the same bit of code, you get additional output:

my $s = MagicalCodeRef->enchant( sub { say +shift } );
print "$s\n";

The output shows everything that perl thinks it needs to reproduce that behavior, including some pragma settings and compiler hints:

---code ref---
/Users/brian/Desktop/magic:25
{
    use strict 'refs';
    BEGIN {
        $^H{'feature_unicode'} = q(1);
        $^H{'feature_say'} = q(1);
        $^H{'feature_state'} = q(1);
        $^H{'feature_switch'} = q(1);
    }
    print shift();
}
---

The code doesn’t look the same as the code reference you initially created, but at least you have an idea what the code reference does.

If the code reference is a closure, you might also need to know which variables it closed over and what their values are. You can get these from the PadWalker module (which doesn’t come with Perl so you’ll need to get it from CPAN):

use v5.14;

package MagicalCodeRef 1.01 {
    use overload '""' => sub 
        {
        require B;
        
        my $ref = shift;
        my $gv = B::svref_2object($ref)->GV;

		require B::Deparse;
		my $deparse = B::Deparse->new;
		my $code = $deparse->coderef2text($ref);

        require PadWalker;
        my $hash = PadWalker::closed_over( $ref );
		
		require Data::Dumper;
		local $Data::Dumper::Terse = 1;
        my $string = sprintf "---code ref---\n%s:%d\n%s\n---\n%s---", 
        $gv->FILE, $gv->LINE, 
        $code,
        Data::Dumper::Dumper( $hash );
        
        };

    sub enchant { bless $_[1], $_[0] }
    }

Give this new version of MagicalCodeRef a closure:

 
my $sub = do {
	my( $x, $y ) = qw( Buster Mimi );

	sub { print "$x $y @_" }
	};

my $s = MagicalCodeRef->enchant( $sub );
say $s;

Now you see that which variables in the code reference refer to lexical variables that are out of scope instead of package or special variables. Only the lexical variables show up in the Dumper output:

---code ref---
/Users/brian/Desktop/magic:35
{
    use strict 'refs';
    BEGIN {
        $^H{'feature_unicode'} = q(1);
        $^H{'feature_say'} = q(1);
        $^H{'feature_state'} = q(1);
        $^H{'feature_switch'} = q(1);
    }
    print "$x $y @_";
}
---
{
  '$y' => \'Mimi',
  '$x' => \'Buster'
}
---

Things to remember

  • You can bless code references and overload their stringification to output what you like
  • The B module can tell you the filename and line number where you created the closure
  • The B::Deparse module can decompile a code reference
  • The PadWalker module can give you the closed-over
    lexical variables and their values.

2 thoughts on “Enchant closures for better debugging output”

  1. If you change the string construction to:

      sub dump_closure {
        my $f = shift;           # the closure
        my $conf = shift || ();  # hashref of output options
        my $indent = exists $conf->{indent} ? $conf->{indent} :  '    ';
        my @deparse_opts =
          exists $conf->{deparse_opts} ? @{$conf->{deparse_opts}} : ('-sC');
      
        require B;
        my $gv = B::svref_2object( $f )->GV;
        my $file_name = $gv->FILE;
        my $line_num  = $gv->LINE;
      
        require PadWalker;
        my ( $lexical_vars ) = PadWalker::closed_over( $f );
        my @lexical_vars = map {
          $indent . 'my '. $_. ' = '. ${$lexical_vars->{$_}}. ';'
        } sort keys %$lexical_vars;
      
        require B::Deparse;
        my $bd = B::Deparse->new( @deparse_opts );
        $bd->ambient_pragmas( strict => 'all', warnings => 'all' );
        my @body = split /\n/, $bd->coderef2text( $f );
        $body[0] = 'return sub ' . $body[0];
        @body = map { $indent . $_ } @body;
      
        return join "\n",
          '# ' . $file_name . ':' . $line_num,
          'sub {',
              @lexical_vars,
              @body,
          '}->()';
      }
      use overload '""' => \&dump_closure;
    

    You get a string that can be eval’d to create a cloned closure, similar to Data::Dump. The resulting strings are human readable for appropriate definitions of human readable.

  2. It looks like you can clone subroutines this way, but you don’t know what else closed over the same variables. I wouldn’t try this without extensive and very reliable knowledge about the original subroutine. That’s why I only use this for debugging.

Comments are closed.