Bug #86825 mysql5.7 crash during create table
Submitted: 26 Jun 2017 7:45 Modified: 26 Jun 2017 9:38
Reporter: dennis gao Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server Severity:S3 (Non-critical)
Version:5.7.13 OS:Any
Assigned to: CPU Architecture:Any

[26 Jun 2017 7:45] dennis gao
Description:
The mysql crash during create table, the error log contains the following info:

Thread pointer: 0x7f30d9c16000
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 = 7f30da7bdde8 thread_stack 0x40000
/app/dbcluster/sgrdb/mysql/bin/sgrdbd(my_print_stacktrace+0x35)[0xf37585]
/app/dbcluster/sgrdb/mysql/bin/sgrdbd(handle_fatal_signal+0x4b4)[0x7c1924]
/lib64/libpthread.so.0[0x3e74a0f7e0]
/app/dbcluster/sgrdb/mysql/bin/sgrdbd(_Z32innobase_parse_hint_from_commentP3THDP12dict_table_tPK11TABLE_SHARE+0x118)[0xfd4c08]
/app/dbcluster/sgrdb/mysql/bin/sgrdbd(_ZN19create_table_info_t24create_table_update_dictEv+0x23f)[0xfda98f]
/app/dbcluster/sgrdb/mysql/bin/sgrdbd(_ZN11ha_innopart6createEPKcP5TABLEP24st_ha_create_information+0x727)[0xff5f17]
/app/dbcluster/sgrdb/mysql/bin/sgrdbd(_Z15ha_create_tableP3THDPKcS2_S2_P24st_ha_create_informationbb+0x2a3)[0x81b5e3]
/app/dbcluster/sgrdb/mysql/bin/sgrdbd(_Z16rea_create_tableP3THDPKcS2_S2_P24st_ha_create_informationR4ListI12Create_fieldEjP6st_keyP7handlerb+0x11a)[0xdd819a]
/app/dbcluster/sgrdb/mysql/bin/sgrdbd[0xd76d37]
/app/dbcluster/sgrdb/mysql/bin/sgrdbd(_Z26mysql_create_table_no_lockP3THDPKcS2_P24st_ha_create_informationP10Alter_infojPb+0xe7)[0xd77607]
/app/dbcluster/sgrdb/mysql/bin/sgrdbd(_Z18mysql_create_tableP3THDP10TABLE_LISTP24st_ha_create_informationP10Alter_info+0xcb)[0xd77e0b]
/app/dbcluster/sgrdb/mysql/bin/sgrdbd(_Z21mysql_execute_commandP3THDb+0x4a0f)[0xd1177f]
/app/dbcluster/sgrdb/mysql/bin/sgrdbd(_Z11mysql_parseP3THDP12Parser_state+0x635)[0xd127b5]
/app/dbcluster/sgrdb/mysql/bin/sgrdbd(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0x11a5)[0xd139c5]
/app/dbcluster/sgrdb/mysql/bin/sgrdbd(_Z10do_commandP3THD+0x1d4)[0xd144f4]
/app/dbcluster/sgrdb/mysql/bin/sgrdbd(handle_connection+0x2cc)[0xdeba2c]
/app/dbcluster/sgrdb/mysql/bin/sgrdbd(pfs_spawn_thread+0x171)[0xf50ca1]
/lib64/libpthread.so.0[0x3e74a07aa1]
/lib64/libc.so.6(clone+0x6d)[0x3e746e8aad] 

How to repeat:
I don't know.

I has meet this bug three times in three day, but fail to repeat it in the test environment.

What I know is that: 
1. there is more than 1w tables in the mysql
2. only table but no data
3. there is some prepare stmt and begin stmt during the create table operation

The conf file is:

[client]
port    = 23310
socket    = /sgb/data3310/mysql.sock
default-character-set=utf8

[mysqld]
plugin-load="rpl_semi_sync_master=semisync_master.so;rpl_semi_sync_slave=semisync_slave.so"
plugin_dir = /app/dbcluster/sgrdb/mysql/lib/sgrdb/plugin/
log-bin-trust-function-creators=1
character-set-server=utf8
port    = 23310
socket  = /sgb/data3310/mysql.sock
basedir = /app/dbcluster/sgrdb/mysql
datadir = /sgb/data3310
tmpdir = /sgb/tmp
skip-external-locking
skip-name-resolve
skip-slave-start
wait_timeout    = 31536000
interactive_timeout=31536000
expire_logs_days=3
back_log=5000
binlog-ignore-db=dbscale_tmp
net_write_timeout=1800
net_read_timeout=1800
lock_wait_timeout=600

secure_file_priv=''

thread_cache_size = 3000
max_connections = 20480
lower_case_table_names = 1 

server-id = 30101
log-bin
log-slave-updates
binlog-format=row

slow-query-log=on
innodb_print_all_deadlocks=on

innodb_buffer_pool_size=3G

innodb_flush_log_at_trx_commit = 1 
sync_binlog = 1 
innodb_file_per_table=1
innodb_locks_unsafe_for_binlog = 1 
innodb_thread_concurrency = 64
innodb_flush_method= O_DIRECT
innodb_io_capacity=800

innodb_read_io_threads=16
innodb_write_io_threads=16

innodb_change_buffering=all

innodb_doublewrite = true
max_allowed_packet = 16M

max_prepared_stmt_count=1048576

gtid-mode              = on
enforce-gtid-consistency

open_files_limit=20000000

slave_rows_search_algorithms = INDEX_SCAN,HASH_SCAN
sql_mode = STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION

Suggested fix:
None.
[26 Jun 2017 9:38] MySQL Verification Team
Thank you for taking the time to report a problem.  Unfortunately you
are not using a current version of the product you reported a problem
with -- the problem might already be fixed. Please download
a new version from http://www.mysql.com/downloads/.

Also, there is no test case provided in the bug report and hence there
is nothing we can verify here.  If you are able to reproduce the bug
with one of the latest versions, please attach the exact reproducible
test case and change the version on this bug report to the version you
tested and change the status back to "Open".  Again, thank you for your
continued support of MySQL.
[21 Dec 2018 2:18] Wei Liu
same problem in 5.7.24

CREATE TABLE IF NOT EXISTS gprscdr_2_cca_20181222 (
R smallint(6) unsigned NOT NULL DEFAULT '0',
Msisdn bigint(20) unsigned NOT NULL DEFAULT '0',

KEY idx_Msisdn (Msisdn)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=COMPRESSED
PARTITION by HASH (Msisdn) PARTITIONS 128;

Thread pointer: 0x7f1c86a09da0
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 = 7f2480d11ea8 thread_stack 0x40000
/mysql/bin/mysqld(my_print_stacktrace+0x35)[0xf4e815]
/mysql/bin/mysqld(handle_fatal_signal+0x4a4)[0x7d1be4]
/lib64/libpthread.so.0(+0xf100)[0x7f2d0afb0100]
/mysql/bin/mysqld(_Z32innobase_parse_hint_from_commentP3THDP12dict_table_tPK11TABLE_SHARE+0x120)[0xff30a0]
/mysql/bin/mysqld(_ZN19create_table_info_t24create_table_update_dictEv+0x1e0)[0xff7740]
/mysql/bin/mysqld(_ZN11ha_innopart6createEPKcP5TABLEP24st_ha_create_information+0xa6b)[0x101191b]
/mysql/bin/mysqld(_Z15ha_create_tableP3THDPKcS2_S2_P24st_ha_create_informationbb+0x1fb)[0x820efb]
/mysql/bin/mysqld(_Z16rea_create_tableP3THDPKcS2_S2_P24st_ha_create_informationR4ListI12Create_fieldEjP6st_keyP7handlerb+0x11a)[0xdddaea]
/mysql/bin/mysqld[0xd7e544]
/mysql/bin/mysqld(_Z26mysql_create_table_no_lockP3THDPKcS2_P24st_ha_create_informationP10Alter_infojPb+0xef)[0xd7ec4f]
/mysql/bin/mysqld(_Z18mysql_create_tableP3THDP10TABLE_LISTP24st_ha_create_informationP10Alter_info+0x9f)[0xd7f3bf]
/mysql/bin/mysqld(_Z21mysql_execute_commandP3THDb+0x44b1)[0xd1af51]
/mysql/bin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x40d)[0xd1bded]
/mysql/bin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0x11a5)[0xd1d015]
/mysql/bin/mysqld(_Z10do_commandP3THD+0x194)[0xd1dec4]
/mysql/bin/mysqld(handle_connection+0x29c)[0xdef52c]
/mysql/bin/mysqld(pfs_spawn_thread+0x174)[0xf74ee4]
/lib64/libpthread.so.0(+0x7dc5)[0x7f2d0afa8dc5]
/lib64/libc.so.6(clone+0x6d)[0x7f2d09a6521d]

cannot repeat
[21 Dec 2018 2:31] Wei Liu
I found  the same problem in percona server

they fix it by https://github.com/percona/percona-server/commit/de29427355290b29fb12306064f3a755cd9784a9

detail:

https://jira.percona.com/browse/PS-3906

Problem:
Inside 'create_table_info_t::create_table_update_dict()' which is called from
"CREATE TABLE" / "ALTER TABLE" handlers we invoke
'innobase_parse_hint_from_comment()', which is supposed to parse the hint for
the table and its indexes and update the information in dictionary, after the
table is closed by 'dict_table_close()'.
This can lead to a race condition in which the first thread calls
'dict_table_close()' and therefore the table is no longer locked.
Meanwhile the second thread ('srv_master_thread') triggers
'srv_master_evict_from_table_cache()' for this table and frees its resources.
After that, the first thread (the one which executes "CREATE TABLE" /
"ALTER TABLE") is activated again and calls
'innobase_parse_hint_from_comment()' which in turn tries to access freed
memory.

Fix:
Making sure that 'innobase_parse_hint_from_comment()' is called before
'dict_table_close()'.
[21 Dec 2018 7:34] MySQL Verification Team
C:\dbs>c:\dbs\5.7\bin\mysql -uroot --port=3570 -p  --prompt="mysql 5.7 > "
Enter password:
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 2
Server version: 5.7.26-log Source distribution BUILD: 2018-DEC-12

Copyright (c) 2000, 2019, 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 5.7 > use test
Database changed
mysql 5.7 > CREATE TABLE IF NOT EXISTS gprscdr_2_cca_20181222 (
    -> R smallint(6) unsigned NOT NULL DEFAULT '0',
    -> Msisdn bigint(20) unsigned NOT NULL DEFAULT '0',
    ->
    -> KEY idx_Msisdn (Msisdn)
    -> ) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=COMPRESSED
    -> PARTITION by HASH (Msisdn) PARTITIONS 128;
Query OK, 0 rows affected (2.65 sec)
[1 Jan 2019 1:54] David Chen Chen
I could execute the same sql statement without any problem,but the MySQL server crashed several times last week because of this bug.
[1 Jan 2019 5:03] MySQL Verification Team
seen https://bugs.mysql.com/bug.php?id=89126 ?