Bug #69641 Crash when enabling innodb_table_monitor (assertion: ib_table->stat_initialized)
Submitted: 1 Jul 2013 21:48 Modified: 31 Mar 2014 16:33
Reporter: Daniël van Eeden (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S1 (Critical)
Version:5.6.12 OS:Any
Assigned to: CPU Architecture:Any
Tags: crash

[1 Jul 2013 21:48] Daniël van Eeden
Description:
Crash when enabling innodb_table_monitor and subsequently selecting from a table without primary key (table was completely read before).

2013-07-01 23:42:35 7f58009d4700  InnoDB: Assertion failure in thread 140015944156928 in file ha_innodb.cc line 10802
InnoDB: Failing assertion: ib_table->stat_initialized
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
21:42:35 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=1
max_threads=151
thread_count=1
connection_count=1
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 68221 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x3139ec0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7f58009d3e20 thread_stack 0x40000
/home/dveeden/opt/mysql/5.6.12/bin/mysqld(my_print_stacktrace+0x35)[0x8f8e95]
/home/dveeden/opt/mysql/5.6.12/bin/mysqld(handle_fatal_signal+0x3e8)[0x66cba8]
/lib/x86_64-linux-gnu/libpthread.so.0(+0xfbd0)[0x7f582e02abd0]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x37)[0x7f582cc25037]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7f582cc28698]
/home/dveeden/opt/mysql/5.6.12/bin/mysqld[0x91c35f]
/home/dveeden/opt/mysql/5.6.12/bin/mysqld(_ZN4JOIN8optimizeEv+0x1103)[0x85f7d3]
/home/dveeden/opt/mysql/5.6.12/bin/mysqld[0x709544]
/home/dveeden/opt/mysql/5.6.12/bin/mysqld(_Z12mysql_selectP3THDP10TABLE_LISTjR4ListI4ItemEPS4_P10SQL_I_ListI8st_orderESB_S7_yP13select_resultP18st_select_lex_unitP13st_select_lex+0xbc)[0x7098cc]
/home/dveeden/opt/mysql/5.6.12/bin/mysqld(_Z13handle_selectP3THDP13select_resultm+0x175)[0x709ad5]
/home/dveeden/opt/mysql/5.6.12/bin/mysqld[0x6e6919]
/home/dveeden/opt/mysql/5.6.12/bin/mysqld(_Z21mysql_execute_commandP3THD+0x3426)[0x6eae76]
/home/dveeden/opt/mysql/5.6.12/bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x318)[0x6ee718]
/home/dveeden/opt/mysql/5.6.12/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x827)[0x6ef037]
/home/dveeden/opt/mysql/5.6.12/bin/mysqld(_Z10do_commandP3THD+0xd7)[0x6f0477]
/home/dveeden/opt/mysql/5.6.12/bin/mysqld(_Z24do_handle_one_connectionP3THD+0x116)[0x6ba786]
/home/dveeden/opt/mysql/5.6.12/bin/mysqld(handle_one_connection+0x45)[0x6ba865]
/home/dveeden/opt/mysql/5.6.12/bin/mysqld(pfs_spawn_thread+0x13b)[0xabfb3b]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7f8e)[0x7f582e022f8e]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f582cce7e1d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f57e4005050): SELECT * FROM innodb_table_wo_primary_key
Connection ID (thread ID): 1
Status: NOT_KILLED

The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.

How to repeat:
CREATE TABLE innodb_table_wo_primary_key (id int, name varchar(200));
SELECT * FROM innodb_table_wo_primary_key;
CREATE TABLE innodb_table_monitor (a INT) ENGINE=INNODB;
SELECT * FROM innodb_table_wo_primary_key;
[1 Jul 2013 22:03] Daniël van Eeden
It might be nessesary to run analyze table on all tables first (mysqlcheck -A -a)
[1 Jul 2013 22:17] MySQL Verification Team
I was able to repeat it after a few tries!

InnoDB: Assertion failure in thread 12156 in file ha_innodb.cc line 10802
InnoDB: Failing assertion: ib_table->stat_initialized
InnoDB: We intentionally generate a memory trap.

mysqld-debug.exe!my_sigabrt_handler()[my_thr_init.c:499]
mysqld-debug.exe!raise()[winsig.c:586]
mysqld-debug.exe!abort()[abort.c:74]
mysqld-debug.exe!ha_innobase::info_low()[ha_innodb.cc:10802]
mysqld-debug.exe!ha_innobase::info()[ha_innodb.cc:11095]
mysqld-debug.exe!TABLE_LIST::fetch_number_of_rows()[table.cc:6005]
mysqld-debug.exe!make_join_statistics()[sql_optimizer.cc:3169]
mysqld-debug.exe!JOIN::optimize()[sql_optimizer.cc:381]
mysqld-debug.exe!mysql_execute_select()[sql_select.cc:1086]
mysqld-debug.exe!mysql_select()[sql_select.cc:1221]
mysqld-debug.exe!handle_select()[sql_select.cc:110]
mysqld-debug.exe!execute_sqlcom_select()[sql_parse.cc:5046]
mysqld-debug.exe!mysql_execute_command()[sql_parse.cc:2604]
mysqld-debug.exe!mysql_parse()[sql_parse.cc:6187]
mysqld-debug.exe!dispatch_command()[sql_parse.cc:1334]
mysqld-debug.exe!do_command()[sql_parse.cc:1036]
mysqld-debug.exe!do_handle_one_connection()[sql_connect.cc:977]
mysqld-debug.exe!handle_one_connection()[sql_connect.cc:893]
mysqld-debug.exe!pfs_spawn_thread()[pfs.cc:1855]
mysqld-debug.exe!pthread_start()[my_winthread.c:61]
mysqld-debug.exe!_callthreadstartex()[threadex.c:314]
mysqld-debug.exe!_threadstartex()[threadex.c:297]
[1 Jul 2013 22:44] MySQL Verification Team
If you enable the innodb_table_monitor during a random ddl test, it also crashes after a while...

