On 19/07/15 15:41, Tim Bunce wrote:
On Thu, Jul 16, 2015 at 10:46:35AM -0700, David E. Wheeler wrote:
On Jul 16, 2015, at 6:40 AM, Tim Bunce <tim.bu...@pobox.com> wrote:
Well, this contains lots more light! ...
-> dbd_st_execute for 03fdf4e0
parse_params statement
SELECT c.change_id ...
Binding parameters: SELECT c.change_id
--> do_error
Out of sort memory, consider increasing server sort buffer size error 1038
recorded: Out of sort memory, consider increasing server sort buffer size
<-- do_error
<- dbd_st_execute returning imp_sth->row_num 18446744073709551615
!! ERROR: 1038 'Out of sort memory, consider increasing server sort buffer
size' (err#0)
<- execute= ( -1 ) [1 items] at /usr/lib/perl5/DBI.pm line 1632 via at
/usr/local/share/perl/5.18.2/App/Sqitch/Role/DBIEngine.pm line 149
So execute failed. Note the crazy row_num. Execute seems to have
returned -1, which is a true value.
!! The ERROR '1038' was CLEARED by call to fetchrow_hashref method
-> fetchrow_hashref for DBD::mysql::st (DBI::st=HASH(0x42cfcc0)~0x4231cf8)
thr#2603010
Then the higher-level code called fetchrow_hashref, which cleared the
error recorded by execute().
FWIW, the database handle is created like this:
my $dbh = DBI->connect($uri->dbi_dsn, scalar $self->username, $pass, {
PrintError => 0,
RaiseError => 0,
AutoCommit => 1,
mysql_enable_utf8 => 1,
mysql_auto_reconnect => 0,
mysql_use_result => 0, # Prevent "Commands out of sync" error.
HandleError => sub {
my ($err, $dbh) = @_;
$@ = $err;
@_ = ($dbh->state || 'DEV' => $dbh->errstr);
goto &hurl;
},
Context:
https://github.com/theory/sqitch/blob/master/lib/App/Sqitch/Engine/mysql.pm#L59
So I’m a little confused as to why the execute failure was ignored. Is this an
issue with DBD::mysql?
Note the "row_num 18446744073709551615" above, that's -1 as an unsigned 64 bit
long.
DBD::mysql's handling of row_num seems less than ideal (prompted in part by
baggage of the DBI's ancient driver API).
int dbd_st_execute(SV* sth, imp_sth_t* imp_sth) <== XXX int (forced by DBI API)
{
...
imp_sth->row_num= mysql_st_internal_execute(...) <== row_num is declared as
my_ulonglong
...
if (imp_sth->row_num+1 != (my_ulonglong)-1) { ... } <== XXX
...
...
sprintf(actual_row_num, "%llu", imp_sth->row_num);
PerlIO_printf(DBIc_LOGPIO(imp_xxh), " <- dbd_st_execute returning
imp_sth->row_num %s\n", actual_row_num);
}
return (int)imp_sth->row_num; # <== XXX
}
my_ulonglong mysql_st_internal_execute(...) <== unsigned
{
my_ulonglong rows= 0; <== unsigned
if (!slen) {
do_error(h, JW_ERR_QUERY, "Missing table name" ,NULL);
return -2; <== signed
}
if (!(table= malloc(slen+1))) {
do_error(h, JW_ERR_MEM, "Out of memory" ,NULL);
return -2; <== signed
}
if (!(*result)) {
do_error(h, mysql_errno(svsock),
mysql_error(svsock),mysql_sqlstate(svsock));
return -2; <== signed
}
if(rows == -2) { <== signed
do_error(h, mysql_errno(svsock), mysql_error(svsock),
mysql_sqlstate(svsock));
if (DBIc_TRACE_LEVEL(imp_xxh) >= 2)
PerlIO_printf(DBIc_LOGPIO(imp_xxh), "IGNORING ERROR errno %d\n", errno);
rows = -2; <== signed
}
return(rows);
}
mysql_st_internal_execute41(...) has very similar issues
Looks to me like you've hit some latent bugs in the DBD::mysql code (e.g., it's
not safe/reliable to throw negative numbers around in unsigned types) compounded
by the limitations of the ancient DBI driver API:
https://github.com/perl5-dbi/dbi/blob/1486773ec0bf357661d756cf37ff2988b5eaf24d/Driver.xst#L585-L601
Seems like there's a need to separate "row count" from "execute return value".
Internally the DBI has a DBIc_ROW_COUNT(sth) macro that has an IV type.
That's a signed int that would be 64 bits on most modern systems.
On many of those systems the plain int type might be 32 bits.
I've just pushed an experimental change that might help in general
https://github.com/perl5-dbi/dbi/commit/29f6b9b76e9c637be31cb80f1a262ff68b42ef43#diff-cb6af96fe009d6f8d9d682415e1ab755
but probably wouldn't in your case.
At the moment I'd view this as a DBD::mysql bug.
Tim.
p.s. These open DBD::mysql issues might also be more or less related:
https://rt.cpan.org/Public/Bug/Display.html?id=48158
https://rt.cpan.org/Public/Bug/Display.html?id=80394
https://rt.cpan.org/Public/Bug/Display.html?id=75570
Please also see the issue I reported in DBI back in 2012:
https://rt.cpan.org/Ticket/Display.html?id=81911
I had to add various workarounds and a warning to DBD::ODBC.
Martin
