0

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
Danny Beckett
  • 20,529
  • 24
  • 107
  • 134
DVK
  • 126,886
  • 32
  • 213
  • 327

1 Answers1

2

Using DBI trace information can show some more debug info for you: export DBI_TRACE=LEVEL where LEVEL from 1 to 15

alex
  • 1,304
  • 12
  • 15