Bug #54861 Additional connections not handled properly in mtr --embedded
Submitted: 28 Jun 2010 11:50 Modified: 3 Oct 2010 1:38
Reporter: Vasil Dimov Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Embedded Library ( libmysqld ) Severity:S3 (Non-critical)
Version:5.5.6-m3 OS:Any
Assigned to: Alexey Botchkov CPU Architecture:Any
Tags: embedded crash mtr

[28 Jun 2010 11:50] Vasil Dimov 
Description:
If this debug assertion in InnoDB is enabled then many tests start crashing in ./mtr --embedded:

in row_search_for_mysql():
row0sel.c:3328: ut_ad(trx->mysql_thread_id == os_thread_get_curr_id());

(to enable this either define UNIV_DEBUG in storage/innobase/include/univ.i or change it from ut_ad() to ut_a()).

Here is the relevant part from one of the failing tests (innodb.innodb_bug49164):

--- cut ---
connect (con1,localhost,root,,);
connect (con2,localhost,root,,);

connection con1;
SET tx_isolation = 'READ-COMMITTED';

CREATE TABLE bug49164 (a INT, b BIGINT, c TINYINT, PRIMARY KEY (a, b))
ENGINE=InnoDB;

insert into bug49164 values (1,1,1), (2,2,2), (3,3,3);

begin;
Update bug49164 set c=7;
SElect * from bug49164;
ROLlback;
SELEct * from bug49164;
begin;
UPDATe bug49164 set c=7;

connection con2;

SET tx_isolation = 'READ-COMMITTED';
begin;
SELECT * from bug49164;
commit;
begin;
--send
UPDATE bug49164 set c=6 where a=1 and b=1;
--- cut ---

To help nail down the problem, apply this patch (adds debug printf):

