Bug #93196 DD crashes on assert if ha_commit_trans() returns error

Submitted: 14 Nov 2018 14:35 Modified: 12 Feb 2019 20:22
Reporter: Vlad Lesin Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: DDL Severity:S6 (Debug Builds)
Version:8.0 OS:Any
Assigned to: CPU Architecture:Any

[14 Nov 2018 14:35] Vlad Lesin
Description:
If we look into trans_commit_implicit() function, we will see that thd->dd_client()->commit_modified_objects() is being invoked ignoring the error, returned by ha_commit_trans(). As a result, the following crash takes place on debug build if ha_commit_trans() returns error:

=====
#0  0x00007ffff5ca1428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
#1  0x00007ffff5ca302a in __GI_abort () at abort.c:89
#2  0x00007ffff5c99bd7 in __assert_fail_base (fmt=<optimized out>, assertion=assertion@entry=0x5a8b9a3 "stored_object == nullptr", 
    file=file@entry=0x5a8b518 "./sql/dd/impl/cache/dictionary_client.cc", line=line@entry=2648, 
    function=function@entry=0x5a90f80 <void dd::cache::Dictionary_client::remove_uncommitted_objects<dd::Abstract_table>(bool)::__PRETTY_FUNCTION__> "void dd::cache::Dictionary_client::remove_uncommitted_objects(bool) [with T = dd::Abstract_table]") at assert.c:92
#3  0x00007ffff5c99c82 in __GI___assert_fail (assertion=0x5a8b9a3 "stored_object == nullptr", 
    file=0x5a8b518 "./sql/dd/impl/cache/dictionary_client.cc", line=2648, 
    function=0x5a90f80 <void dd::cache::Dictionary_client::remove_uncommitted_objects<dd::Abstract_table>(bool)::__PRETTY_FUNCTION__> "void dd::cache::Dictionary_client::remove_uncommitted_objects(bool) [with T = dd::Abstract_table]") at assert.c:101
#4  0x000000000424504c in dd::cache::Dictionary_client::remove_uncommitted_objects<dd::Abstract_table> (this=0x7fff3c01c1c0, commit_to_shared_cache=true)
    at ./sql/dd/impl/cache/dictionary_client.cc:2648
#5  0x000000000423fc7d in dd::cache::Dictionary_client::commit_modified_objects (this=0x7fff3c01c1c0)
    at ./sql/dd/impl/cache/dictionary_client.cc:2741
#6  0x000000000315c3b2 in trans_commit_implicit (thd=0x7fff3c1182a0, ignore_global_read_lock=false) at ./sql/transaction.cc:349
#7  0x00000000030991b3 in mysql_rm_table_no_locks (thd=0x7fff3c1182a0, tables=0x7fff3c18f528, if_exists=false, drop_temporary=false, drop_database=false, 
    dropped_non_atomic_flag=0x7fffe89fdf11, post_ddl_htons=0x7fffe89fdf80, fk_invalidator=0x7fffe89fdfb0, safe_to_release_mdl=0x7fffe89fdf40)
    at ./sql/sql_table.cc:3179
#8  0x0000000003094b82 in mysql_rm_table (thd=0x7fff3c1182a0, tables=0x7fff3c18f528, if_exists=false, drop_temporary=false)
    at ./sql/sql_table.cc:1467
#9  0x0000000002ff89ec in mysql_execute_command (thd=0x7fff3c1182a0, first_level=true) at ./sql/sql_parse.cc:3336
#10 0x0000000002ffe4c4 in mysql_parse (thd=0x7fff3c1182a0, parser_state=0x7fffe89ff380, force_primary_storage_engine=false)
    at ./sql/sql_parse.cc:5041
#11 0x0000000002ff3e0c in dispatch_command (thd=0x7fff3c1182a0, com_data=0x7fffe89ffcf0, command=COM_QUERY)
    at ./sql/sql_parse.cc:1687
#12 0x0000000002ff246e in do_command (thd=0x7fff3c1182a0) at ./sql/sql_parse.cc:1260
#13 0x000000000319fe59 in handle_connection (arg=0x7037f60) at ./sql/conn_handler/connection_handler_per_thread.cc:308
#14 0x0000000004c263d0 in pfs_spawn_thread (arg=0x72ce310) at ./storage/perfschema/pfs.cc:2836
#15 0x00007ffff79be6ba in start_thread (arg=0x7fffe8a00700) at pthread_create.c:333
#16 0x00007ffff5d7341d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
=====

