MySQL Bugs: #56137: Assertion `thd->lock == 0' failed on upgrading from 5.1.50 to 5.5.6

Bug #56137	Assertion `thd->lock == 0' failed on upgrading from 5.1.50 to 5.5.6
Submitted:	20 Aug 2010 8:12	Modified:	13 Nov 2010 16:44
Reporter:	Nirbhay Choubey	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server	Severity:	S3 (Non-critical)
Version:	5.5.6-m3-debug	OS:	Any
Assigned to:	Dmitry Lenev	CPU Architecture:	Any
Tags:	mysql-5.5, upgrade

Description:
mysql-5.5 crashes when upgraded from 5.1

./bin/mysql_upgrade --force --verbose --user=root --port=3306
Looking for 'mysql' as: ./bin/mysql
Looking for 'mysqlcheck' as: ./bin/mysqlcheck
Running 'mysqlcheck' with connection arguments: '--port=3306' 
Running 'mysqlcheck' with connection arguments: '--port=3306' 
mysql.columns_priv                                 OK
mysql.db                                           OK
mysql.event                                        OK
mysql.func                                         OK
mysql.general_log
Error    : You can't use locks with log tables.
status   : OK
mysql.help_category                                OK
mysql.help_keyword                                 OK
mysql.help_relation                                OK
mysql.help_topic                                   OK
mysql.host                                         OK
mysql.ndb_binlog_index                             OK
mysql.plugin                                       OK
mysql.proc                                         OK
mysql.procs_priv                                   OK
mysql.servers                                      OK
mysql.slow_log
Error    : You can't use locks with log tables.
status   : OK
mysql.tables_priv                                  OK
mysql.time_zone                                    OK
mysql.time_zone_leap_second                        OK
mysql.time_zone_name                               OK
mysql.time_zone_transition                         OK
mysql.time_zone_transition_type                    OK
mysql.user                                         OK
Running 'mysql_fix_privilege_tables'...
100820 13:26:51 [ERROR] Incorrect definition of table mysql.proc: expected column 'comment' at position 15 to have type text, found type char(64).
mysqld: /home/nirbhay/Project/mysql/repo/builds/source/mysql-5.5/sql/sql_base.cc:5448: bool lock_tables(THD*, TABLE_LIST*, uint, uint): Assertion `thd->lock == 0' failed.
100820 13:26:51 - mysqld got signal 6 ;

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 = 0xa6c4134c thread_stack 0x30000
./bin/mysqld(my_print_stacktrace+0x32)[0x861ada7]
./bin/mysqld(handle_segfault+0x2ab)[0x815fab6]
[0xb7744400]
/lib/tls/i686/cmov/libc.so.6(abort+0x182)[0xb7470a82]
/lib/tls/i686/cmov/libc.so.6(__assert_fail+0xf8)[0xb7466718]
./bin/mysqld(_Z11lock_tablesP3THDP10TABLE_LISTjj+0x108)[0x81a4937]
./bin/mysqld(_Z20open_and_lock_tablesP3THDP10TABLE_LISTbjP19Prelocking_strategy+0x10d)[0x81a454b]
./bin/mysqld(_Z20open_and_lock_tablesP3THDP10TABLE_LISTbj+0x40)[0x819a256]
./bin/mysqld(_ZN19Event_db_repository16open_event_tableEP3THD13thr_lock_typePP5TABLE+0xbf)[0x82a46d9]
./bin/mysqld(_ZN19Event_db_repository18drop_schema_eventsEP3THD19st_mysql_lex_string+0xa8)[0x82a54c8]
./bin/mysqld(_ZN6Events18drop_schema_eventsEP3THDPc+0xdd)[0x82a7b77]
./bin/mysqld(_Z11mysql_rm_dbP3THDPcbb+0x312)[0x81cb7b3]
./bin/mysqld(_Z21mysql_execute_commandP3THD+0x4ae2)[0x81eea5f]
./bin/mysqld(_ZN18Prepared_statement7executeEP6Stringb+0x42e)[0x8208ad6]
./bin/mysqld(_ZN18Prepared_statement12execute_loopEP6StringbPhS2_+0xf3)[0x8207de7]
./bin/mysqld(_Z22mysql_sql_stmt_executeP3THD+0x180)[0x82062ad]
./bin/mysqld(_Z21mysql_execute_commandP3THD+0xa02)[0x81ea97f]
./bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x1d8)[0x81f4c79]
./bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x9d1)[0x81e81e0]
./bin/mysqld(_Z10do_commandP3THD+0x242)[0x81e7614]
./bin/mysqld(_Z24do_handle_one_connectionP3THD+0x148)[0x82bd7d9]
./bin/mysqld(handle_one_connection+0x28)[0x82bd68a]
/lib/tls/i686/cmov/libpthread.so.0(+0x596e)[0xb771e96e]
/lib/tls/i686/cmov/libc.so.6(clone+0x5e)[0xb7510a4e]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0xb289198 = DROP DATABASE IF EXISTS performance_schema
thd->thread_id=4
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.
ERROR 2013 (HY000) at line 153: Lost connection to MySQL server during query
ERROR 2006 (HY000) at line 154: MySQL server has gone away

How to repeat:
Get a fresh build of mysql-5.5 + 5.1.50

Follow these stems :
1) cd 5.1.50 

2) mysql_install_db / 5.1.50       :   ./scripts/mysql_install_db --no-defaults --basedir=.

3) Start 5.1.50                    :   ./bin/mysqld --no-defaults --basedir=. &

4) Run mysqldump                   :   ./bin/mysqldump --all-databases --events --max_allowed_packet=256M --add-drop-table --flush-privileges --user=root --port=3306 --force > 5.1.50.dmp

5) shutdown 5.1.50                 :   ./bin/mysqladmin -u root -S /tmp/mysql.sock shut

6) cd 5.5.6-m3

7) mysql_install_db / 5.5.6-m3     :   ./scripts/mysql_install_db  --no-defaults --basedir=.

8) Start 5.5.6-m3                  :   ./bin/mysqld --no-defaults --basedir=. &

9) Load dump                       :   ./bin/mysql --protocol=tcp --user=root --port=3306 --execute="source 5.1.50.dmp" --force --max_allowed_packet=256M

10)Run mysql_upgrade command       :   ./bin/mysql_upgrade --force --verbose --user=root --port=3306
<<server crashes here>>

Thank you for the report.

I can not repeat described behavior with mysql-next-mr tree. Which tree do you use? How do you build it?

The newer server in the above upgrade scenario is a build from
mysql-5.5 tree using cmake/make.

cmake . -DWITH_DEBUG=1 -DWITH_DEBUG_FULL=1 -DWITH_INNODB_STORAGE_ENGINE=1

Thank you for the feedback.

Verified as described. To repeat it is required to repeat all steps as described. Starting server with --skip-grant-tables, then loading dump does not lead to crash.

Preliminary analysis shows that this bug was introduced by one of pre-requisite patches for bug#52044.

The issue still exists with the latest mysql-5.5 *debug* build (Ver : 5.5.7-m3 Linux )

However, this crash is not noticed with latest mysql-5.5 *non-debug* build.

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/117183

3124 Dmitry Lenev	2010-08-31
      Bug #56137 "Assertion `thd->lock == 0' failed on upgrading 
      from 5.1.50 to 5.5.6".
      
      Debug builds of server aborted due to assertion failure when
      one run DROP DATABASE statement on an installation which had
      outdated or corrupted mysql.proc table. Particularly this
      affected mysql_upgrade tool which was run as part of 5.1 to 
      5.5 upgrade.
      
      The problem was that sp_drop_db_routines(), which was invoked
      during dropping of database, could have returned without
      closing and unlocking mysql.proc table in case when this 
      table was not up-to-date with current server. As result 
      further attempt to open and lock mysql.event table, which
      was necessary to complete dropping of database, ended up 
      with assert.
      
      This patch solves this problem by ensuring that 
      sp_drop_db_routines() always closes mysql.proc table and
      releases metadata locks on it. This is achieved by changing
      open_proc_table_for_update() function to close tables and 
      release metadata locks acquired by it in case of failure.
      This step also makes behavior of the latter function 
      consistent with behavior of open_proc_table_for_read()/
      open_and_lock_tables().
      
      Test case for this bug was added to sp-destruct.test.

