Bug #32724 innodb_mysql.test fails randomly
Submitted: 26 Nov 2007 15:11 Modified: 20 Apr 2008 18:42
Reporter: Ingo Struewing Email Updates:
Status: Closed
Category:Tests: Engine Severity:S2 (Serious)
Version:5.1.23 OS:Mac OS X
Assigned to: Konstantin Osipov Target Version:5.1+
Tags: pbfail
Triage: D3 (Medium)

[26 Nov 2007 15:11] Ingo Struewing
Description:
main.innodb_mysql              [ fail ]

---
/Users/henry/pb/mysql-5.1-engines/277/mysql-5.1.23-rc-pb277/mysql-test/r/innodb_mysql.result	Mon
Nov 26 00:00:19 2007
+++
/Users/henry/pb/mysql-5.1-engines/277/mysql-5.1.23-rc-pb277/mysql-test/r/innodb_mysql.reject	Mon
Nov 26 02:15:02 2007
@@ -1504,8 +1504,6 @@
 1	init+con1
 # Switch to connection con2
 SELECT * FROM t1;
-a	b
-1	init+con1+con2
 # Switch to connection con1
 # 3. test for updated key column:
 TRUNCATE t1;

mysqltest: Result content mismatch

Disabling the test case. Please re-enable after fix.

How to repeat:
See pushbuild, for example
https://intranet.mysql.com/secure/pushbuild/showdir.pl?dir=mysql-5.1-engines
log
https://intranet.mysql.com/secure/pushbuild/getlog.pl?dir=mysql-5.1-engines&entry=istruewi...
See also
https://intranet.mysql.com/secure/pushbuild/xref.pl?startdate=&enddate=&dir=&plat=&testtyp...
[28 Nov 2007 10:24] Bugs System
Pushed into 6.0.4-alpha
[28 Nov 2007 10:26] Bugs System
Pushed into 5.1.23-rc
[10 Jan 2008 11:16] Vasil Dimov
Ingo, I cannot repeat this failure on the latest 5.1 BK tree:

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

main.innodb_mysql              [ pass ]          36773
-------------------------------------------------------
Stopping All Servers
All 1 tests were successful.
The servers were restarted 1 times
Spent 36.773 of 41 seconds executing testcases
--- cut ---

This is after applying the patch in Bug#33790 (which is unrelated).

Can you repeat the failure or give some more details on how to repeat it?

Can we enable this test?
[10 Jan 2008 16:15] Ingo Struewing
Since this did not happen on my machine, but only in pushbuild on powermacg5, I cannot
give more details on how to repeat it.

If you cannot repeat it any more on Mac OS X, then please set the bug report to "Can't
repeat" and re-enable the test case.

If it fails again, we can re-open the bug report, hopefully with more information.
[28 Mar 2008 17:25] Ingo Struewing
I re-checked the bug:

main.innodb_mysql              [ fail ]

mysqltest: In included file "./include/mix1.inc": At line 655: query 'LOCK TABLES t1
READ, t2 READ' failed with wrong errno 2013: 'Lost connection to MySQL server during
query', instead of 1205...

The result from queries just before the failure was:
...
drop table bug29807;
CREATE TABLE t1 (a INT) ENGINE=InnoDB;
CREATE TABLE t2 (a INT) ENGINE=InnoDB;
switch to connection c1
SET AUTOCOMMIT=0;
INSERT INTO t2 VALUES (1);
switch to connection c2
SET AUTOCOMMIT=0;
LOCK TABLES t1 READ, t2 READ;
ERROR HY000: Lost connection to MySQL server during query

backtrace:

