use strict;
use warnings;

use DBI;
use Data::Dumper;
use Hook::WrapSub qw( wrap_subs unwrap_subs );

wrap_subs \&log_prepare, 'DBI::db::prepare';
wrap_subs \&log_execute, 'DBI::st::execute';

my $dbh = DBI->connect(
   qw(DBI:driver:database:host user pass),
   {RaiseError=>1}
);

my $sth = $dbh->prepare('select foo,bar from qux');

$sth->execute();
$sth->finish();
$dbh->disconnect;

unwrap_subs qw(DBI::db::prepare DBI::st::execute);

# just announce we were called and dump our args
sub log_prepare {
   print "prepare called:\n", Dumper \@_;
}
sub log_execute {
   print "execute called:\n", Dumper \@_;
}
[download]

jeffa

L-LL-L--L-LL-L--L-LL-L--
-R--R-RR-R--R-RR-R--R-RR
B--B--B--B--B--B--B--B--
H---H---H---H---H---H---
(the triplet paradiddle with high-hat)

Jeffa, thank you. This is exactly what I needed.

I am planning to use this to create a log that identifies where database queries are being prepared/executed after having used DBI::ProfileDumper to profile the queries in a mod_perl application.

update: whoops, read the note way too quickly. Thought you wanted a trace of what's going on in the prepare calls; the advice stands for that usage, but not for the poster's question!

Check out the DBI's trace method, which is simple to set up:

my $db = DBI->connect(#blah blah blah");
# trace level (1-9), and output (STDERR if not specified)
$db->trace(2, '/tmp/trace.log');
[download]

I find level 2 to be of general use while debugging harder problems, 3 when 2 doesn't reveal enough, but I've never needed to go any higher. As the docs used to say, 6 really is too high to be useful, but I suppose it's there for a reason =)

If not P, what? Q maybe?
"Sidney Morgenbesser"

Assuming that you control the code that's doing the prepare(), a simple approach is to wrap the object that prepare() hands back. Something like:

    my $sth = $dbh->prepare("SELECT ... WHERE ... ? ...");
    $sth = Statement->wrap($sth, "Label");
    ...
    $sth->execute(@args);
[download]

    package Statement;

    sub wrap {
        my($pkg, $sth, $label) = @_;
        bless [ $sth, $label ], $pkg;
    }

    sub execute {
        my $self = shift;
        # tracing, timing code here. E.g.,
        log($self->[1] . " is about to execute");
        my $rv = $self->[0]->execute(@args);
        # timing, logging code here
    }

    sub finish {
        my $self = shift;
        $self->[0]->finish();
    }

    1;
[download]

The label helps track the statement and makes the logs more readable, and could include the text of the query.

------- MyDBI.pm -------
package MyDBI;
use DBI;
@ISA = qw(DBI);

sub execute{
   print "DBI::execute() called with ".join(',', @_)."\n";
   $_[0]->SUPER::execute(@_);
}

# other methods here
------- MyDBI.pm -------
[download]

Proxying doesn't exactly work like that, because DBI creates objects of other classes, and your execute is defined in the wrong class.

There's a section on "subclassing the DBI" on the DBI manpage that lists in careful detail what you have to do. Basically, you'll have to create three classes named similarly to the DBI triad, and then add your execute override to the statement-handle derived class.

-- Randal L. Schwartz, Perl hacker
Be sure to read my standard disclaimer if this is a reply.

Thanks for pointing that out. I was looking at, apparently, an older version of DBI docs which doesn't have any info on subclassing DBI.

--perlplexer