| Bug #78778 | mysqlclient does not return correct mysql_insert_id via database handle | ||
|---|---|---|---|
| Submitted: | 9 Oct 2015 9:45 | Modified: | 3 Mar 2017 1:51 |
| Reporter: | Michiel Beijen (OCA) | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: C API (client library) | Severity: | S3 (Non-critical) |
| Version: | 5.7.8 | OS: | Any |
| Assigned to: | Georgi Kodinov | CPU Architecture: | Any |
[9 Oct 2015 9:45]
Michiel Beijen
[15 Oct 2015 16:30]
MySQL Verification Team
Hello Michiel Beijen, Thank you for the report. Verified as described. Thanks, Umesh
[15 Oct 2015 16:33]
MySQL Verification Team
test results
Attachment: 78778.results (application/octet-stream, text), 13.87 KiB.
[6 Nov 2015 15:59]
Georgi Kodinov
This seems to be some sort of a Perl::DBD specific problem.
I've tried the following program using libmysql's C API directly:
-----------------
#include <mysql.h>
int main()
{
MYSQL con;
const char *cmds[] =
{
"SET @@auto_increment_offset = 1",
"SET @@auto_increment_increment = 1",
"CREATE TEMPORARY TABLE dbd_mysql_t31 ( "
" id INT(3) PRIMARY KEY AUTO_INCREMENT NOT NULL, "
" name VARCHAR(64))",
NULL
};
if (!mysql_init(&con))
{
fprintf(stderr, "mysql_init failed\n");
exit(1);
}
if (!mysql_real_connect(&con, "localhost", "root", "", "xx", 3306, NULL, 0))
{
fprintf(stderr, "mysql_real_connect failed: %s\n", mysql_error(&con));
exit(1);
}
for (auto idx= 0; cmds[idx] != NULL; idx++)
{
if (mysql_query(&con, cmds[idx]))
{
fprintf(stderr, "%s failed: %s\n", cmds[idx], mysql_error(&con));
exit(1);
}
}
MYSQL_STMT *stmt= mysql_stmt_init(&con);
if (!stmt)
{
fprintf(stderr, "mysql_stmt_init failed: %s\n", mysql_error(&con));
exit(1);
}
if (mysql_stmt_prepare(stmt,
"INSERT INTO dbd_mysql_t31 (name) VALUES (?)",
sizeof("INSERT INTO dbd_mysql_t31 (name) VALUES (?)") - 1))
{
fprintf(stderr, "mysql_stmt_prepare failed: %s\n", mysql_stmt_error(stmt));
exit(1);
}
MYSQL_BIND bind;
char buffer[50];
unsigned long str_length;
unsigned iid;
memset(&bind, 0, sizeof(bind));
bind.buffer_type= MYSQL_TYPE_STRING;
bind.buffer= &buffer[0];
bind.buffer_length= sizeof(buffer) - 1;
bind.is_null= 0;
bind.length= &str_length;
if (mysql_stmt_bind_param(stmt, &bind))
{
fprintf(stderr, "mysql_stmt_bind_param failed: %s\n", mysql_stmt_error(stmt));
exit(1);
}
strcpy_s(buffer, "Jochen");
str_length= strlen(buffer);
if (mysql_stmt_execute(stmt))
{
fprintf(stderr, "mysql_stmt_execute failed: %s\n", mysql_stmt_error(stmt));
exit(1);
}
iid= (unsigned) mysql_insert_id(&con);
printf("iid after Jochen=%u\n", iid);
strcpy_s(buffer, "Patrick");
str_length= strlen(buffer);
if (mysql_stmt_execute(stmt))
{
fprintf(stderr, "mysql_stmt_execute 2 failed: %s\n", mysql_stmt_error(stmt));
exit(1);
}
iid= (unsigned) mysql_insert_id(&con);
printf("iid after Patrick=%u\n", iid);
mysql_stmt_close(stmt);
mysql_close(&con);
}
---------------
After compiling and running it against a 5.7.9 server I'm getting:
iid after Jochen=1
iid after Patrick=2
Can you please compare the sequence of C API calls with the above and let me know how should the above program be modified to reproduce the issue ?
[7 Dec 2015 1:00]
Bugs System
No feedback was provided for this bug for over a month, so it is being suspended automatically. If you are able to provide the information that was originally requested, please do so and change the status of the bug back to "Open".
[5 Mar 2016 19:00]
Ryan Perry
I can confirm this is still an issue with 5.10 on FreeBSD. It does not seem to be a bug in the perl code. I would ask you re-check your library code.
[10 Mar 2016 13:48]
Georgi Kodinov
I understand it's still an issue, since nothing was done to fix it. Thus I've provided you with a sample program that demonstrates the correct sequence of calls and asked you to compare it with the one the perl driver is producing. I need the C API call sequence in order to reproduce the problem.
[10 Apr 2016 11:11]
Daniël van Eeden
Running the test
===============================================================
$ make test TEST_VERBOSE=1 TEST_FILES='t/31insertid.t'
PERL_DL_NONLAZY=1 "/usr/bin/perl" "-MExtUtils::Command::MM" "-MTest::Harness" "-e" "undef *Test::Harness::Switches; test_harness(1, 'blib/lib', 'blib/arch')" t/31insertid.t
t/31insertid.t ..
1..18
ok 1
ok 2
ok 3 - create dbd_mysql_t31
ok 4
ok 5
ok 6
ok 7 - insert id == 1
ok 8
ok 9
ok 10
ok 11
ok 12
ok 13
ok 14 - sth insert id 2 == max(id) 2 in dbd_mysql_t31
not ok 15 - dbh insert id 0 == max(id) 2 in dbd_mysql_t31
# Failed test 'dbh insert id 0 == max(id) 2 in dbd_mysql_t31'
# at t/31insertid.t line 58.
# got: 0
# expected: 2
ok 16
ok 17
ok 18
# Looks like you failed 1 test of 18.
Dubious, test returned 1 (wstat 256, 0x100)
Failed 1/18 subtests
Test Summary Report
-------------------
t/31insertid.t (Wstat: 256 Tests: 18 Failed: 1)
Failed test: 15
Non-zero exit status: 1
Files=1, Tests=18, 0 wallclock secs ( 0.02 usr 0.00 sys + 0.04 cusr 0.00 csys = 0.06 CPU)
Result: FAIL
Failed 1/1 test programs. 1/18 subtests failed.
Makefile:1161: recipe for target 'test_dynamic' failed
make: *** [test_dynamic] Error 1
===============================================================
Using tshark to see the network traffic:
===============================================================
# tshark -d tcp.port==5711,mysql -Y mysql -i lo -Tfields -e mysql.insert_id -e mysql.affected_rows -e mysql.query tcp port 5711
Running as user "root" and group "root". This could be dangerous.
Capturing on 'Loopback'
0
SET @@auto_increment_offset = 1
0
SET @@auto_increment_increment = 1
0
CREATE TEMPORARY TABLE dbd_mysql_t31 (
id INT(3) PRIMARY KEY AUTO_INCREMENT NOT NULL,
name VARCHAR(64))
0
INSERT INTO dbd_mysql_t31 (name) VALUES ('Jochen')
1 1
INSERT INTO dbd_mysql_t31 (name) VALUES ('Patrick')
2 1
SELECT max(id) FROM dbd_mysql_t31
^C16 packets captured
===============================================================
From ltrace (sudo ltrace -b -f -e 'my*@libmysqlclient.so.20' -o /tmp/ltrace.out make test…)
===============================================================
$ cat /tmp/ltrace.out | egrep -v '[+-]{3}'
14839 libmysqlclient.so.20->mysql_server_init(0, 0, 0, 5711 <unfinished ...>
14839 libmysqlclient.so.20->my_init(0, 0, 0, 5711) = 0
14839 libmysqlclient.so.20->mysql_debug(0, 0x7fccf6789634, 0x8000, 1054) = 0
14839 <... mysql_server_init resumed> ) = 0
14839 libmysqlclient.so.20->mysql_options(0x29a0da0, 34, 0x7fcceed14432, 0x2973d40) = 0
14839 libmysqlclient.so.20->mysql_options(0x29a0da0, 34, 0x7fcceed1443f, 0) = 0
14839 libmysqlclient.so.20->mysql_options(0x29a0da0, 34, 0x7fcceed14443, 0) = 0
14839 libmysqlclient.so.20->mysql_options(0x29a0da0, 34, 0x7fcceed1444d, 0) = 0
14839 libmysqlclient.so.20->mysql_options(0x29a0da0, 34, 0x7fcceed14452, 0) = 0
14839 libmysqlclient.so.20->mysql_options(0x29a0da0, 34, 0x7fcceed1445a, 0) = 0
14839 libmysqlclient.so.20->mysql_options4(0x29a0da0, 33, 0x7fcceed14432, 0x7fcceed1446a) = 0
14839 libmysqlclient.so.20->mysql_options4(0x29a0da0, 33, 0x7fcceed1445a, 0x7fcceed13464) = 0
14839 libmysqlclient.so.20->mysql_options4(0x29a0da0, 33, 0x7fcceed1443f, 0x7fcceed14473) = 0
14839 libmysqlclient.so.20->mysql_options4(0x29a0da0, 33, 0x7fcceed14443, 0x7fcceed14479) = 0
14839 libmysqlclient.so.20->mysql_options4(0x29a0da0, 33, 0x7fcceed1444d, 0x7ffe3dccff20) = 0
14839 libmysqlclient.so.20->mysql_get_option(0, 39, 0x7ffe3dccfd80, 0) = 0
14839 libmysqlclient.so.20->mysql_get_option(0, 40, 0x7ffe3dccfd78, 0xfffffffffff64aa0) = 0
14839 libmysqlclient.so.20->mysql_send_query(0x29a0da0, 0x2968c70, 31, 10) = 0
14839 libmysqlclient.so.20->mysql_send_query(0x29a0da0, 0x268f7c0, 34, 10) = 0
14839 libmysqlclient.so.20->mysql_send_query(0x29a0da0, 0x253f2e0, 108, 10) = 0
14839 libmysqlclient.so.20->mysql_real_escape_string_quote(0x29a0da0, 0x2a5cdaa, 0x2a1cae0, 6) = 6
14839 libmysqlclient.so.20->mysql_send_query(0x29a0da0, 0x2a5cd80, 50, 10) = 0
14839 libmysqlclient.so.20->mysql_real_escape_string_quote(0x29a0da0, 0x2a14a5a, 0x2a1cae0, 7) = 7
14839 libmysqlclient.so.20->mysql_send_query(0x29a0da0, 0x2a14a30, 51, 10) = 0
14839 libmysqlclient.so.20->mysql_send_query(0x29a0da0, 0x2564ab0, 33, 10) = 0
===============================================================
[10 Apr 2016 11:21]
Daniël van Eeden
With a more specific ltrace:
sudo ltrace -b -f -e 'mysql_insert_id@mysql.so' -e 'mysql_send_query@libmysqlclient.so.20' -o /tmp/ltrace.out make …
$ cat /tmp/ltrace.out | egrep -v '[+-]{3}'
15402 libmysqlclient.so.20->mysql_send_query(0x182dcf0, 0x17f5bb0, 31, 10) = 0
15402 libmysqlclient.so.20->mysql_send_query(0x182dcf0, 0x14c3630, 34, 10) = 0
15402 libmysqlclient.so.20->mysql_send_query(0x182dcf0, 0x13cc2e0, 108, 10) = 0
15402 libmysqlclient.so.20->mysql_send_query(0x182dcf0, 0x18e9ce0, 50, 10) = 0
15402 mysql.so->mysql_insert_id(0x182dcf0, 0x7fb7a35fcb70, 0x182dcf0, 0) = 1
15402 mysql.so->mysql_insert_id(0x182dcf0, 0x18a162f, 0x7fb79bebbe90, 0) = 1
15402 mysql.so->mysql_insert_id(0x182dcf0, 0x18a15af, 0x7fb79bebbe90, 0) = 1
15402 libmysqlclient.so.20->mysql_send_query(0x182dcf0, 0x18a1950, 51, 10) = 0
15402 mysql.so->mysql_insert_id(0x182dcf0, 0x7fb7a35fcb78, 0x182dcf0, 0) = 2
15402 libmysqlclient.so.20->mysql_send_query(0x182dcf0, 0x13f1b10, 33, 10) = 0
15402 mysql.so->mysql_insert_id(0x182dcf0, 0x18a162f, 0x7fb79bebbe90, 0) = 0
15402 mysql.so->mysql_insert_id(0x182dcf0, 0x181cc3f, 0x7fb79bebbe90, 0) = 0
[10 Apr 2016 13:04]
Michiel Beijen
Daniël, thanks for stepping in. If I'm not mistaken you only attached 5.7 logs. Is there a difference in the trace between the 5.7.8 client and older clients? And is the difference in the data sent from the client or also in the replies from the server?
[28 Jul 2016 14:28]
Vladimir Marek
Truss output from 5.6 (successfull) run
Attachment: 5.6.good.txt (text/plain), 150.21 KiB.
[28 Jul 2016 14:28]
Vladimir Marek
Truss output from 5.7 (fail) run
Attachment: 5.7.bad.txt (text/plain), 278.66 KiB.
[28 Jul 2016 14:39]
Vladimir Marek
Hi, I'm porting DBD::mysql to Solaris and I found this issue too. I am attaching truss output of good and bad run. Franky, I can't make any sense of the difference though. I have modified both output so that it's easier comparable by vim -d (made some pointers into symbolic name). You can find the problem by looing for '=='. mysql_insert_id just before that returns 0. I know it would be great to have also info on what statements have been executed, I'll work on providing that. Is it enough to collect what strings have been passed to mysql_real_query ? BTW there is corresponding bug against DBD::mysql where I entered my observations too. https://rt.cpan.org/Public/Bug/Display.html?id=108000 Thank you __ Vlad
[1 Aug 2016 11:38]
Vladimir Marek
The new behaviour of mysql 5.7 is accepted by DBD::mysql perl module. The author
says
"An INSERT statement is executed on the database handle. Subsequently, on the
same database handle, a SELECT is performed. Now $dbh->{mysql_insertid} is 0 on
the database handle; when compiled against libmysqlclient 5.7 or up. That
actually seems more correct to me, although it is of course a change in
behavior when compared to earlier versions of libmysqlclient."
Since we are in the same company I can give you easily Solaris machine with
reproducible case if it helps anything. It would be great to have confirmed
from your side that this is expected behavior. And maybe a little test so that
the behavior does not change in the future.
Many thanks!
__
Vlad
[1 Aug 2016 16:07]
Michiel Beijen
What I found is the sample by Georgi Kodinov does not represent the test suite. In the test suite, an additional query is executed on the statement handle: SELECT max(id) FROM dbd_mysql_t31; And only after this the value of mysql_insertid is now 0, when using 5.7.x libmysqlclient. For earlier versions, the value of mysql_insertid was still available.
[14 Sep 2016 12:51]
Georgi Kodinov
Ok, I was able to reproduce the problem using the following program:
------------------
if (!mysql_real_connect(&con, "localhost", "root", "", "xx", 3306, NULL, 0))
{
fprintf(stderr, "mysql_real_connect failed: %s\n", mysql_error(&con));
exit(1);
}
char *stmt= "INSERT INTO dbd_mysql_t31 (name) VALUES ('Jochen')";
if (mysql_query(&con, stmt))
{
fprintf(stderr, "mysql_query INSERT failed: %s\n", mysql_error(&con));
exit(1);
}
iid= (unsigned) mysql_insert_id(&con);
printf("iid after Jochen=%u\n", iid);
if (mysql_query(&con, "SELECT max(id) FROM dbd_mysql_t31"))
{
fprintf(stderr, "mysql_query SELECT failed: %s\n", mysql_error(&con));
exit(1);
}
mysql_free_result(mysql_store_result(&con));
iid= (unsigned) mysql_insert_id(&con);
printf("iid after the SELECT=%u\n", iid);
mysql_close(&con);
-------------------------
This prints:
iid after Jochen=4
iid after the SELECT=0
FYI, this does not happen with the server's LAST_INSERT_ID() function. It stays the same even after a SELECT.
[14 Sep 2016 13:18]
Georgi Kodinov
Also reproducible with mysql.
5.6:
mysql> \s
--------------
..\client\debug\mysql Ver 14.14 Distrib 5.6.33, for Win64 (x86_64)
Connection id: 1
Current database: xx
Current user: root@localhost
SSL: Not in use
Using delimiter: ;
Server version: 5.6.33-debug-log Source distribution
Protocol version: 10
Connection: localhost via TCP/IP
Server characterset: latin1
Db characterset: latin1
Client characterset: cp850
Conn. characterset: cp850
TCP port: 13000
Uptime: 1 min 10 sec
Threads: 1 Questions: 10 Slow queries: 0 Opens: 70 Flush tables: 1 Open tables: 63 Queries per second avg: 0.142
--------------
mysql> insert into dbd_mysql_t31 (name) values ('haha');
--------------
insert into dbd_mysql_t31 (name) values ('haha')
--------------
Query OK, 1 row affected (0.01 sec)
mysql> \s
--------------
..\client\debug\mysql Ver 14.14 Distrib 5.6.33, for Win64 (x86_64)
Connection id: 1
Current database: xx
Current user: root@localhost
SSL: Not in use
Using delimiter: ;
Server version: 5.6.33-debug-log Source distribution
Protocol version: 10
Connection: localhost via TCP/IP
Insert id: 7
Server characterset: latin1
Db characterset: latin1
Client characterset: cp850
Conn. characterset: cp850
TCP port: 13000
Uptime: 1 min 27 sec
Threads: 1 Questions: 14 Slow queries: 0 Opens: 71 Flush tables: 1 Open tables: 64 Queries per second avg: 0.160
--------------
5.7:
mysql> \s
--------------
client\Debug\mysql.exe Ver 14.14 Distrib 8.0.1-dmr, for Win64 (x86_64)
Connection id: 4
Current database: xx
Current user: root@localhost
SSL: Not in use
Using delimiter: ;
Server version: 8.0.1-dmr-debug Source distribution
Protocol version: 10
Connection: localhost via TCP/IP
Server characterset: latin1
Db characterset: latin1
Client characterset: cp850
Conn. characterset: cp850
TCP port: 3306
Uptime: 3 min 30 sec
Threads: 1 Questions: 6 Slow queries: 0 Opens: 163 Flush tables: 2 Open tables: 139 Queries per second avg: 0.028
--------------
mysql> insert into dbd_mysql_t31 (name) values ('haha');
Query OK, 1 row affected (0.01 sec)
mysql> \s
--------------
client\Debug\mysql.exe Ver 14.14 Distrib 8.0.1-dmr, for Win64 (x86_64)
Connection id: 4
Current database: xx
Current user: root@localhost
SSL: Not in use
Using delimiter: ;
Server version: 8.0.1-dmr-debug Source distribution
Protocol version: 10
Connection: localhost via TCP/IP
Server characterset: latin1
Db characterset: latin1
Client characterset: cp850
Conn. characterset: cp850
TCP port: 3306
Uptime: 3 min 37 sec
Threads: 1 Questions: 10 Slow queries: 0 Opens: 163 Flush tables: 2 Open tables: 139 Queries per second avg: 0.046
--------------
Note the absence of Insert id:
[3 Mar 2017 1:51]
Paul DuBois
Posted by developer: Noted in 5.7.18, 8.0.1 changelogs. After performing inserts in a table containing an AUTO_INCREMENT column and then performing a SELECT operation, the LAST_INSERT_ID() returns the correct value, but the value of the mysql_insert_id() C API function was being reset to 0.
[11 Apr 2017 7:15]
Daniël van Eeden
commit 06484eda0bf3e80530fd9762a0b1159f629c85dd
Author: Anushree Prakash B <anushree.prakash.b@oracle.com>
Date: Mon Feb 20 14:02:14 2017 +0530
BUG#22028117 - MYSQLCLIENT DOES NOT RETURN CORRECT
MYSQL_INSERT_ID VIA DATABASE HANDLE
DESCRIPTION
===========
mysql_insert_id() does not return correct values after
performing inserts in a table containing an AUTO_INCREMENT
field and then performing a SELECT operation.
The value of insert_id is getting reset to 0 after
performing SELECT. However, LAST_INSERT_ID() gives the
correct value.
ANALYSIS
========
An OK packet is sent from the server to the client to
signal successful completion of a command.
As of MySQL 5.7.5, OK packes are also used to indicate EOF,
as EOF packets are deprecated. The packet identifier 0x00
represents an OK packet whereas the packet identifier OxFE
represents an EOF packet. The EOF packet has valid values
for the following fields: packet header, warnings and
server status. The fields affected_rows and insert_id will
have valid values only if it was an OK packet and not for
an EOF packet. Reading the values of the above two fields
for an EOF packet will result in inconsistent values being
assigned to the connection handle.
FIX
====
The fix is to assign the affected_rows and insert_id fields
to the connection handle only if they were read from an OK
packet. In case of an EOF packet, skip the assignment and
proceed to the next valid fields. This way we can make sure
that they don't get wrongly updated in the connection
handle.
sql-common/client.c | 29 ++++++++++++++++++++++-------
testclients/mysql_client_test.c | 71 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
2 files changed, 93 insertions(+), 7 deletions(-)
