MySQL Bugs: #46193: crash when accessing tables after enabling innodb_force

Bug #46193	crash when accessing tables after enabling innodb_force_recovery option
Submitted:	15 Jul 9:28	Modified:	6 Aug 2:00
Reporter:	Martin K
Status:	In review
Category:	Server: InnoDB	Severity:	S1 (Critical)
Version:	>=5.1.31, 5.1.37, 5.4.4	OS:	Any (win xp, fc8)
Assigned to:	Sunny Bains	Target Version:	5.1+
Tags:	regression, innodb_force_recovery
Triage:	Triaged: D1 (Critical) / R1 (None/Negligible) / E1 (None/Negligible)

Description:
I used MySQL more than 4 months and it works very well. But now, when I try SELECT from
table I obtained windows (Visual Studio Just-In-Time Debugger) error message An
unhandled...

Details from MySQL daemon:

C:\Program Files\MySQL\MySQL Server 5.1\bin>mysqld --standalone --console
090715  9:16:09  InnoDB: Started; log sequence number 0 98271
InnoDB: !!! innodb_force_recovery is set to 4 !!!
090715  9:16:09 [Note] Event Scheduler: Loaded 0 events
090715  9:16:09 [Note] mysqld: ready for connections.
Version: '5.1.35-community'  socket: ''  port: 3306  MySQL Community Server (GPL
)
090715  9:16:14 - mysqld got exception 0xc0000005 ;
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=26214400
read_buffer_size=65536
max_used_connections=1
max_threads=100
threads_connected=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 58231 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x2cc5c88
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...
006AA763    mysqld.exe!ha_innobase::innobase_get_index()[ha_innodb.cc:4473]
006AE3B7    mysqld.exe!ha_innobase::innobase_initialize_autoinc()[ha_innodb.cc:2
371]
006AE75F    mysqld.exe!ha_innobase::open()[ha_innodb.cc:2601]
00443C36    mysqld.exe!handler::ha_open()[handler.cc:2047]
005BFEAB    mysqld.exe!open_table_from_share()[table.cc:1882]
005264E7    mysqld.exe!open_unireg_entry()[sql_base.cc:3910]
00529B5D    mysqld.exe!open_table()[sql_base.cc:2907]
0052AA32    mysqld.exe!open_tables()[sql_base.cc:4570]
0052AF8A    mysqld.exe!open_and_lock_tables_derived()[sql_base.cc:4976]
00553EF2    mysqld.exe!execute_sqlcom_select()[sql_parse.cc:4974]
005551A0    mysqld.exe!mysql_execute_command()[sql_parse.cc:2211]
0055A8C3    mysqld.exe!mysql_parse()[sql_parse.cc:5933]
0055B3B3    mysqld.exe!dispatch_command()[sql_parse.cc:1218]
0055C1B7    mysqld.exe!do_command()[sql_parse.cc:861]
005DF511    mysqld.exe!handle_one_connection()[sql_connect.cc:1115]
0064588B    mysqld.exe!pthread_start()[my_winthread.c:85]
0072ADD3    mysqld.exe!_callthreadstart()[thread.c:293]
FCB0E900
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 02D45AD0=select * from testfw
thd->thread_id=1
thd->killed=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.

Martin

How to repeat:
Perform some select queries...

Thank you for the report.

Please provide output of SHOW CREATE TABLE testfw and SHOW TABLE STATUS LIKE 'testfw'.
Also please check in you run mysql_upgrade last time when you upgraded.

Hi,
this is output of SHOW CREATE TABLE testfw:
+--------+----------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
---------------------------------------------------------------------+
| Table  | Create Table

                                                                     |
+--------+----------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
---------------------------------------------------------------------+
| testfw | CREATE TABLE `testfw` (
  `idtestfw` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `title` varchar(100) COLLATE cp1250_czech_cs DEFAULT NULL,
  `note` text COLLATE cp1250_czech_cs,
  `checked` varchar(1) COLLATE cp1250_czech_cs DEFAULT NULL,
  `traffic` int(10) unsigned DEFAULT NULL,
  `password` varchar(100) COLLATE cp1250_czech_cs DEFAULT NULL,
  `image` varchar(100) COLLATE cp1250_czech_cs DEFAULT NULL,
  `moto` varchar(20) COLLATE cp1250_czech_cs DEFAULT NULL,
  `idcustomer` int(10) unsigned DEFAULT NULL,
  `dateinsert` date DEFAULT NULL,
  `idrecord` int(10) unsigned DEFAULT NULL,
  PRIMARY KEY (`idtestfw`)
) ENGINE=InnoDB AUTO_INCREMENT=3 DEFAULT CHARSET=cp1250 COLLATE=cp1250_czech_cs
|
+--------+----------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
---------------------------------------------------------------------+
1 row in set (0.11 sec)