#6  __assert_fail () from /lib/libc.so.6
#7  ha_commit_trans (thd=0x19a0388, all=true) at handler.cc:1040
#8  end_active_trans (thd=0x19a0388) at sql_parse.cc:123
#9  mysql_execute_command (thd=0x19a0388) at sql_parse.cc:3304
#10 mysql_parse (thd=0x19a0388, inBuf=0x19b19c8 "LOCK TABLES t1 READ, t2 READ",
length=28, found_semicolon=0x43909f10) at sql_parse.cc:5630
#11 dispatch_command (command=COM_QUERY, thd=0x19a0388, packet=0x19ad979 "LOCK TABLES t1
READ, t2 READ", packet_length=28) at sql_parse.cc:1121
#12 do_command (thd=0x19a0388) at sql_parse.cc:781
#13 handle_one_connection (arg=0x19a0388) at sql_connect.cc:1106

Failing line in ha_commit_trans():
1040   DBUG_ASSERT(thd->transaction.stmt.ha_list == NULL ||
1041               trans == &thd->transaction.stmt);

Variables:
thd->transaction.stmt.ha_list = (Ha_trx_info *) 0x19a1518
  {m_next = 0x0, m_ht = 0x1151ee8, m_flags = 0 '\0'}
trans = (THD_TRANS *) 0x19a16e0
  {no_2pc = false, ha_list = 0x19a1530, modified_non_trans_table = false}
&thd->transaction.stmt = (THD_TRANS *) 0x19a16f8
  {no_2pc = false, ha_list = 0x19a1518, modified_non_trans_table = false}

Lines from mysql_execute_command():

3276   case SQLCOM_LOCK_TABLES:
3277     unlock_locked_tables(thd);
3278     /* we must end the trasaction first, regardless of anything */
3279     if (end_active_trans(thd))
3280       goto error;
3281     if (check_table_access(thd, LOCK_TABLES_ACL | SELECT_ACL, all_tables,
3282                            UINT_MAX, FALSE))
3283       goto error;
3284     thd->in_lock_tables=1;
3285     thd->options|= OPTION_TABLE_LOCK;
3286 
3287     if (!(res= simple_open_n_lock_tables(thd, all_tables)))
3288     {
3289 #ifdef HAVE_QUERY_CACHE
3290       if (thd->variables.query_cache_wlock_invalidate)
3291         query_cache.invalidate_locked_for_write(first_table);
3292 #endif /*HAVE_QUERY_CACHE*/
3293       thd->locked_tables=thd->lock;
3294       thd->lock=0;
3295       my_ok(thd);
3296     }
3297     else
3298     {
3299       /* 
3300         Need to end the current transaction, so the storage engine (InnoDB)
3301         can free its locks if LOCK TABLES locked some tables before finding
3302         that it can't lock a table in its list
3303       */
3304 ==>   end_active_trans(thd);
3305       thd->options&= ~(OPTION_TABLE_LOCK);
3306     }
3307     thd->in_lock_tables=0;
3308     break;
3309   case SQLCOM_CREATE_DB:
[7 Apr 2008 11:42] 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/44986

ChangeSet@1.2586, 2008-04-07 15:42:32+04:00, kostja@dipika.(none) +2 -0
  A fix for Bug#32724 "innodb_mysql.test fails randomly".
  Enable back the disabled test case.
[20 Apr 2008 13:00] Bugs System
Pushed into 6.0.6-alpha
[20 Apr 2008 18:42] Konstantin Osipov
A test suite bug, needs no documentation.
[29 Apr 2008 3:03] 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/46164

ChangeSet@1.2572, 2008-04-29 00:03:19-03:00, davi@mysql.com +4 -0
  Backport kostja's fix for Bug#32724 "innodb_mysql.test fails randomly".
  Enable back the disabled test case.
[6 May 2008 0:29] Bugs System
Pushed into 5.1.25-rc
[6 May 2008 0:32] Bugs System
Pushed into 6.0.6-alpha
[20 May 2008 21:22] Bugs System
Pushed into 5.1.25-rc
[28 Jul 2008 16:53] Bugs System
Pushed into 5.1.25-rc  (revid:sp1r-kostja@bodhi.(none)-20080520073817-17550) (version
source revid:sp1r-kostja@bodhi.(none)-20080520073817-17550) (pib:3)