Skip Menu |

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

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

People
Owner: MICHIELB [...] cpan.org
Requestors: shay [...] cpan.org
Cc:
AdminCc:

Bug Information
Severity: (no value)
Broken in: 4.023
Fixed in:
  • 4.022
  • 4.023
  • 4.024



Subject: fetch*() on lost connection wrongly reports "fetch() without execute()" instead of "MySQL server has gone away"
If the perl program's connection to the MySQL server gets timed out and closed by the server then a subsequent prepare() + execute() + fetchrow_array() + finish() wrongly reports error 19 ("fetch() without execute()") instead of 2006 ("MySQL server has gone away"). (And, in fact, the error comes from the fetchrow_array() function, *after* it has (apparently) done a successful execute()!) The problem can be easily reproduced with the attached perl program after setting "wait_timeout = 5" in the [mysqld] section of the appropriate my.ini configuration file (and restarting the MySQL server). The program establishes a connection to the 'mysql' database, waits for 7 seconds to be sure the connection gets timed out, then prepares, excutes, fetches and finishes a simple statement ('SELECT 1'). I get the following output every time: Connecting... Sleeping... Preparing... Executing... Fetching... Error 19: fetch() without execute() The other three fetch*() functions commented out in the program behave the same way, but strangely the three select*() functions in a separate block in the program apparently succeed with no error at all if you adjust the program to run through that block of code instead. Note that I have previously had a similar issue with "fetch() without execute()" being wrongly reported instead of the expected lost connection error. For example, see the following mailing list archive thread from 11 years ago in which I reported the same problem: http://grokbase.com/t/mysql/perl/0251jk3kpt/dbd-mysql-fetch-without-execute-error That discussion resulted in a fix for the problem which I had then, and the fix which it put into dbdimp.c is indeed still there around line 3273. I wonder if there is a similar problem lurking somewhere else in that file?
Subject: dbtest.pl
use strict; use warnings; use DBI; my($dbh, $sth); my $ok = eval { print "Connecting...\n"; $dbh = DBI->connect('dbi:mysql:database=mysql;mysql_client_found_rows=1', 'root', undef, {PrintError => 0, RaiseError => 1, AutoCommit => 0}); print "Sleeping...\n"; sleep 7; my $sql = 'SELECT 1'; if (1) { print "Preparing...\n"; $sth = $dbh->prepare($sql); print "Executing...\n"; $sth->execute(); print "Fetching...\n"; my @res = $sth->fetchrow_array(); # my $res = $sth->fetchrow_arrayref(); # my $res = $sth->fetchrow_hashref(); # my $res = $sth->fetchall_arrayref(); print "Finishing...\n"; $sth->finish(); $sth = undef; } else { print "Selecting...\n"; my @res = $dbh->selectrow_array($sql); # my $res = $dbh->selectall_arrayref($sql); # my $res = $dbh->selectcol_arrayref($sql); } print "Disconnecting...\n"; $dbh->disconnect(); $dbh = undef; 1; }; if (not $ok) { printf "Error %d: %s\n", $DBI::err, $DBI::errstr; eval { $sth->finish(); } if defined $sth; eval { $dbh->disconnect(); } if defined $dbh; }
Subject: [PATCH] fetch*() on lost connection wrongly reports "fetch() without execute()" instead of "Lost connection to MySQL server during query"
On Thu Jun 06 06:23:16 2013, SHAY wrote: Show quoted text
> If the perl program's connection to the MySQL server gets timed out > and closed by the server then a subsequent prepare() + execute() + > fetchrow_array() + finish() wrongly reports error 19 ("fetch() > without execute()") instead of 2006 ("MySQL server has gone away"). > (And, in fact, the error comes from the fetchrow_array() function, > *after* it has (apparently) done a successful execute()!) >
I have now debugged this and have a patch which fixes it (attached). It turns out that execute() was returning early because mysql_db_reconnect() only checked for CR_SERVER_GONE_ERROR (0x000007d6 == 2006), but the error that it got from mysql_errno() was actually CR_SERVER_LOST (0x000007dd == 2013): Show quoted text
> mysql.dll!mysql_db_reconnect(sv * h) Line 4851 C
mysql.dll!mysql_st_internal_execute(sv * h, sv * statement, sv * attribs, int num_params, imp_sth_ph_st * params, st_mysql_res * * result, st_mysql * svsock, int use_mysql_use_result) Line 3269 + 0x1e bytes C mysql.dll!mysql_st_execute(sv * sth, imp_sth_st * imp_sth) Line 3513 + 0x3c bytes C mysql.dll!XS_DBD__mysql__st_execute(interpreter * my_perl, cv * cv) Line 591 + 0xd bytes C DBI.dll!XS_DBI_dispatch(interpreter * my_perl, cv * cv) Line 3715 + 0x18 bytes C [...] Checking for either error code allows mysql_db_reconnect() to proceed further, and it will now succeed if AutoCommit==1 and mysql_auto_reconnect==1. However, if either of those options are not set (as in my sample program) mysql_db_reconnect() still returns early without reconnecting: that's fine in itself, but when execution continues back in the caller it eventually goes into fetch() and fails exactly as before, claiming that no execute() has yet been performed!: Show quoted text
> mysql.dll!mysql_st_fetch(sv * sth, imp_sth_st * imp_sth) Line 3766 C
mysql.dll!XS_DBD__mysql__st_fetchrow_array(interpreter * my_perl, cv * cv) Line 639 + 0xd bytes C DBI.dll!XS_DBI_dispatch(interpreter * my_perl, cv * cv) Line 3715 + 0x18 bytes C [...] I understand why it says this now, but it would be much better if mysql_st_internal_execute() had caught the error about the connection having been lost earlier, thus giving the correct error in the correct place, before it even goes as far as trying to fetch() after a failed execute(). The attached patch makes both of these changes, and my sample program now outputs the expected: Connecting... Sleeping... Preparing... Executing... Error 2013: Lost connection to MySQL server during query (Well, actually, I was expecting error 2006, just like dbdimp.c evidently was too, but I can work with 2013 just as well ;-) The test suite also now passes t/91errcheck.t test 1, which previously failed for me. There are no other test failures except t/50chopblanks.t tests 15, 22, 44, 51 and t/76multi_statement.t tests 14, 22-23 which all failed originally anyway. I would be very grateful if somebody could apply this patch and roll a new DBD-mysql release.
Subject: dbd-mysql.patch
diff -ruN DBD-mysql-4.023.orig/dbdimp.c DBD-mysql-4.023/dbdimp.c --- DBD-mysql-4.023.orig/dbdimp.c 2013-04-12 22:18:56.000000000 +0100 +++ DBD-mysql-4.023/dbdimp.c 2013-06-10 15:37:59.318939600 +0100 @@ -3268,6 +3268,10 @@ (!mysql_db_reconnect(h) || (mysql_real_query(svsock, sbuf, slen)))) { + if (mysql_errno(svsock)) + do_error(h, mysql_errno(svsock), mysql_error(svsock) + ,mysql_sqlstate(svsock)); + rows = -2; } else { /** Store the result from the Query */ @@ -4836,6 +4840,7 @@ dTHX; D_imp_xxh(h); imp_dbh_t* imp_dbh; + unsigned int last_errno; MYSQL save_socket; if (DBIc_TYPE(imp_xxh) == DBIt_ST) @@ -4846,7 +4851,8 @@ else imp_dbh= (imp_dbh_t*) imp_xxh; - if (mysql_errno(imp_dbh->pmysql) != CR_SERVER_GONE_ERROR) + last_errno = mysql_errno(imp_dbh->pmysql); + if (last_errno != CR_SERVER_GONE_ERROR && last_errno != CR_SERVER_LOST) /* Other error */ return FALSE;
Hi Steve, Thanks for filing a bug report, and for providing a patch. Since you filed it, we released a new version I've rewrote your demo program a little so it can act as a test; here: https://github.com/perl5-dbi/DBD-mysql/commit/c8f23b7de82a24e034dc9268a8dbd5f41f2a1cd4 The thing is, for me the test works, it nicely reports 'the server has gone away' - I also tested on older versions of DBD::mysql. Can you maybe take a brief look and point out where I made a mistake? -- Mike On Mon Jun 10 11:07:03 2013, SHAY wrote: Show quoted text
> On Thu Jun 06 06:23:16 2013, SHAY wrote:
> > If the perl program's connection to the MySQL server gets timed out > > and closed by the server then a subsequent prepare() + execute() + > > fetchrow_array() + finish() wrongly reports error 19 ("fetch() > > without execute()") instead of 2006 ("MySQL server has gone > > away"). > > (And, in fact, the error comes from the fetchrow_array() function, > > *after* it has (apparently) done a successful execute()!) > >
> > I have now debugged this and have a patch which fixes it (attached). > > It turns out that execute() was returning early because > mysql_db_reconnect() only checked for CR_SERVER_GONE_ERROR (0x000007d6 > == 2006), but the error that it got from mysql_errno() was actually > CR_SERVER_LOST (0x000007dd == 2013): >
> > mysql.dll!mysql_db_reconnect(sv * h) Line 4851 C
> mysql.dll!mysql_st_internal_execute(sv * h, sv * statement, sv * > attribs, int num_params, imp_sth_ph_st * params, st_mysql_res * * > result, st_mysql * svsock, int use_mysql_use_result) Line 3269 + 0x1e > bytes C > mysql.dll!mysql_st_execute(sv * sth, imp_sth_st * imp_sth) Line 3513 > + 0x3c bytes C > mysql.dll!XS_DBD__mysql__st_execute(interpreter * my_perl, cv * cv) > Line 591 + 0xd bytes C > DBI.dll!XS_DBI_dispatch(interpreter * my_perl, cv * cv) Line 3715 + > 0x18 bytes C > [...] > > Checking for either error code allows mysql_db_reconnect() to proceed > further, and it will now succeed if AutoCommit==1 and > mysql_auto_reconnect==1. > > However, if either of those options are not set (as in my sample > program) mysql_db_reconnect() still returns early without > reconnecting: that's fine in itself, but when execution continues back > in the caller it eventually goes into fetch() and fails exactly as > before, claiming that no execute() has yet been performed!: >
> > mysql.dll!mysql_st_fetch(sv * sth, imp_sth_st * imp_sth) Line 3766 > > C
> mysql.dll!XS_DBD__mysql__st_fetchrow_array(interpreter * my_perl, cv * > cv) Line 639 + 0xd bytes C > DBI.dll!XS_DBI_dispatch(interpreter * my_perl, cv * cv) Line 3715 + > 0x18 bytes C > [...] > > I understand why it says this now, but it would be much better if > mysql_st_internal_execute() had caught the error about the connection > having been lost earlier, thus giving the correct error in the correct > place, before it even goes as far as trying to fetch() after a failed > execute(). > > The attached patch makes both of these changes, and my sample program > now outputs the expected: > > Connecting... > Sleeping... > Preparing... > Executing... > Error 2013: Lost connection to MySQL server during query > > (Well, actually, I was expecting error 2006, just like dbdimp.c > evidently was too, but I can work with 2013 just as well ;-) > > The test suite also now passes t/91errcheck.t test 1, which previously > failed for me. There are no other test failures except > t/50chopblanks.t tests 15, 22, 44, 51 and t/76multi_statement.t tests > 14, 22-23 which all failed originally anyway. > > I would be very grateful if somebody could apply this patch and roll a > new DBD-mysql release.
CC: shay [...] cpan.org
Subject: Re: [rt.cpan.org #85919] [PATCH] fetch*() on lost connection wrongly reports "fetch() without execute()" instead of "Lost connection to MySQL server during query"
Date: Fri, 4 Oct 2013 18:01:07 +0100
To: bug-DBD-mysql [...] rt.cpan.org
From: Steve Hay <steve.m.hay [...] googlemail.com>
Thanks for the heads-up. I've just tried the latest version (4.024) from CPAN and I too find that my original test case no longer exhibits the problem. Switching back to the version that I was using at the time (4.021), I see the problem again so something in 4.022, 4.023 or 4.024 has evidently fixed it anyway. I didn't bisect to find exactly what. On 3 October 2013 19:30, Michiel Beijen via RT <bug-DBD-mysql@rt.cpan.org> wrote: Show quoted text
> <URL: https://rt.cpan.org/Ticket/Display.html?id=85919 > > > Hi Steve, > > Thanks for filing a bug report, and for providing a patch. > Since you filed it, we released a new version > > I've rewrote your demo program a little so it can act as a test; here: > https://github.com/perl5-dbi/DBD-mysql/commit/c8f23b7de82a24e034dc9268a8dbd5f41f2a1cd4 > > The thing is, for me the test works, it nicely reports 'the server has gone away' - I also tested on older versions of DBD::mysql. > Can you maybe take a brief look and point out where I made a mistake? > > -- > Mike > > On Mon Jun 10 11:07:03 2013, SHAY wrote:
>> On Thu Jun 06 06:23:16 2013, SHAY wrote:
>> > If the perl program's connection to the MySQL server gets timed out >> > and closed by the server then a subsequent prepare() + execute() + >> > fetchrow_array() + finish() wrongly reports error 19 ("fetch() >> > without execute()") instead of 2006 ("MySQL server has gone >> > away"). >> > (And, in fact, the error comes from the fetchrow_array() function, >> > *after* it has (apparently) done a successful execute()!) >> >
>> >> I have now debugged this and have a patch which fixes it (attached). >> >> It turns out that execute() was returning early because >> mysql_db_reconnect() only checked for CR_SERVER_GONE_ERROR (0x000007d6 >> == 2006), but the error that it got from mysql_errno() was actually >> CR_SERVER_LOST (0x000007dd == 2013): >>
>> > mysql.dll!mysql_db_reconnect(sv * h) Line 4851 C
>> mysql.dll!mysql_st_internal_execute(sv * h, sv * statement, sv * >> attribs, int num_params, imp_sth_ph_st * params, st_mysql_res * * >> result, st_mysql * svsock, int use_mysql_use_result) Line 3269 + 0x1e >> bytes C >> mysql.dll!mysql_st_execute(sv * sth, imp_sth_st * imp_sth) Line 3513 >> + 0x3c bytes C >> mysql.dll!XS_DBD__mysql__st_execute(interpreter * my_perl, cv * cv) >> Line 591 + 0xd bytes C >> DBI.dll!XS_DBI_dispatch(interpreter * my_perl, cv * cv) Line 3715 + >> 0x18 bytes C >> [...] >> >> Checking for either error code allows mysql_db_reconnect() to proceed >> further, and it will now succeed if AutoCommit==1 and >> mysql_auto_reconnect==1. >> >> However, if either of those options are not set (as in my sample >> program) mysql_db_reconnect() still returns early without >> reconnecting: that's fine in itself, but when execution continues back >> in the caller it eventually goes into fetch() and fails exactly as >> before, claiming that no execute() has yet been performed!: >>
>> > mysql.dll!mysql_st_fetch(sv * sth, imp_sth_st * imp_sth) Line 3766 >> > C
>> mysql.dll!XS_DBD__mysql__st_fetchrow_array(interpreter * my_perl, cv * >> cv) Line 639 + 0xd bytes C >> DBI.dll!XS_DBI_dispatch(interpreter * my_perl, cv * cv) Line 3715 + >> 0x18 bytes C >> [...] >> >> I understand why it says this now, but it would be much better if >> mysql_st_internal_execute() had caught the error about the connection >> having been lost earlier, thus giving the correct error in the correct >> place, before it even goes as far as trying to fetch() after a failed >> execute(). >> >> The attached patch makes both of these changes, and my sample program >> now outputs the expected: >> >> Connecting... >> Sleeping... >> Preparing... >> Executing... >> Error 2013: Lost connection to MySQL server during query >> >> (Well, actually, I was expecting error 2006, just like dbdimp.c >> evidently was too, but I can work with 2013 just as well ;-) >> >> The test suite also now passes t/91errcheck.t test 1, which previously >> failed for me. There are no other test failures except >> t/50chopblanks.t tests 15, 22, 44, 51 and t/76multi_statement.t tests >> 14, 22-23 which all failed originally anyway. >> >> I would be very grateful if somebody could apply this patch and roll a >> new DBD-mysql release.
> > >
RT-Send-CC: steve.m.hay [...] googlemail.com
Steve, On Fri Oct 04 13:01:27 2013, steve.m.hay@googlemail.com wrote: Show quoted text
> Thanks for the heads-up. I've just tried the latest version (4.024) > from CPAN and I too find that my original test case no longer exhibits > the problem. Switching back to the version that I was using at the > time (4.021), I see the problem again so something in 4.022, 4.023 or > 4.024 has evidently fixed it anyway. I didn't bisect to find exactly > what.
Great, thanks for the confirmation. I'm setting this RT ticket to resolved now. -- Mike