I'm having a fairly strange problem.
It's a bit of an X-Y problem, so I will first describe "X".
Question X: How can I debug DBI internals using Perl?
More specifically, the calls to DBI's db_error_handler. Some of the SQL server callback output is printed (Query plans) 100% of the time, but some (Actual IOs) is ONLY printed when the query returns zero rows (with set statistics io on
).
Ultimate problem Y I'm trying to address:
For some reason, my Perl script prints query plans but not actual IOs spent when executing Sybase queries when the query returns a result set; BUT print both query plans AND actual IOs spent when the SAME query returns zero rows.
I have a script that, in essence, does this:
sub DoSql { # Sql execution wrapper
my ($dbh, $sql) = @_;
my $sth = $dbh->prepare($sql);
$sth->execute();
}
# Set up DB connection, with debug printing turned on
my $dbh = CreateDBH(); # Uses DBI and creates Sybase database handle DBI object
$dbh->DoSql("set statistics io on");
$dbh->DoSql("set showplan on");
# Print output from DBH callback
$dbh->{_db_error_handler} = sub { PrettyPrintSybaseDebug($_[6]); }
$dbh->DoSql("SELECT * FROM MyTable WHERE ID=100"); # 1 row returned
$dbh->DoSql("SELECT * FROM MyTable WHERE ID=987654321"); # zero rows
When executing this script, the first query prints the following Sybase output from db_error_handler:
QUERY PLAN FOR STATEMENT 1 (at line 1).
STEP 1
The type of query is SELECT.
.....
Total estimated I/O cost for statement 1 (at line 1): 80.
BUT the second query prints the following Sybase output (see the last 3 lines added):
QUERY PLAN FOR STATEMENT 1 (at line 1).
STEP 1
The type of query is SELECT.
.....
Total estimated I/O cost for statement 1 (at line 1): 80.
Table: MyTable scan count 1, logical reads: (regular=3 apf=0 total=3), ...
Total actual I/O cost for this command: 6.
Total writes for this command: 0
Please note that when I execute these queries in raw isql
, BOTH of them, as expected, print both the plan AND the scan counts per table and actual IOs. Both queries run fine and produce expected results sets (1 row and 0 rows respectively)
What am I doing wrong and how can I debug this? Unfortunately, perl -d
doesn't help me, since I can only debug outside $sth->execute();
call and inside the callback.
If it matters, my environment is:
- Perl 5.8.0
- Solaris 10
- Sybase ASE 12.5
- DBI version is 1.37