Bug #19366 consistent_snapshot.test fails
Submitted: 26 Apr 2006 9:44 Modified: 4 May 2006 8:45
Reporter: Ingo Strüwing Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S2 (Serious)
Version:4.1.19-BK OS:Linux (Debian Linux kernel 2.6.16)
Assigned to: Osku Salerma CPU Architecture:Any

[26 Apr 2006 9:44] Ingo Strüwing
Description:
consistent_snapshot            [ fail ]

Errors are (from /home/mytest/mysql-4.1-test/tmp/test1/mysql-test/var/log/mysqltest-time) :
mysqltest: At line 15: query 'create table t1 (a int) engine=innodb' failed: 2013: Lost connection to MySQL server during query
(the last lines may be the most important ones)

After this, all other tests fail like this:

constraints                    [ fail ]

Errors are (from /home/mytest/mysql-4.1-test/tmp/test1/mysql-test/var/log/mysqltest-time) :
mysqltest: At line 6: query 'drop table if exists t1' failed: 1051: Unknown table 't1'
(the last lines may be the most important ones)

The stack backtrace looks like follows:

#0  0xb7d579d3 in pthread_kill () from /lib/tls/libpthread.so.0
(gdb) bt
#0  0xb7d579d3 in pthread_kill () from /lib/tls/libpthread.so.0
#1  0x082ad699 in write_core (sig=11) at stacktrace.c:220
#2  0x08199149 in handle_segfault (sig=11) at mysqld.cc:2006
#3  <signal handler called>
#4  0x08378994 in dict_table_get_n_user_cols (table=0xb6bda468) at dict0dict.ic:96
#5  0x083a6217 in row_create_table_for_mysql (table=0xb6bda468, trx=0xb6bdac68) at row0mysql.c:1515
#6  0x0825150a in create_table_def (trx=0xb6bdac68, form=0xb2604480, table_name=0xb2601410 "test/t1", path_of_temp_table=0x0) at ha_innodb.cc:3738
#7  0x08251b1b in ha_innobase::create (this=0x8e75de0, name=0xb2605ad0 "./test/t1.frm", form=0xb2604480, create_info=0x8e76e98) at ha_innodb.cc:3961
#8  0x0823b271 in ha_create_table (name=0xb2605ad0 "./test/t1.frm", create_info=0x8e76e98, update_create_info=false) at handler.cc:1331
#9  0x08226d07 in rea_create_table (thd=0x8e76ad0, file_name=0xb2605ad0 "./test/t1.frm", db=0x8e43298 "test", table=0x8e90f28 "t1", create_info=0x8e76e98, create_fields=@0x8e76dd4, keys=0, key_info=0x8e91130) at unireg.cc:246
#10 0x0826d77b in mysql_create_table (thd=0x8e76ad0, db=0x8e43298 "test", table_name=0x8e90f28 "t1", create_info=0x8e76e98, fields=@0x8e76dd4, keys=@0x8e76dc8, tmp_table=false, select_field_count=0) at sql_table.cc:1469
#11 0x081b13c5 in mysql_execute_command (thd=0x8e76ad0) at sql_parse.cc:2539
#12 0x081b609a in mysql_parse (thd=0x8e76ad0, inBuf=0x8e90ed8 "create table t1 (a int) engine=innodb", length=37) at sql_parse.cc:4334
#13 0x081ae9a5 in dispatch_command (command=COM_QUERY, thd=0x8e76ad0, packet=0x8e88e79 "create table t1 (a int) engine=innodb", packet_length=38) at sql_parse.cc:1502
#14 0x081ae20d in do_command (thd=0x8e76ad0) at sql_parse.cc:1315
#15 0x081ad5c0 in handle_one_connection (arg=0x8e76ad0) at sql_parse.cc:1047
#16 0xb7d54ced in start_thread () from /lib/tls/libpthread.so.0
#17 0xb7c7dd7e in clone () from /lib/tls/libc.so.6

Hence putting it in InnoDB category.

How to repeat:
BUILD/compile-pentium-debug-max
cd mysql-test
./mysql-test-run consistent_snapshot
[26 Apr 2006 11:57] Valeriy Kravchuk
Thank you for a bug report. Verified just as described with 4.1.19-BK-debug (ChangeSet@1.2458.10.2, 2006-04-26 11:15:09+04:00) on SuSE 9.3:

Starting Tests

TEST                            RESULT
-------------------------------------------------------
consistent_snapshot            [ fail ]