mysqld.exe!my_sigabrt_handler()[my_thr_init.c:498]
mysqld.exe!raise()[winsig.c:586]
mysqld.exe!abort()[abort.c:74]
mysqld.exe!ha_innobase::info_low()[ha_innodb.cc:10812]
mysqld.exe!ha_innobase::info()[ha_innodb.cc:11095]
mysqld.exe!copy_data_between_tables()[sql_table.cc:8610]
mysqld.exe!mysql_alter_table()[sql_table.cc:8252]
mysqld.exe!Sql_cmd_alter_table::execute()[sql_alter.cc:313]
mysqld.exe!mysql_execute_command()[sql_parse.cc:4898]
mysqld.exe!mysql_parse()[sql_parse.cc:6187]
mysqld.exe!dispatch_command()[sql_parse.cc:1337]
mysqld.exe!do_command()[sql_parse.cc:1036]
mysqld.exe!do_handle_one_connection()[sql_connect.cc:977]
mysqld.exe!handle_one_connection()[sql_connect.cc:893]
mysqld.exe!pfs_spawn_thread()[pfs.cc:1855]
mysqld.exe!pthread_start()[my_winthread.c:61]
mysqld.exe!_callthreadstartex()[threadex.c:314]
mysqld.exe!_threadstartex()[threadex.c:292]
[19 Nov 2013 12:10] Daniël van Eeden
Add Crash tag
[17 Dec 2013 16:10] MySQL Verification Team
Testcase from http://bugs.mysql.com/bug.php?id=71163
---------
drop procedure if exists p1;
delimiter $
create procedure p1()
begin
  declare continue handler for sqlexception begin end;
  repeat
    if rand()*10000 >9999 then drop table if exists innodb_table_monitor; select 'dropped'; end if;
	if rand()*100 <20   then create table if not exists innodb_table_monitor(a int)engine=innodb; select 'created'; end if;
	if rand()>0.5       then drop table if exists t1; end if;
	if rand()>0.5       then create table if not exists t1(a int primary key)partition by key(a) partitions 5; end if;
	if rand()>0.1       then replace into t1 values(rand()*100); end if;
	if rand()>0.1       then select * from information_schema.INNODB_SYS_TABLESTATS where name like '%t1%'; end if;
	if(rand()>0.1       then analyze table t1; end if;
	
  until 1=2 end repeat;

end $
delimiter ;
call p1();
----------
[31 Mar 2014 16:33] Daniel Price
Fixed as of 5.6.18, 5.7.5 and here's the changelog entry:

Enabling the "InnoDB" Table Monitor would result in a
"ib_table->stat_initialized" assertion failure. 

Thank you for the bug report.
[2 Jun 2014 13:55] Laurynas Biveinis
$ bzr log -r 5864
------------------------------------------------------------
revno: 5864
committer: Aditya A <aditya.a@oracle.com>
branch nick: mysql-5.6
timestamp: Tue 2014-03-18 14:59:24 +0530
message:
  Bug#17039528	CRASH WHEN ENABLING INNODB_TABLE_MONITOR
  		(ASSERTION: IB_TABLE->STAT_INITIALIZED)
  
  PROBLEM
  -------
  
  While saving the statistics to the disk there is
  an assert to check if statistics have been 
  initialized or not,which was failing. The reason 
  for this failure was that the variable 
  table->stat_initialized was set as FALSE by 
  dict_table_print() which is called by background 
  server monitor thread. 
  
  void dict_table_print()
  {
    if(!table->stat_initialized)
    {
      dict_stats_update_transient(table);
    }	
  
    /* print the statistics */
      
    table->stat_initialized = FALSE;
  }
  
  If the table statistics are not initialized then
  dict_table_print() will update the the statistics
  using dict_stats_update_transient() which sets 
  table->stat_initialized = TRUE,print the statistics
  and then set table->stat_initialized = FALSE to 
  bring it back to its original state. This is wrong 
  because we are doing it without prior knowledge of 
  state of stat_initialized variable (It might be 
  TRUE from the beginning). Since the the variable
  table->stat_initialized is not a protected member,
  it can be set TRUE at any time.
  
  FIX
  ---
   
  We do not need to set table->stat_initialized = FALSE.
  The print function just need to print the statistics
  and call dict_stats_update_transient() only when 
  table->stat_initialized is FALSE. 
  
  [Aprooved by Vasil #rb4944]