Patch approved.

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/117185

3124 Dmitry Lenev	2010-08-31
      Bug #56137 "Assertion `thd->lock == 0' failed on upgrading 
      from 5.1.50 to 5.5.6".
      
      Debug builds of the server aborted due to an assertion
      failure when DROP DATABASE statement was run on an
      installation which had outdated or corrupt mysql.proc table.
      Particularly this affected the mysql_upgrade tool which is
      run as part of 5.1 to 5.5 upgrade.
      
      The problem was that sp_drop_db_routines(), which was invoked
      during dropping of the database, could have returned without
      closing and unlocking mysql.proc table in cases when this
      table was not up-to-date with the current server. As a result
      further attempt to open and lock the mysql.event table, which
      was necessary to complete dropping of the database, ended up
      with an assert.
      
      This patch solves this problem by ensuring that
      sp_drop_db_routines() always closes mysql.proc table and
      releases metadata locks on it. This is achieved by changing
      open_proc_table_for_update() function to close tables and
      release metadata locks acquired by it in case of failure.
      This step also makes behavior of the latter function
      consistent with behavior of open_proc_table_for_read()/
      open_and_lock_tables().
      
      
      Test case for this bug was added to sp-destruct.test.

Queued into mysql-5.5-runtime tree.

Pushed into mysql-5.5 5.5.7-rc (revid:joerg@mysql.com-20100910184813-csdto6tk4nlogrsq) (version source revid:alik@sun.com-20100831135426-h5a4s2w6ih1d8q2x) (merge vers: 5.5.6-m3) (pib:21)

