Bug #46193 crash when accessing tables after enabling innodb_force_recovery option

• Submitted: 15 Jul 2009 7:28
• Modified: 18 Jun 2010 22:37
• Reporter: Martin K
• Status: Closed
• Category: MySQL Server: InnoDB storage engine
• Severity: S1 (Critical)
• Version: >=5.1.31, 5.1.37, 5.1.42, 5.4.4
• OS: Any (win xp, fc8)
• Assigned to: Satya B
• CPU Architecture: Any
• Tags: innodb_force_recovery, regression

[15 Jul 2009 7:28] Martin K

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...

[15 Jul 2009 8:42] Sveta Smirnova

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.

[15 Jul 2009 12:27] Martin K

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

[15 Jul 2009 21:20] MySQL Verification Team

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

[16 Jul 2009 5:59] Martin K

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

Thanks Martin

[16 Jul 2009 20:01] MySQL Verification Team

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()

[16 Jul 2009 20:14] MySQL Verification Team

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

[24 Jul 2009 12:59] MySQL Verification Team

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

[22 Jan 2010 9:57] 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/97827

3332 Sergey Vojtovich	2010-01-22
      Applying InnoDB snapshot, fixes BUG#46193.
      
      Detailed revision comments:
      
      r6424 | marko | 2010-01-12 12:22:19 +0200 (Tue, 12 Jan 2010) | 16 lines
      branches/5.1: In innobase_initialize_autoinc(), do not attempt to read
      the maximum auto-increment value from the table if
      innodb_force_recovery is set to at least 4, so that writes are
      disabled. (Bug #46193)
      
      innobase_get_int_col_max_value(): Move the function definition before
      ha_innobase::innobase_initialize_autoinc(), because that function now
      calls this function.
      
      ha_innobase::innobase_initialize_autoinc(): Change the return type to
      void.  Do not attempt to read the maximum auto-increment value from
      the table if innodb_force_recovery is set to at least 4.  Issue
      ER_AUTOINC_READ_FAILED to the client when the auto-increment value
      cannot be read.
      
      rb://144 by Sunny, revised by Marko

[22 Jan 2010 13:44] Sergey Vojtovich

Fixed in 5.1, built-in InnoDB.

[4 Feb 2010 10:18] Bugs System

Pushed into 5.1.44 (revid:[e-mail]-20100204101444-2j32mhqroo0iiio6) (version source revid:[e-mail]-20100125025505-zqa9v2mgdcfza0v6) (merge vers: 5.1.43) (pib:16)

[5 Feb 2010 11:45] Bugs System

Pushed into mysql-next-mr (revid:[e-mail]-20100204063540-9czpdmpixi3iw2yb) (version source revid:[e-mail]-20100130201057-zm9nj1sy0xpz1ohp) (pib:16)

[5 Feb 2010 11:52] Bugs System

Pushed into 6.0.14-alpha (revid:[e-mail]-20100205113942-oqovjy0eoqbarn7i) (version source revid:[e-mail]-20100204064210-ljwanqvrjs83s1gq) (merge vers: 6.0.14-alpha) (pib:16)

[5 Feb 2010 11:58] Bugs System

Pushed into 5.5.2-m2 (revid:[e-mail]-20100203172258-1n5dsotny40yufxw) (version source revid:[e-mail]-20100130182921-uva9w0cxpxqeylbf) (merge vers: 5.5.2-m2) (pib:16)

[11 Feb 2010 5:26] James Day

Paul,

"If innodb_force_recovery is set to 4 or higher MySQL could crash when opening an InnoDB table with an autoincrement column. Versions 5.1.31 and later were affected."

[2 Mar 2010 0:51] Paul DuBois

Noted in 5.1.44, 5.5.2, 6.0.14 changelogs.

[12 Mar 2010 14:16] Bugs System

Pushed into 5.1.44-ndb-7.0.14 (revid:[e-mail]-20100312135944-t0z8s1da2orvl66x) (version source revid:[e-mail]-20100312115609-woou0te4a6s4ae9y) (merge vers: 5.1.44-ndb-7.0.14) (pib:16)

[12 Mar 2010 14:32] Bugs System

Pushed into 5.1.44-ndb-6.2.19 (revid:[e-mail]-20100312134846-tuqhd9w3tv4xgl3d) (version source revid:[e-mail]-20100312060623-mx6407w2vx76h3by) (merge vers: 5.1.44-ndb-6.2.19) (pib:16)

[12 Mar 2010 14:48] Bugs System

Pushed into 5.1.44-ndb-6.3.33 (revid:[e-mail]-20100312135724-xcw8vw2lu3mijrhn) (version source revid:[e-mail]-20100312103652-snkltsd197l7q2yg) (merge vers: 5.1.44-ndb-6.3.33) (pib:16)

[6 Apr 2010 8:00] Bugs System

Pushed into 5.1.46 (revid:[e-mail]-20100405111026-7kz1p8qlzglqgfmu) (version source revid:[e-mail]-20100401151005-c6re90vdvutln15d) (merge vers: 5.1.46) (pib:16)

[6 Apr 2010 13:14] Jon Stephens

Already documented in 5.1.44. Closed.

[9 Apr 2010 14:49] Paul DuBois

Noted in 5.1.43sp1 changelog.

[12 Apr 2010 10:16] Bugs System

Pushed into 5.1.47 (revid:[e-mail]-20100412101220-adgau1r18kwgthps) (version source revid:[e-mail]-20100412101220-adgau1r18kwgthps) (merge vers: 5.1.47) (pib:16)

[28 Apr 2010 4:15] James Day

The fix for this is in the InnoDB Plugin version 1.0.7 which was included with MySQL 5.1.46.

[5 May 2010 15:21] Bugs System

Pushed into 5.1.47 (revid:[e-mail]-20100505145753-ivlt4hclbrjy8eye) (version source revid:[e-mail]-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)

[6 May 2010 17:45] Paul DuBois

Push resulted from incorporation of InnoDB tree. No changes pertinent to this bug.
Re-closing.

[28 May 2010 5:51] Bugs System

Pushed into mysql-next-mr (revid:[e-mail]-20100524190136-egaq7e8zgkwb9aqi) (version source revid:[e-mail]-20100331130613-8ja7n0vh36a80457) (pib:16)

[28 May 2010 6:20] Bugs System

Pushed into 6.0.14-alpha (revid:[e-mail]-20100524190941-nuudpx60if25wsvx) (version source revid:[e-mail]-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)

[28 May 2010 6:48] Bugs System

Pushed into 5.5.5-m3 (revid:[e-mail]-20100524185725-c8k5q7v60i5nix3t) (version source revid:[e-mail]-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)

[29 May 2010 2:52] Paul DuBois

Push resulted from incorporation of InnoDB tree. No changes pertinent to this bug.
Re-closing.

[15 Jun 2010 8:16] Bugs System

Pushed into 5.5.5-m3 (revid:[e-mail]-20100615080459-smuswd9ooeywcxuc) (version source revid:[e-mail]-20100415070122-1nxji8ym4mao13ao) (merge vers: 5.1.47) (pib:16)

[15 Jun 2010 8:32] Bugs System

Pushed into mysql-next-mr (revid:[e-mail]-20100615080558-cw01bzdqr1bdmmec) (version source revid:[e-mail]-20100415070122-1nxji8ym4mao13ao) (pib:16)

[17 Jun 2010 11:52] Bugs System

Pushed into 5.1.47-ndb-7.0.16 (revid:[e-mail]-20100617114014-bva0dy24yyd67697) (version source revid:[e-mail]-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)

[17 Jun 2010 12:29] Bugs System

Pushed into 5.1.47-ndb-6.2.19 (revid:[e-mail]-20100617115448-idrbic6gbki37h1c) (version source revid:[e-mail]-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)

[17 Jun 2010 13:17] Bugs System

Pushed into 5.1.47-ndb-6.3.35 (revid:[e-mail]-20100617114611-61aqbb52j752y116) (version source revid:[e-mail]-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)