and this is output of SHOW TABLE STATUS LIKE 'testfw':
+--------+--------+---------+------------+------+----------------+-------------+
-----------------+--------------+-----------+----------------+------------------
---+-------------+------------+-----------------+----------+----------------+---
------+
| Name   | Engine | Version | Row_format | Rows | Avg_row_length | Data_length |
 Max_data_length | Index_length | Data_free | Auto_increment | Create_time
   | Update_time | Check_time | Collation       | Checksum | Create_options | Co
mment |
+--------+--------+---------+------------+------+----------------+-------------+
-----------------+--------------+-----------+----------------+------------------
---+-------------+------------+-----------------+----------+----------------+---
------+
| testfw | InnoDB |      10 | Compact    |    2 |           8192 |       16384 |
               0 |            0 |   4194304 |              3 | 2009-07-13 10:53:
32 | NULL        | NULL       | cp1250_czech_cs |     NULL |                |
      |
+--------+--------+---------+------------+------+----------------+-------------+
-----------------+--------------+-----------+----------------+------------------
---+-------------+------------+-----------------+----------+----------------+---
------+
1 row in set (0.00 sec)

When I try run mysql_upgrade.exe, then I obtain this same error as I described in this
bug report "an unhandled...".

Output from command line window:
C:\Program Files\MySQL\MySQL Server 5.1\bin>mysql_upgrade.exe
Looking for 'mysql.exe' as: C:\Program Files\MySQL\MySQL Server 5.1\bin\mysql.ex
e
Looking for 'mysqlcheck.exe' as: C:\Program Files\MySQL\MySQL Server 5.1\bin\mys
qlcheck.exe
Running 'mysqlcheck'...
Running 'mysqlcheck'...
C:\Program Files\MySQL\MySQL Server 5.1\bin\mysqlcheck.exe: Got error: 2013: Los
t connection to MySQL server during query when executing 'CHECK TABLE ...  FOR U
PGRADE'
martin.mk_login                                    OK
FATAL ERROR: Upgrade failed

Martin

Could you please provide your my.ini file and that table it was created with which server
version?. Thanks in advance.

Hi, 
there is link http://source.php5.cz/My_and_table.zip. 
I'm not sure, if you thought that table.

Thanks Martin

testcase:
----------
start server normally, create a table:
create table t1(id int auto_increment primary key)engine=innodb;

shutdown server, start it with --innodb-force-recovery=4 
select * from t1;

crashes.
stack from 5.1.37:

mysqld.exe!ha_innobase::innobase_get_index()[ha_innodb.cc:4506]
mysqld.exe!ha_innobase::innobase_initialize_autoinc()[ha_innodb.cc:2404]
mysqld.exe!ha_innobase::open()[ha_innodb.cc:2632]
mysqld.exe!handler::ha_open()[handler.cc:2055]
mysqld.exe!open_table_from_share()[table.cc:1882]
mysqld.exe!open_unireg_entry()[sql_base.cc:3910]
mysqld.exe!open_table()[sql_base.cc:2907]
mysqld.exe!open_tables()[sql_base.cc:4571]
mysqld.exe!open_and_lock_tables_derived()[sql_base.cc:4977]
mysqld.exe!open_and_lock_tables()[mysql_priv.h:1555]
mysqld.exe!execute_sqlcom_select()[sql_parse.cc:4978]
mysqld.exe!mysql_execute_command()[sql_parse.cc:2208]
mysqld.exe!mysql_parse()[sql_parse.cc:5933]
mysqld.exe!dispatch_command()[sql_parse.cc:1213]
mysqld.exe!do_command()[sql_parse.cc:854]
mysqld.exe!handle_one_connection()[sql_connect.cc:1127]
mysqld.exe!pthread_start()[my_winthread.c:85]
mysqld.exe!_callthreadstart()[thread.c:293]
mysqld.exe!_threadstart()[thread.c:277]
kernel32.dll!FlsSetValue()

this bug is introduced in 5.1.31.  how this hasn't been noticed yet is suprising.

Thanks Sunny, your patch indeed stops the crashes at least on my 5.1.37 test system.