--- cut ---
--- storage/innobase/handler/ha_innodb.cc	revid:jimmy.yang@oracle.com-20100625051420-ps44ileuontw6hn3
+++ storage/innobase/handler/ha_innodb.cc	2010-06-28 11:12:26 +0000
@@ -5557,12 +5557,22 @@ ha_innobase::index_read(
 	ulint		ret;
 
 	DBUG_ENTER("index_read");
 
 	ut_a(prebuilt->trx == thd_to_trx(user_thd));
 
+	size_t		len;
+	const char*	stmt;
+	stmt = innobase_get_stmt(prebuilt->trx->mysql_thd, &len);
+	
+	fprintf(stderr, "::index_read(): %p %p %.*s\n",
+		os_thread_get_curr_id(),
+		prebuilt->trx->mysql_thread_id,
+		(int) len, stmt);
+	ut_a(prebuilt->trx->mysql_thread_id == os_thread_get_curr_id());
+
 	ha_statistic_increment(&SSV::ha_read_key_count);
--- cut ---

and then run ./mtr --embedded --client-gdb innodb.innodb_bug49164, it prints this before crashing:

::index_read(): 0x8018041c0 0x8018041c0 Update bug49164 set c=7
::index_read(): 0x8018041c0 0x8018041c0 SElect * from bug49164
::index_read(): 0x8018041c0 0x8018041c0 SELEct * from bug49164
::index_read(): 0x8018041c0 0x8018041c0 UPDATe bug49164 set c=7
::index_read(): 0x8018041c0 0x8018041c0 SELECT * from bug49164
[New Thread 801808980 (LWP 100310)]
::index_read(): 0x801808980 0x8018041c0 UPDATE bug49164 set c=6 where a=1 and b=1
100628 14:13:02  InnoDB: Assertion failure in thread 34384939392 in file /usr/w/mysql-trunk-innodb/storage/innobase/handler/ha_innodb.cc line 5571
InnoDB: Failing assertion: prebuilt->trx->mysql_thread_id == os_thread_get_curr_id()

Notice that after the "connection con2" command the first SQL command "SELECT * from bug49164;" is still executed by the old thread "0x8018041c0", then a new thread is created and the subsequent "UPDATE bug49164 set c=6 where a=1 and b=1" command is executed by the new thread "0x801808980", while prebuilt->trx->mysql_thread_id still points to the old thread "0x8018041c0".

How to repeat:
Compile mysql with innodb and embedded support, enable the assertion as described above and run e.g. ./mtr --embedded innodb.innodb_bug49164 (lots of other tests fail too with the same assertion)
[28 Jun 2010 12:37] Valeriy Kravchuk 
Verified just as described on Mac OS X:

valeriy-kravchuks-macbook-pro:mysql-test openxs$ ./mtr --embedded --client-gdb innodb.innodb_bug49164
Logging: ./mtr  --embedded --client-gdb innodb.innodb_bug49164
100628 15:32:44 [Warning] Setting lower_case_table_names=2 because file system for /var/folders/dX/dXCzvuSlHX4Op1g-o1jIWk+++TI/-Tmp-/M4fxIrcPO6/ is case insensitive
100628 15:32:44 [Note] Buffered information: Performance schema disabled (reason: start parameters).

100628 15:32:44 [Note] Plugin 'FEDERATED' is disabled.
100628 15:32:44 [Note] Plugin 'ndbcluster' is disabled.
MySQL Version 5.5.6
Checking supported features...
 - skipping ndbcluster
 - skipping SSL
 - binaries are debug compiled
Collecting tests...
vardir: /Users/openxs/dbs/trunk/mysql-test/var
Checking leftover processes...
Removing old var directory...
Creating var directory '/Users/openxs/dbs/trunk/mysql-test/var'...
Installing system database...
Using server port 63913

==============================================================================

TEST                                      RESULT   TIME (ms)
------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
innodb.innodb_bug49164                   [ pass ]       
------------------------------------------------------------
The servers were restarted 0 times
Spent 0.000 of 81 seconds executing testcases

Completed: All 1 tests were successful.

valeriy-kravchuks-macbook-pro:mysql-test openxs$ ./mtr --embedded innodb.innodb_bug49164
Logging: ./mtr  --embedded innodb.innodb_bug49164
100628 15:34:27 [Warning] Setting lower_case_table_names=2 because file system for /var/folders/dX/dXCzvuSlHX4Op1g-o1jIWk+++TI/-Tmp-/X89KAYFKyY/ is case insensitive
100628 15:34:27 [Note] Buffered information: Performance schema disabled (reason: start parameters).

100628 15:34:27 [Note] Plugin 'FEDERATED' is disabled.
100628 15:34:27 [Note] Plugin 'ndbcluster' is disabled.
MySQL Version 5.5.6
Checking supported features...
 - skipping ndbcluster
 - skipping SSL
 - binaries are debug compiled
Collecting tests...
vardir: /Users/openxs/dbs/trunk/mysql-test/var
Checking leftover processes...
Removing old var directory...
Creating var directory '/Users/openxs/dbs/trunk/mysql-test/var'...
Installing system database...
Using server port 63926

==============================================================================

TEST                                      RESULT   TIME (ms)
------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
innodb.innodb_bug49164                   [ fail ]
        Test ended at 2010-06-28 15:34:39

CURRENT_TEST: innodb.innodb_bug49164
InnoDB: The InnoDB memory heap is disabled
InnoDB: Mutexes and rw_locks use GCC atomic builtins
InnoDB: Compressed tables use zlib 1.2.3
100628 15:34:39  InnoDB: highest supported file format is Barracuda.
::index_read(): 0xa05e1720 0xa05e1720 update bug49164 set c=7
::index_read(): 0xa05e1720 0xa05e1720 select * from bug49164
::index_read(): 0xa05e1720 0xa05e1720 select * from bug49164
::index_read(): 0xa05e1720 0xa05e1720 update bug49164 set c=7
::index_read(): 0xa05e1720 0xa05e1720 select * from bug49164
::index_read(): 0xb0545000 0xa05e1720 update bug49164 set c=6 where a=1 and b=1
100628 15:34:39  InnoDB: Assertion failure in thread 2958315520 in file handler/ha_innodb.cc line 5571
InnoDB: Failing assertion: prebuilt->trx->mysql_thread_id == os_thread_get_curr_id()
[13 Jul 2010 14:51] Vasil Dimov 
From above: innodb.innodb_bug49164 and storage/innobase mean that this is the builtin. The InnoDB Plugin lives in storage/innodb_plugin and its tests are named like e.g. innodb_plugin.innodb_bug49164.
[13 Jul 2010 14:52] Vasil Dimov 
Hmm, actually this bug is filled against 5.5. There is only one InnoDB in MySQL 5.5.
[4 Aug 2010 7:53] Bugs System 
Pushed into mysql-trunk 5.5.6-m3 (revid:alik@sun.com-20100731131027-1n61gseejyxsqk5d) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (merge vers: 5.1.49) (pib:18)
[4 Aug 2010 7:55] Bugs System 
Pushed into mysql-trunk 5.5.6-m3 (revid:alik@sun.com-20100731131027-1n61gseejyxsqk5d) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (merge vers: 5.1.49) (pib:18)
[4 Aug 2010 7:56] Bugs System 
Pushed into mysql-trunk 5.5.6-m3 (revid:alik@sun.com-20100731131027-1n61gseejyxsqk5d) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (merge vers: 5.1.49) (pib:18)
[4 Aug 2010 7:57] Bugs System 
Pushed into mysql-trunk 5.5.6-m3 (revid:alik@sun.com-20100731131027-1n61gseejyxsqk5d) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (merge vers: 5.1.49) (pib:18)
[4 Aug 2010 7:58] Bugs System 
Pushed into mysql-trunk 5.5.6-m3 (revid:alik@sun.com-20100731131027-1n61gseejyxsqk5d) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (merge vers: 5.1.49) (pib:18)
[4 Aug 2010 7:59] Bugs System 
Pushed into mysql-trunk 5.5.6-m3 (revid:alik@sun.com-20100731131027-1n61gseejyxsqk5d) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (merge vers: 5.1.49) (pib:18)
[4 Aug 2010 8:00] Bugs System 
Pushed into mysql-trunk 5.5.6-m3 (revid:alik@sun.com-20100731131027-1n61gseejyxsqk5d) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (merge vers: 5.1.49) (pib:18)
[4 Aug 2010 8:11] Bugs System 
Pushed into mysql-trunk 5.6.1-m4 (revid:alik@ibmvm-20100804080001-bny5271e65xo34ig) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (merge vers: 5.1.49) (pib:18)
[4 Aug 2010 8:13] Bugs System 
Pushed into mysql-trunk 5.6.1-m4 (revid:alik@ibmvm-20100804080001-bny5271e65xo34ig) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (merge vers: 5.1.49) (pib:18)
[4 Aug 2010 8:14] Bugs System 
Pushed into mysql-trunk 5.6.1-m4 (revid:alik@ibmvm-20100804080001-bny5271e65xo34ig) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (merge vers: 5.1.49) (pib:18)
[4 Aug 2010 8:15] Bugs System 
Pushed into mysql-trunk 5.6.1-m4 (revid:alik@ibmvm-20100804080001-bny5271e65xo34ig) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (merge vers: 5.1.49) (pib:18)
[4 Aug 2010 8:16] Bugs System 
Pushed into mysql-trunk 5.6.1-m4 (revid:alik@ibmvm-20100804080001-bny5271e65xo34ig) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (merge vers: 5.1.49) (pib:18)
[4 Aug 2010 8:17] Bugs System 
Pushed into mysql-trunk 5.6.1-m4 (revid:alik@ibmvm-20100804080001-bny5271e65xo34ig) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (merge vers: 5.1.49) (pib:18)
[4 Aug 2010 8:26] Bugs System 
Pushed into mysql-trunk 5.6.1-m4 (revid:alik@ibmvm-20100804081533-c1d3rbipo9e8rt1s) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (merge vers: 5.1.49) (pib:18)
[4 Aug 2010 9:00] Bugs System 
Pushed into mysql-trunk 5.6.1-m4 (revid:alik@ibmvm-20100804081533-c1d3rbipo9e8rt1s) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (merge vers: 5.1.49) (pib:20)
[4 Aug 2010 9:05] Bugs System 
Pushed into mysql-next-mr (revid:alik@ibmvm-20100804081630-ntapn8bf9pko9vj3) (version source revid:marko.makela@oracle.com-20100629125518-m3am4ia1ffjr0d0j) (pib:20)
[11 Aug 2010 11:59] Alexander Nozdrin 
Nothing was pushed wrt this bug.
Another CS mentions it:
"Disable UNIV_DEBUG when WITH_DEBUG is enabled

It causes lots of failures due to
Bug#54861 Additional connections not handled properly in mtr --embedded
should be re-enabled when that bug is resolved"
[1 Sep 2010 13:48] Bugs System 
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/117336

3197 Alexey Botchkov	2010-09-01
      Bug#54861      Additional connections not handled properly in mtr --embedded
              When in embedded-serve mode, mysqltest tried to run '--send' commands in the separate thread.
              That upsets some engines (InnoDB particularly) as the transaction has to be executed in the same
              thread completely. So i implemented some different approach. So we create one separate thread for
              each connection and execute all the queries of this connection inside it. Looks even simpler than it was
              for me.
      
      per-file comments:
        client/mysqltest.cc
      Bug#54861      Additional connections not handled properly in mtr --embedded
              Now the connection has one running connection_thread() attached. And sends all the
              query and read-result requests to it.
[8 Sep 2010 14:55] Vasil Dimov 
Hello, when is this going to be pushed?
[9 Sep 2010 7:54] Alexey Botchkov 
mysql-5.5-bugfixing
[9 Sep 2010 8:08] Vasil Dimov 
Thanks!
[2 Oct 2010 18:12] Bugs System 
Pushed into mysql-trunk 5.6.1-m4 (revid:alexander.nozdrin@oracle.com-20101002180948-852x1cuv7c6i85ea) (version source revid:alexander.nozdrin@oracle.com-20101002180857-an32jpuwzemsp4f2) (merge vers: 5.6.1-m4) (pib:21)
[2 Oct 2010 18:15] Bugs System 
Pushed into mysql-next-mr (revid:alexander.nozdrin@oracle.com-20101002181053-6iotvl26uurcoryp) (version source revid:alexander.nozdrin@oracle.com-20101002180917-h0n62akupm3z20nt) (pib:21)
[2 Oct 2010 18:16] Bugs System 
Pushed into mysql-5.5 5.5.7-rc (revid:alexander.nozdrin@oracle.com-20101002180831-590ka2tuit9qoxbb) (version source revid:alexander.nozdrin@oracle.com-20101002180831-590ka2tuit9qoxbb) (merge vers: 5.5.7-rc) (pib:21)
[3 Oct 2010 1:38] Paul DuBois 
Changes to test suite. No changelog entry needed.