Lightning Strikes Four Times
by Shlomi Fish, Bob Free, Mike Friedman, brian d foyApril 12, 2007
Good software design principles tell us that we should work to separate unrelated concerns. For example, the popular Model-View-Controller (MVC) pattern is common in web application designs. In MVC, separate modular components form a model, which provides access to a data source, a view, which presents the data to the end user, and a controller, which implements the required features.
Ideally, it's possible to replace any one of these components without breaking the whole system. A templating engine that translates the application's data into HTML (the view) could be replaced with one that generates YAML or a PDF file. The model and controller shouldn't be affected by changing the way that the view presents data to the user.
Other concerns are difficult to separate. In the world of aspect-oriented programming, a crosscutting concern is a facet of a program which is difficult to modularize because it must interact with many disparate pieces of your system.
Consider an application that logs copious trace data when in debugging mode. In order to ensure that it is operating correctly, you may want to log when it enters and exits each subroutine. A typical way to accomplish this is by conditionally executing a logging function based on the value of a constant, which turns debugging on and off.
use strict;
use warnings;
use constant DEBUG => 1;
sub do_something {
log_message("I'm doing something") if DEBUG;
# do something here
log_message("I'm done doing something") if DEBUG;
}
This solution is simple, but it presents a few problems. Perhaps most strikingly, it's simply a lot of code to write. For each subroutine that you want to log, you must write two nearly identical lines of code. In a large system with hundreds or thousands of subroutines, this gets tedious fast, and can lead to inconsistently formatted messages as every copy-paste-edit cycle tweaks them a little bit.
Further, it offends the simple design goal of an MVC framework, because every component must talk to the logging system directly.
One way to improve this technique is to automatically wrap every interesting subroutine in a special logging function. There are a few ways to go about this. One of the simplest is to use subroutine attributes to install a dynamically generated wrapper.
Attributes
Perl 5.6 introduced attributes that allow you to add arbitrary metadata to a variable. Attributes can be attached both to package variables, including subroutines, and lexical variables. Since Perl 5.8, attributes on lexical variables apply at runtime. Attributes on package variables activate at compile-time.
The interface to Perl attributes is via the attributes pragma. (The older attrs is deprecated.) The CPAN module Attribute::Handlers makes working with attributes a bit easier. Here's an example of how you might rewrite the logging system using an attribute handler.
use strict;
use warnings;
use constant DEBUG => 1;
use Attribute::Handlers;
sub _log : ATTR(CODE) {
my ($pkg, $sym, $code) = @_;
if( DEBUG ) {
my $name = *{ $sym }{NAME};
no warnings 'redefine';
*{ $sym } = sub {
log_message("Entering sub $pkg\:\:$name");
my @ret = $code->( @_ );
log_message("Leaving sub $pkg\:\:$name");
return @ret;
};
}
}
sub do_something : _log {
print "I'm doing something.\n";
}
Attributes are declared by placing a colon (:) and the attribute name after a variable or subroutine declaration. Optionally, the attribute can receive some data as a parameter; Attribute::Handlers goes to great lengths to massage the passed data for you if necessary.
To set up an attribute handler, the code declares a subroutine, _log, with the ATTR attribute, passing the string CODE as a parameter. Attribute::Handlers provides ATTR, and the CODE parameter tells it that the new handler only applies to subroutines.
During compile time, any subroutine declared with the _log attribute causes Perl to call the attribute handler with several parameters. The first three are the package in which the subroutine was compiled, a reference to the typeglob where its symbol lives, and a reference to the subroutine itself. These are sufficient for now.
If the DEBUG constant is true, the handler sets to work wrapping the newly compiled subroutine. First, it grabs its name from the typeglob, then it adds a new subroutine to its spot in the symbol table. Because the code redefines a package symbol, it's important to turn off warnings for symbol redefinitions in within this block.
Because the new function is a lexical closure over $pkg, $name, and most importantly $code, it can use those values to construct the logging messages and call the original function.
All of this may seem like a lot of work, but once it's done, all you need to do to enable entry and exit logging for any function is to simply apply the _log attribute. The logging messages themselves get manufactured via closures when the program compiles, so we know they'll always be consistent. If you want to change them, you only have to do it in one place.
Best of all, because attribute handlers get inherited, if you define your handler in a base class, any subclass can use it.
Caveats
Although this is a powerful technique, it isn't perfect. The code will not properly wrap anonymous subroutines, and it won't necessarily propagate calling context to the wrapped functions. Further, using this technique will significantly increase the number of subroutine dispatches that your program must execute during runtime. Depending on your program's complexity, this may significantly increase the size of your call stack. If blinding speed is a major design goal, this strategy may not be for you.
Going Further
Other common cross-cutting concerns are authentication and authorization systems. Subroutine attributes can wrap functions in a security checker that will refuse to call the functions to callers without the proper credentials.

