Bug #48782 On lock wait timeout, CREATE INDEX (creating primary key) attempts DROP TABLE

• Submitted: 15 Nov 2009 18:58
• Modified: 20 Jun 2010 17:31
• Reporter: Shane Bester (Platinum Quality Contributor)
• Status: Closed
• Category: MySQL Server: InnoDB Plugin storage engine
• Severity: S1 (Critical)
• Version: 5.1.40, 5.1.42-bzr
• OS: Any
• Assigned to: Satya B
• CPU Architecture: Any

[15 Nov 2009 18:58] Shane Bester

Description:
running concurrent alter table causes innodb to assert:

InnoDB: The InnoDB memory heap is disabled
InnoDB: Mutexes and rw_locks use Windows interlocked functions.
091115 20:43:14  InnoDB: highest supported file format is Barracuda.
091115 20:43:14 InnoDB Plugin 1.0.4 started; log sequence number 4548740
091115 20:43:14 [Note] mysqld: ready for connections.
Version: '5.1.40-enterprise-gpl-advanced'  socket: ''  port: 3306  MySQL Enterprise Server - Advanced Edition (GPL)
091115 20:43:46  InnoDB: Assertion failure in thread 3924 in file .\row\row0merge.c line 2259
InnoDB: Failing assertion: table->n_mysql_handles_opened == 0
InnoDB: We intentionally generate a memory trap.

1800AC3CD    ha_innodb_plugin.dll!row_merge_drop_table()[row0merge.c:2259]
18009C27C    ha_innodb_plugin.dll!ha_innodb::add_index()[handler0alter.cc:881]
1400E9EAF    mysqld.exe!mysql_alter_table()[sql_table.cc:7202]
14006B2D4    mysqld.exe!mysql_execute_command()[sql_parse.cc:2891]
14006E966    mysqld.exe!mysql_parse()[sql_parse.cc:5967]
14006F4FA    mysqld.exe!dispatch_command()[sql_parse.cc:1226]
140070167    mysqld.exe!do_command()[sql_parse.cc:865]
1400968B7    mysqld.exe!handle_one_connection()[sql_connect.cc:1127]
1403169D5    mysqld.exe!pthread_start()[my_winthread.c:85]
1402E0B07    mysqld.exe!_callthreadstart()[thread.c:295]
1402E0BD5    mysqld.exe!_threadstart()[thread.c:275]
077D6B6CA    kernel32.dll!BaseThreadStart()
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 00000000033B5470=alter ignore table t3 add primary key(id)

How to repeat:
start mysqld with: --skip-grant-tables --skip-name-resolve --innodb_flush_log_at_trx_commit=0  --ignore-builtin-innodb 
--plugin-load=innodb=ha_innodb_plugin.dll 
--innodb_lock_wait_timeout=1 --innodb_buffer_pool_size=100M

(s/dll/so/ for linux).

compile and run the attached .c testcase

[15 Nov 2009 19:03] MySQL Verification Team

testcase, see top of file for user, password, host, gcc options..

Attachment: bug48782.c (text/x-csrc), 7.75 KiB.

[15 Nov 2009 20:25] Valeriy Kravchuk

Verified just as described with recent 5.1.42 from bzr (and InnoDB plugin 1.0.5 as a result) on Mac OS X:

091115 22:21:10 InnoDB Plugin 1.0.5 started; log sequence number 1991232
091115 22:21:10 [Note] Event Scheduler: Loaded 0 events
091115 22:21:10 [Note] /Users/openxs/dbs/5.1/libexec/mysqld: ready for connections.
Version: '5.1.42-debug'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution
091115 22:21:15  InnoDB: Assertion failure in thread 2960855040 in file row/row0merge.c line 2418
InnoDB: Failing assertion: table->n_mysql_handles_opened == 0
InnoDB: We intentionally generate a memory trap.
...

[17 Nov 2009 14:16] Marko Mäkelä

Unfortunately, I am having hardware trouble and have to use a substitute working environment.
I can repeat this with 5.1.40+plugin. It seems that the error occurs during cleanup after an error. When the clustered index tree (primary key) is re-created, the table is copied. Somehow, the error cleanup code is attempting to drop t2 and not the temporary table t2#1, and t2 has indexed_table->n_mysql_handles_opened = 1.

[17 Nov 2009 14:44] Marko Mäkelä

The error is DB_LOCK_WAIT_TIMEOUT, and we have innodb_table==indexed_table in ha_innobase::add_index(). That should not be possible when new_primary holds.

[18 Nov 2009 8:33] Marko Mäkelä

If the first call to row_merge_lock_table() in ha_innobase::add_index() fails, indexed_table == innodb_table holds even if new_primary holds.  This change allows the test program to run into completion in my environment:

Index: handler0alter.cc
===================================================================
--- handler0alter.cc	(revision 6184)
+++ handler0alter.cc	(working copy)
@@ -882,7 +882,9 @@
 		/* fall through */
 	default:
 		if (new_primary) {
-			row_merge_drop_table(trx, indexed_table);
+			if (indexed_table != innodb_table) {
+				row_merge_drop_table(trx, indexed_table);
+			}
 		} else {
 			if (!dict_locked) {
 				row_mysql_lock_data_dictionary(trx);

[30 Nov 2009 13:13] 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/92088

3228 Satya B	2009-11-30
      Applying InnoDB Plugin 1.0.6 snapshot, part 8. Fixes BUG#48782
      
      applied revisions: r6185, r6186, r6189, r6194
      
      r6185 - only code changes incorporated, changesets which change
              innodb tests in the main mysql suite are discarded
      
      r61889 - Fixes BUG#48782
      
      Detailed revision comments:
      
      r6185 | marko | 2009-11-17 16:44:20 +0200 (Tue, 17 Nov 2009) | 16 lines
      branches/zip: Report duplicate table names
      to the client connection, not to the error log.  This change will allow
      innodb-index.test to be re-enabled.  It was previously disabled, because
      mysql-test-run does not like output in the error log.
      
      row_create_table_for_mysql(): Do not output anything to the error log
      when reporting DB_DUPLICATE_KEY.  Let the caller report the error.
      Add a TODO comment that the dict_table_t object is apparently not freed
      when an error occurs.
      
      create_table_def(): Convert InnoDB table names to the character set
      of the client connection for reporting.  Use my_error(ER_WRONG_COLUMN_NAME)
      for reporting reserved column names.  Report my_error(ER_TABLE_EXISTS_ERROR)
      when row_create_table_for_mysql() returns DB_DUPLICATE_KEY.
      
      rb://206
      r6186 | vasil | 2009-11-17 16:48:14 +0200 (Tue, 17 Nov 2009) | 4 lines
      branches/zip:
      
      Add ChangeLog entry for r6185.
      
      r6189 | marko | 2009-11-18 11:36:18 +0200 (Wed, 18 Nov 2009) | 5 lines
      branches/zip: ha_innobase::add_index(): When creating the primary key
      and the table is being locked by another transaction,
      do not attempt to drop the table. (Bug #48782)
      
      Approved by Sunny Bains over IM
      r6194 | vasil | 2009-11-19 09:24:45 +0200 (Thu, 19 Nov 2009) | 5 lines
      branches/zip:
      
      Increment version number from 1.0.5 to 1.0.6 since 1.0.5 was just released
      by MySQL and we will soon release 1.0.6.

[1 Dec 2009 10:15] Satya B

patch queued to mysql-5.1-bugteam storage/innodb_plugin only.

Will be merged to mysql-trunk.

[2 Dec 2009 8:05] Bugs System

Pushed into 5.1.42 (revid:[e-mail]-20091202080033-mndu4sxwx19lz2zs) (version source revid:[e-mail]-20091130131334-1mpwktuzq6xef1xr) (merge vers: 5.1.42) (pib:13)

[10 Dec 2009 1:54] Paul DuBois

Noted in 5.1.42 changelog.

Concurrent ALTER TABLE operations on an InnoDB table could raise an 
assertion. 

Setting to NDI pending push to 5.5.x+.

[16 Dec 2009 8:40] Bugs System

Pushed into 6.0.14-alpha (revid:[e-mail]-20091216083311-xorsasf5kopjxshf) (version source revid:[e-mail]-20091214191830-wznm8245ku8xo702) (merge vers: 6.0.14-alpha) (pib:14)

[16 Dec 2009 8:46] Bugs System

Pushed into 5.5.0-beta (revid:[e-mail]-20091216082430-s0gtzibcgkv4pqul) (version source revid:[e-mail]-20091202140050-nh3ebk6s3bziv8cb) (merge vers: 5.5.0-beta) (pib:14)

[16 Dec 2009 8:53] Bugs System

Pushed into mysql-next-mr (revid:[e-mail]-20091216083231-rp8ecpnvkkbhtb27) (version source revid:[e-mail]-20091212203859-fx4rx5uab47wwuzd) (merge vers: 5.6.0-beta) (pib:14)

[18 Dec 2009 1:34] Paul DuBois

Noted in 5.5.1, 6.0.14 changelogs.

[12 Mar 2010 14:13] 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:29] 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:44] 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)

[5 May 2010 15:17] 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:11] Paul DuBois

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

[28 May 2010 5:49] 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:19] 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:46] 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)

[30 May 2010 0:03] 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:33] 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:50] 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:28] 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:15] 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)