How to repeat:
Execute the following sequence of queries on debug build:

CREATE TABLE t_innodb(a INT NOT NULL, KEY (a)) ENGINE=InnoDB;
SET @@GLOBAL.DEBUG= '+d,simulate_failure_in_before_commit_hook';
DROP TABLE t_innodb;

Suggested fix:
Check the result of ha_commit_trans() at the end of trans_commit_implicit() function and invoke thd->dd_client()->rollback_modified_objects() on error.
[14 Nov 2018 15:50] MySQL Verification Team
Thank you for the bug report.

Enter password:
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 8
Server version: 8.0.14-debug Source distribution BUILD: 2018-NOV-11

Copyright (c) 2000, 2018, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql 8.0 > create database test;
Query OK, 1 row affected (0,43 sec)

mysql 8.0 > use test
Database changed
mysql 8.0 > CREATE TABLE t_innodb(a INT NOT NULL, KEY (a)) ENGINE=InnoDB;
DROP TABLE t_innodb;
Query OK, 0 rows affected (2,37 sec)

mysql 8.0 > SET @@GLOBAL.DEBUG= '+d,simulate_failure_in_before_commit_hook';
Query OK, 0 rows affected (0,00 sec)

mysql 8.0 > DROP TABLE t_innodb;
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql 8.0 >

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 = 7f0a8c1a7cd8 thread_stack 0x46000
/home/miguel/dbsd/8.0/bin/mysqld(my_print_stacktrace(unsigned char*, unsigned long)+0x55) [0x55f5c9f2ab19]
/home/miguel/dbsd/8.0/bin/mysqld(handle_fatal_signal+0x3f2) [0x55f5c8be2dc3]
/usr/lib/libpthread.so.0(+0x123c0) [0x7f0ab9c083c0]
/usr/lib/libc.so.6(gsignal+0x10f) [0x7f0ab917fd7f]
/usr/lib/libc.so.6(abort+0x125) [0x7f0ab916a672]
/usr/lib/libc.so.6(+0x22548) [0x7f0ab916a548]
/usr/lib/libc.so.6(+0x30396) [0x7f0ab9178396]
/home/miguel/dbsd/8.0/bin/mysqld(void dd::cache::Dictionary_client::remove_uncommitted_objects<dd::Abstract_table>(bool)+0x1e1) [0x55f5c9c700f5]
/home/miguel/dbsd/8.0/bin/mysqld(dd::cache::Dictionary_client::commit_modified_objects()+0x1d) [0x55f5c9c6b31f]
/home/miguel/dbsd/8.0/bin/mysqld(trans_commit_implicit(THD*, bool)+0x368) [0x55f5c8b89957]
/home/miguel/dbsd/8.0/bin/mysqld(mysql_rm_table_no_locks(THD*, TABLE_LIST*, bool, bool, bool, bool*, std::set<handlerton*, std::less<handlerton*>, std::allocator<handlerton*> >*, Foreign_key_parents_invalidator*, std::vector<MDL_ticket*, std::allocator<MDL_ticket*> >*)+0x103f) [0x55f5c8ac3325]
/home/miguel/dbsd/8.0/bin/mysqld(mysql_rm_table(THD*, TABLE_LIST*, bool, bool)+0x57f) [0x55f5c8abec3e]
/home/miguel/dbsd/8.0/bin/mysqld(mysql_execute_command(THD*, bool)+0x24a1) [0x55f5c8a230f3]
/home/miguel/dbsd/8.0/bin/mysqld(mysql_parse(THD*, Parser_state*, bool)+0x696) [0x55f5c8a28be9]
/home/miguel/dbsd/8.0/bin/mysqld(dispatch_command(THD*, COM_DATA const*, enum_server_command)+0x14c9) [0x55f5c8a1e411]
/home/miguel/dbsd/8.0/bin/mysqld(do_command(THD*)+0x487) [0x55f5c8a1c974]
/home/miguel/dbsd/8.0/bin/mysqld(+0x2e2e47b) [0x55f5c8bce47b]
/home/miguel/dbsd/8.0/bin/mysqld(+0x48782f4) [0x55f5ca6182f4]
/usr/lib/libpthread.so.0(+0x7a9d) [0x7f0ab9bfda9d]
/usr/lib/libc.so.6(clone+0x43) [0x7f0ab9243b23]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f0a24190b68): DROP TABLE t_innodb
Connection ID (thread ID): 8
Status: NOT_KILLED
[14 Nov 2018 18:41] Vlad Lesin
BTW, the same issue is in trans_commit() function. For example, the following queries sequence:

