MySQL Bugs: #56541: Assertion table->db_stat failed in sql_base.cc::open_table() during I

Bug #56541	Assertion table->db_stat failed in sql_base.cc::open_table() during I_S queries
Submitted:	3 Sep 2010 15:05	Modified:	19 Apr 2011 17:26
Reporter:	John Embretsen	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Information schema	Severity:	S1 (Critical)
Version:	5.1.48	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	RQG

Description:
While executing a SHOW TABLE STATUS query as well as other background load, MySQL server asserted as follows:

-----------------

mysqld.exe: ready for connections.
Version: '5.1.51-debug-log'  socket: ''  port: 10020  Source distribution
Assertion failed: table->db_stat, file .\sql_base.cc, line 2804

This application has requested the Runtime to terminate it in an unusual way.
Please contact the application's support team for more information.

This application has requested the Runtime to terminate it in an unusual way.
Please contact the application's support team for more information.
100903 17:39:59 - mysqld got exception 0x80000003 ;

-----------------

Backtrace from error log:

00444D73    mysqld.exe!my_sigabrt_handler()[mysqld.cc:2086]
0040932B    mysqld.exe!raise()[winsig.c:590]
004118A5    mysqld.exe!abort()[abort.c:71]
008BF077    mysqld.exe!_wassert()[assert.c:346]
0052D344    mysqld.exe!open_table()[sql_base.cc:2804]
005313C8    mysqld.exe!open_tables()[sql_base.cc:4621]
00532A80    mysqld.exe!open_normal_and_derived_tables()[sql_base.cc:5089]
004BE7F4    mysqld.exe!get_all_tables()[sql_show.cc:3491]
004CBB68    mysqld.exe!get_schema_tables_result()[sql_show.cc:6175]
00637592    mysqld.exe!JOIN::exec()[sql_select.cc:1846]
00639732    mysqld.exe!mysql_select()[sql_select.cc:2519]
00632355    mysqld.exe!handle_select()[sql_select.cc:269]
005B87AF    mysqld.exe!execute_sqlcom_select()[sql_parse.cc:5127]
005B0B31    mysqld.exe!mysql_execute_command()[sql_parse.cc:2292]
005BAB8F    mysqld.exe!mysql_parse()[sql_parse.cc:6051]
005AE765    mysqld.exe!dispatch_command()[sql_parse.cc:1260]
005ADD12    mysqld.exe!do_command()[sql_parse.cc:888]
004A7548    mysqld.exe!handle_one_connection()[sql_connect.cc:1136]
008E64D6    mysqld.exe!pthread_start()[my_winthread.c:85]
008C2303    mysqld.exe!_callthreadstart()[thread.c:293]
008C2299    mysqld.exe!_threadstart()[thread.c:277]
77E6482F    kernel32.dll!GetModuleHandleA()

This is a regression introduced some time between 5.1.47 and 5.1.51. Reproduced on Windows 2003 against latest mysql-5.1-bugteam, revid davi.arnaut@oracle.com-20100824134845-h459kwlylg6h745v.

This may or may not be related to Bug#56540, reported against 5.5.6 and higher-level development branches but with seemingly slightly different symptoms (yet detected using the same RQG test).

How to repeat:
No regular test case available yet. Reproducible using the Random Query Generator, available at Launchpad (bzr branch lp:randgen).

RQG command line:

perl runall.pl 
  --grammar=conf/runtime/information_schema.yy 
  --queries=100000 
  --threads=10 
  --duration=300 
  --reporters=Deadlock,ErrorLog,Backtrace,Shutdown 
  --basedir=%CODE% 
  --mysqld=--log-output=file 
  --mysqld=--loose-table-lock-wait-timeout=1 
  --mysqld=--loose-lock-wait-timeout=1 
  --mysqld=--loose-innodb-lock-wait-timeout=1

where %CODE% is an environment variable pointing to the location of the MySQL installation directory.

Full test output with stacktraces from CDB dump (mysql-5.1-bugteam).

Attachment: bug56541_log_rqg_info_schema_5.1-bugteam.txt (text/plain), 94.70 KiB.

Two simultaneous client threads (RQG option --threads=2) is enough to reproduce the issue. Also seen on Unix, hence not limited to Windows, and not likely the exact same cause as Bug#56540 (which does not seem to occur on Unix).

In one situation the 2 queries executed at the time of the assertion were:

SELECT * 
FROM (test . `D` AS table1 
  STRAIGHT_JOIN INFORMATION_SCHEMA . `PARTITIONS` AS table2 
  ON ( table2 . `PARTITION_DESCRIPTION` = table1 . `col_time_nokey` ) ) 
WHERE NOT (NOT table1 . `col_time_nokey` = 8 
  AND table1 . `col_date_key` >= table1 . `col_varchar_key`)   
ORDER BY table1 . `col_date_nokey` , 
         table2 . `TABLE_NAME`
;

and

CREATE TRIGGER i 
  BEFORE INSERT ON `D` 
  FOR EACH ROW BEGIN 
    INSERT INTO `DD` SELECT * FROM `B` LIMIT 0 ; 
  END
;

or 

DROP TRIGGER IF EXISTS x;

so it seems SHOW TABLE STATUS is not a required property of this bug (but perhaps a STRAIGHT_JOIN query is). Synopsis modified accordingly.

on Fedora X86_64

Attachment: core56541.txt (text/plain), 33.38 KiB.

Thank you for the bug report.

I ran the bzrfind tool on mysql-5.1-bugteam in order to find the cause of this regression. The tool replied:

# Regression source: mattias.jonsson@sun.com-20100317141041-o1629etmqbe8mpbq

$ bzr log -v -r revid:mattias.jonsson@sun.com-20100317141041-o1629etmqbe8mpbq
------------------------------------------------------------
revno: 3351.44.1
committer: Mattias Jonsson <mattias.jonsson@sun.com>
branch nick: b50561-51-bugteam_name_lock_fix
timestamp: Wed 2010-03-17 15:10:41 +0100
message:
  Bug#50561: ALTER PARTITIONS does not have adequate lock, breaks with
  concurrent I_S query

  There were two problem:
  1) MYSQL_LOCK_IGNORE_FLUSH also ignored name locks
  2) there was a race between abort_and_upgrade_locks and
     alter_close_tables
     (i.e. remove_table_from_cache and
      close_data_files_and_morph_locks)

  Which allowed the table to be opened with MYSQL_LOCK_IGNORE_FLUSH flag
  resulting in renaming a partition that was already in use,
  which could cause the table to be unusable.

  Solution was to not allow IGNORE_FLUSH to skip waiting for
  a named locked table.

  And to not release the LOCK_open mutex between the
  calls to remove_table_from_cache and
  close_data_files_and_morph_locks by merging the functions
  abort_and_upgrade_locks and alter_close_tables.
added:
  mysql-test/suite/parts/r/partition_debug_sync_innodb.result
  mysql-test/suite/parts/t/partition_debug_sync_innodb-master.opt
  mysql-test/suite/parts/t/partition_debug_sync_innodb.test
modified:
  sql/authors.h
  sql/ha_partition.cc
  sql/mysql_priv.h
  sql/sql_base.cc
  sql/sql_partition.cc
  sql/sql_show.cc

This was pushed to mysql-5.1-bugteam 2010-05-10.

Noted in 5.1.57, 5.5.12, 5.6.3 changelogs.

An assertion could be raised if a statement that required a name lock
on a table (for example, DROP TRIGGER) executed concurrently with an
INFORMATION_SCHEMA query that also used the table.

CHANGESET - http://lists.mysql.com/commits/134121

Correction: This was fixed only in 5.1.57.