| Subject: | Inefficient fetching when mysql_server_prepare is set |
I'm testing DBD::mysql-4.005 and perl 5.8.8 on Mac OS X 10.4.11, dual core Intel 2.33GHz.
Fetching the result set data is much slower when using server-prepared statements. It
would seem to be an implementation problem as the data send back from the server appears
the same. I used wireshark to capture the network traffic for client-prepared versus server-
prepared statements. The requests are different as expected but the responses from the
server look the same.
By running the attached script with DBI::Profile, you can see that the execute method runs
faster for server-prepared statements as expected, but the fetchall_arrayref() is MUCH
slower. BTW, I also tried bind_column/fetch calls as saw the same slow performance.
Here are the numbers on my machine for reference:
Server-prepared
DBI::Profile: 1.334358s 44.21% (40004 calls) dbi_bug_report.pl @ 2007-12-14 10:45:55
'DESTROY' =>
0.000080s / 2 = 0.000040s avg (first 0.000044s, min 0.000036s, max 0.000044s)
'STORE' =>
0.000101s
'bind_param' =>
0.010730s / 10000 = 0.000001s avg (first 0.000024s, min 0.000000s, max 0.000024s)
'execute' =>
1.193439s / 10000 = 0.000119s avg (first 0.000267s, min 0.000095s, max 0.009568s)
'fetchall_arrayref' =>
0.123249s / 10000 = 0.000012s avg (first 0.000082s, min 0.000009s, max 0.000086s)
'finish' =>
0.006153s / 10000 = 0.000001s avg (first 0.000001s, min 0.000000s, max 0.000025s)
'prepare' =>
0.000606s
Client_prepared
DBI::Profile: 1.455457s 48.23% (40007 calls) dbi_bug_report.pl @ 2007-12-14 10:45:55
'DESTROY' =>
0.000084s / 2 = 0.000042s avg (first 0.000025s, min 0.000025s, max 0.000059s)
'STORE' =>
0.000043s
'bind_param' =>
0.011236s / 10000 = 0.000001s avg (first 0.000002s, min 0.000001s, max 0.000011s)
'do' =>
0.013926s / 3 = 0.004642s avg (first 0.010250s, min 0.000825s, max 0.010250s)
'execute' =>
1.371118s / 10000 = 0.000137s avg (first 0.000218s, min 0.000121s, max 0.000776s)
'fetchall_arrayref' =>
0.053881s / 10000 = 0.000005s avg (first 0.000013s, min 0.000005s, max 0.000094s)
'finish' =>
0.005113s / 10000 = 0.000001s avg (first 0.000001s, min 0.000000s, max 0.000020s)
'prepare' =>
0.000057s
| Subject: | dbi_bug_report.pl |
use strict;
use DBI qw(:sql_types);
use DBI::Profile;
use Time::HiRes qw(gettimeofday tv_interval);
my $dbh_prepared = DBI->connect("dbi:mysql:test;mysql_server_prepare=1","user","password");
my $dbh = DBI->connect("dbi:mysql:test","user","password");
$dbh_prepared->{'Profile'} = DBI::Profile->new;
$dbh_prepared->{'Profile'} = 4;
$dbh->{'Profile'} = DBI::Profile->new;
$dbh->{'Profile'} = 4;
$dbh->do('DROP TABLE IF EXISTS sample');
$dbh->do('CREATE TABLE sample ( id INTEGER, col2 VARCHAR(16), col3 INTEGER, col4 TIMESTAMP, col5 VARCHAR(16), col6 INTEGER, col7 INTEGER )');
$dbh->do('INSERT INTO sample VALUES (1, \'some text for you\', 67890, CURRENT_TIMESTAMP, \'still more text here\', 1234567, -7623)');
my $rows = 10000;
my $sql = 'SELECT *,CURRENT_TIMESTAMP FROM sample WHERE id = ?';
my $sth_prepared = $dbh_prepared->prepare($sql);
my $t0_prepared = [gettimeofday];
for (my $i = 0; $i < $rows; $i++) {
$sth_prepared->bind_param(1, 1, { 'TYPE' => SQL_INTEGER });
$sth_prepared->execute();
my $result_prepared = $sth_prepared->fetchall_arrayref;
$sth_prepared->finish();
}
my $elapsed_prepared = tv_interval ($t0_prepared);
print "Elapsed server prepared ($rows rows): ${elapsed_prepared}s\n";
my $sth = $dbh->prepare($sql);
my $t0 = [gettimeofday];
for (my $i = 0; $i < $rows; $i++) {
$sth->bind_param(1, 1, { 'TYPE' => SQL_INTEGER });
$sth->execute();
my $result = $sth->fetchall_arrayref;
$sth->finish();
}
my $elapsed = tv_interval ($t0);
print "Elapsed client prepared ($rows rows): ${elapsed}s\n";