CREATE DATABASE test1;
SET @@GLOBAL.DEBUG= '+d,simulate_failure_in_before_commit_hook';
DROP DATABASE test;

leads to the following crash:

===
#0  __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:62
62      ../sysdeps/unix/sysv/linux/pthread_kill.c: No such file or directory.
[Current thread is 1 (Thread 0x7f21ccd6d700 (LWP 26036))]
#0  __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:62
#1  0x0000000004530a69 in my_write_core (sig=6) at ./mysys/stacktrace.cc:278
#2  0x00000000031b430d in handle_fatal_signal (sig=6) at ./sql/signal_handler.cc:249
#3  <signal handler called>
#4  0x00007f21d86d9428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54
#5  0x00007f21d86db02a in __GI_abort () at abort.c:89
#6  0x00007f21d86d1bd7 in __assert_fail_base (fmt=<optimized out>, assertion=assertion@entry=0x5a8b9a3 "stored_object == nullptr", file=file@entry=0x5a8b518 "./sql/dd/impl/cache/dictionary_client.cc", line=line@entry=2648, function=function@entry=0x5a93860 <void dd::cache::Dictionary_client::remove_uncommitted_objects<dd::Schema>(bool)::__PRETTY_FUNCTION__> "void dd::cache::Dictionary_client::remove_uncommitted_objects(bool) [with T = dd::Schema]") at assert.c:92
#7  0x00007f21d86d1c82 in __GI___assert_fail (assertion=0x5a8b9a3 "stored_object == nullptr", file=0x5a8b518 "./sql/dd/impl/cache/dictionary_client.cc", line=2648, function=0x5a93860 <void dd::cache::Dictionary_client::remove_uncommitted_objects<dd::Schema>(bool)::__PRETTY_FUNCTION__> "void dd::cache::Dictionary_client::remove_uncommitted_objects(bool) [with T = dd::Schema]") at assert.c:101
#8  0x000000000424a9a0 in dd::cache::Dictionary_client::remove_uncommitted_objects<dd::Schema> (this=0x7f212c01c1c0, commit_to_shared_cache=true) at ./sql/dd/impl/cache/dictionary_client.cc:2648
#9  0x000000000423fc8e in dd::cache::Dictionary_client::commit_modified_objects (this=0x7f212c01c1c0) at ./sql/dd/impl/cache/dictionary_client.cc:2742
#10 0x000000000315bfe0 in trans_commit (thd=0x7f212c027680, ignore_global_read_lock=false) at ./sql/transaction.cc:281
#11 0x0000000002f82b48 in mysql_rm_db (thd=0x7f212c027680, db=..., if_exists=false) at ./sql/sql_db.cc:643
#12 0x0000000002ff932e in mysql_execute_command (thd=0x7f212c027680, first_level=true) at ./sql/sql_parse.cc:3504
#13 0x0000000002ffe4c4 in mysql_parse (thd=0x7f212c027680, parser_state=0x7f21ccd6c380, force_primary_storage_engine=false) at ./sql/sql_parse.cc:5041
#14 0x0000000002ff3e0c in dispatch_command (thd=0x7f212c027680, com_data=0x7f21ccd6ccf0, command=COM_QUERY) at ./sql/sql_parse.cc:1687
#15 0x0000000002ff246e in do_command (thd=0x7f212c027680) at ./sql/sql_parse.cc:1260
#16 0x000000000319fe59 in handle_connection (arg=0x768dcf0) at ./sql/conn_handler/connection_handler_per_thread.cc:308
#17 0x0000000004c263d0 in pfs_spawn_thread (arg=0x7660270) at ./storage/perfschema/pfs.cc:2836
#18 0x00007f21da3f66ba in start_thread (arg=0x7f21ccd6d700) at pthread_create.c:333
#19 0x00007f21d87ab41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109
===
[12 Feb 2019 20:22] Paul DuBois
Posted by developer:
 
Fixed in 8.0.16.

The data dictionary cache could become out of sync with data
dictionary contents due to failure to check the result of a
transaction-related operation.

Portions of this website are copyright © 2001, 2002 The PHP Group

Page generated in 0.053 sec. using MySQL 8.4.7-u6-cloud

Timestamp references displayed by the system are UTC.
Content reproduced on this site is the property of the respective copyright holders.
It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.