Skip Menu |
 

This queue is for tickets about the DBD-mysql CPAN distribution.

Report information
The Basics
Id: 31550
Status: resolved
Priority: 0/
Queue: DBD-mysql

People
Owner: Nobody in particular
Requestors: thedude_rog [...] yahoo.com
Cc:
AdminCc:

Bug Information
Severity: Important
Broken in: 4.005
Fixed in: (no value)



Subject: Inefficient fetching when mysql_server_prepare is set
Download (untitled) / with headers
text/plain 2.1k
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
Download dbi_bug_report.pl
text/x-perl 1.5k
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";
Download (untitled) / with headers
text/plain 147b
For reference, I also tried PHP mysqli and Ruby mysql module and both of those were much more efficient than DBD::mysql at fetching the same data.
Download (untitled) / with headers
text/plain 1.5k
Here are updated numbers on recent DBI /DBD::mysql. The differences still exist but are not as big as before. Elapsed server prepared (10000 rows): 3.718708s Elapsed client prepared (10000 rows): 3.814599s DBI::Profile: 3.502119s 46.38% (40007 calls) t.pl @ 2013-10-20 20:04:52 'DESTROY' => 0.000091s / 2 = 0.000046s avg (first 0.000020s, min 0.000020s, max 0.000071s) 'STORE' => 0.000049s 'bind_param' => 0.058869s / 10000 = 0.000006s avg (first 0.000005s, min 0.000001s, max 0.000697s) 'do' => 0.016166s / 3 = 0.005389s avg (first 0.005523s, min 0.002034s, max 0.008609s) 'execute' => 3.265197s / 10000 = 0.000327s avg (first 0.000305s, min 0.000138s, max 0.006285s) 'fetchall_arrayref' => 0.113331s / 10000 = 0.000011s avg (first 0.000014s, min 0.000003s, max 0.000963s) 'finish' => 0.048356s / 10000 = 0.000005s avg (first 0.000004s, min 0.000000s, max 0.002494s) 'prepare' => 0.000060s DBI::Profile: 3.379176s 44.75% (40004 calls) t.pl @ 2013-10-20 20:04:52 'DESTROY' => 0.000162s / 2 = 0.000081s avg (first 0.000089s, min 0.000073s, max 0.000089s) 'STORE' => 0.000144s 'bind_param' => 0.062555s / 10000 = 0.000006s avg (first 0.000017s, min 0.000000s, max 0.001218s) 'execute' => 3.106647s / 10000 = 0.000311s avg (first 0.000459s, min 0.000125s, max 0.003506s) 'fetchall_arrayref' => 0.161787s / 10000 = 0.000016s avg (first 0.000041s, min 0.000000s, max 0.002391s) 'finish' => 0.047360s / 10000 = 0.000005s avg (first 0.000006s, min 0.000000s, max 0.000431s) 'prepare' => 0.000521s
Closing


This service is sponsored and maintained by Best Practical Solutions and runs on Perl.org infrastructure.

Please report any issues with rt.cpan.org to rt-cpan-admin@bestpractical.com.