Errors are (from /home/openxs/dbs/4.1/mysql-test/var/log/mysqltest-time) :
mysqltest: At line 15: query 'create table t1 (a int) engine=innodb' failed: 201
3: Lost connection to MySQL server during query
(the last lines may be the most important ones)

Aborting: consistent_snapshot failed in default mode. To continue, re-run with '--force'.

Ending Tests
Shutting-down MySQL daemon

Non-debug version of server passes this test OK.
[27 Apr 2006 14:19] Elliot Murphy
Reproduced with current BK source on AMD64 Ubuntu. Ran consistent_snapshot, got crash. Here is the backtrace:
(gdb) bt
#0  0x00002aaaab2a3807 in pthread_kill () from /lib/libpthread.so.0
#1  0x00000000006ae030 in write_core (sig=11) at stacktrace.c:220
#2  0x000000000058039b in handle_segfault (sig=11) at mysqld.cc:2006
#3  <signal handler called>
#4  0x000000000078d72d in dict_table_get_n_user_cols (table=0x2aaaacb7e4b8)
    at dict0dict.ic:96
#5  0x00000000007bccb3 in row_create_table_for_mysql (table=0x2aaaacb7e4b8,
    trx=0x2aaaacb828b8) at row0mysql.c:1515
#6  0x000000000064e800 in create_table_def (trx=0x2aaaacb828b8,
    form=0x4391ba90, table_name=0x439189d0 "test/t1", path_of_temp_table=0x0)
    at ha_innodb.cc:3738
#7  0x000000000064ee53 in ha_innobase::create (this=0x17550d8,
    name=0x4391d3c0 "./test/t1.frm", form=0x4391ba90,
    create_info=0x2aaaadb4b3c8) at ha_innodb.cc:3961
#8  0x0000000000636b48 in ha_create_table (name=0x4391d3c0 "./test/t1.frm",
    create_info=0x2aaaadb4b3c8, update_create_info=false) at handler.cc:1331
#9  0x00000000006211d7 in rea_create_table (thd=0x2aaaadb4aca8,
    file_name=0x4391d3c0 "./test/t1.frm", db=0x171d9f8 "test",
    table=0x173a370 "t1", create_info=0x2aaaadb4b3c8,
    create_fields=@0x2aaaadb4b250, keys=0, key_info=0x173a690)
    at unireg.cc:246
#10 0x000000000066be16 in mysql_create_table (thd=0x2aaaadb4aca8,
    db=0x171d9f8 "test", table_name=0x173a370 "t1",
    create_info=0x2aaaadb4b3c8, fields=@0x2aaaadb4b250, keys=@0x2aaaadb4b238,
    tmp_table=false, select_field_count=0) at sql_table.cc:1469
#11 0x000000000059bd78 in mysql_execute_command (thd=0x2aaaadb4aca8)
    at sql_parse.cc:2559
#12 0x00000000005a00f2 in mysql_parse (thd=0x2aaaadb4aca8,
    inBuf=0x173a308 "create table t1 (a int) engine=innodb", length=37)
    at sql_parse.cc:4351
#13 0x00000000005a0b24 in dispatch_command (command=COM_QUERY,
    thd=0x2aaaadb4aca8,
    packet=0x2aaaadb55319 "create table t1 (a int) engine=innodb",
    packet_length=38) at sql_parse.cc:1519
---Type <return> to continue, or q <return> to quit---
#14 0x00000000005a2158 in do_command (thd=0x2aaaadb4aca8) at sql_parse.cc:1322
#15 0x00000000005a2519 in handle_one_connection (arg=0x2aaaadb4aca8)
    at sql_parse.cc:1054
#16 0x00002aaaab2a00fa in start_thread () from /lib/libpthread.so.0
#17 0x00002aaaab845ce2 in clone () from /lib/libc.so.6
#18 0x0000000000000000 in ?? ()
[29 Apr 2006 16:07] Ingo Strüwing
Made it a showstopper as it hinders me to push the fix for showstopper Bug#10405. I tried to disable consistent_snapshot.test, but then create_select_tmp.test crashes the server. This happens also in InnoDB code: dict_table_get_n_user_cols().

A vague guess is that the problem might have to do with:
ChangeSet@1.2453.40.1, 2006-04-20 23:09:49+04:00, aivanov@mysql.com
  Applied innodb-4.1-ss22 snapshot.