Pushed into mysql-trunk 5.6.1-m4 (revid:dlenev@mysql.com-20100913103627-p2oqplu42x1gv2bd) (version source revid:dlenev@mysql.com-20100913095811-ken3pb2y9n82suwv) (merge vers: 5.6.1-m4) (pib:21)

Pushed into mysql-next-mr (revid:dlenev@mysql.com-20100913121556-sfxqlpj9kbc28kaf) (version source revid:alik@sun.com-20100831135426-h5a4s2w6ih1d8q2x) (pib:21)

Noted in 5.5.7, 5.6.1 changelogs.

In debug builds, the server raised an assertion for DROP DATABASE in
installations that had an outdated or corrupted mysql.proc table. For
example, this affected mysql_upgrade when run as part of a MySQL 5.1 
to 5.5 upgrade.

Pushed into mysql-5.5 5.5.7-rc (revid:sunanda.menon@sun.com-20101109182959-otkxq8vo2dcd13la) (version source revid:marko.makela@oracle.com-20100824081003-v4ecy0tga99cpxw2) (merge vers: 5.1.50) (pib:21)

Pushed into mysql-trunk 5.6.99-m5 (revid:alexander.nozdrin@oracle.com-20101113155825-czmva9kg4n31anmu) (version source revid:marko.makela@oracle.com-20100824081003-v4ecy0tga99cpxw2) (merge vers: 5.1.50) (pib:21)

Pushed into mysql-next-mr (revid:alexander.nozdrin@oracle.com-20101113160336-atmtmfb3mzm4pz4i) (version source revid:marko.makela@oracle.com-20100824081003-v4ecy0tga99cpxw2) (pib:21)