[2 May 2006 2:08] Heikki Tuuri
Marko,

please look at this.

Heikki
[2 May 2006 8:51] Marko Mäkelä
Could you please attach the relevant snip of the error log? It should contain the failing InnoDB assertion.
[2 May 2006 9:13] Ingo Strüwing
060429 18:48:36InnoDB: Assertion failure in thread 2992851888 in file ../include/dict0dict.ic line 96
InnoDB: Failing assertion: table->cached
[2 May 2006 9:35] Ingo Strüwing
Ooops, accidentally changed status to open.
[2 May 2006 9:36] Marko Mäkelä
./mysql-test-run consistent_snapshot
Logging: ./mysql-test-run consistent_snapshot
Installing Test Databases
Removing Stale Files
Installing Master Databases
running  ../sql/mysqld --no-defaults --bootstrap --skip-grant-tables     --basedir=. --datadir=./var/master-data --skip-innodb --skip-ndbcluster --skip-bdb --language=../sql/share/english/ --character-sets-dir=../sql/share/charsets/
Installing Master Databases 1
running  ../sql/mysqld --no-defaults --bootstrap --skip-grant-tables     --basedir=. --datadir=./var/master-data1 --skip-innodb --skip-ndbcluster --skip-bdb  --language=../sql/share/english/ --character-sets-dir=../sql/share/charsets/
Installing Slave Databases
running  ../sql/mysqld --no-defaults --bootstrap --skip-grant-tables     --basedir=. --datadir=./var/slave-data --skip-innodb --skip-ndbcluster --skip-bdb     --language=../sql/share/english/ --character-sets-dir=../sql/share/charsets/
Manager disabled, skipping manager start.
Starting ndbcluster
Starting ndbd
Starting ndbd
Waiting for started...
NDBT_ProgramExit: 0 - OK
Connected to Management Server at: localhost:9350
Cluster Configuration
---------------------
[ndbd(NDB)]     2 node(s)
id=1    @127.0.0.1  (Version: 4.1.20, Nodegroup: 0, Master)
id=2    @127.0.0.1  (Version: 4.1.20, Nodegroup: 0)

[ndb_mgmd(MGM)] 1 node(s)
id=3    @127.0.0.1  (Version: 4.1.20)

[mysqld(API)]   4 node(s)
id=4 (not connected, accepting connect from any host)
id=5 (not connected, accepting connect from any host)
id=6 (not connected, accepting connect from any host)
id=7 (not connected, accepting connect from any host)

Loading Standard Test Databases
Starting Tests

TEST                            RESULT
-------------------------------------------------------
consistent_snapshot            [ pass ]
-------------------------------------------------------

Ending Tests
Shutting-down MySQL daemon

Master shutdown finished
Slave shutdown finished
All 1 tests were successful.
[2 May 2006 15:11] Heikki Tuuri
The bug is that Osku's new code from April 20, 2006 calls the following before the table has been added to the dictionary cache.

Fix: remove the debug assertion ut_ad(table->cached);

This bug is probably in 5.0 and 5.1, too.

/************************************************************************
Gets the number of system columns in a table in the dictionary cache. */
UNIV_INLINE
ulint
dict_table_get_n_sys_cols(
/*======================*/
                                /* out: number of system (e.g.,
                                ROW_ID) columns of a table */
        dict_table_t*   table __attribute__((unused)))  /* in: table */
{
        ut_ad(table);
        ut_ad(table->magic_n == DICT_TABLE_MAGIC_N);
        ut_ad(table->cached);

        return(DATA_N_SYS_COLS);
}

Regards,

Heikki
[2 May 2006 15:12] Heikki Tuuri
Assign this to Osku.
[2 May 2006 15:16] Heikki Tuuri
The bug has been fixed in 5.1 already. But it is present in the latest svn version of 5.0.
[3 May 2006 6:27] Osku Salerma
Fixed in InnoDB's 4.1 and 5.0 repositories, new snapshots sent to MySQL.
[3 May 2006 11:17] 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/5867
[3 May 2006 11:25] Heikki Tuuri
I approve Osku's patches.
[3 May 2006 12:24] 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/5879
[3 May 2006 14:30] Alexander Ivanov
Pushed into 4.1.20 and 5.0.22.
[4 May 2006 8:45] MC Brown
Noted in 4.1 and 5.0 changelogs.
[5 May 2006 20:28] Paul DuBois
This was a test-case-only problem. No changelog entries needed.