Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Duplicate
-
10.2.13, 10.0(EOL), 10.1(EOL), 10.2(EOL), 10.3(EOL), 10.4(EOL)
-
Ubuntu 16.04.3 LTS (GNU/Linux 4.4.0-1049-aws x86_64) running on Amazon AWS EC2 (Can provide instance level if needed)
Description
On a production server, we experience a crash during an alter table. I have attached the relevant entries from syslog (which is where MariaDB logs to), along with a similar SQL creation statement for the table that was altered. Unfortunately, the table in question was marked as crashed after the service restarted, and there was multiple entries per second being written to the error log about the table being crashed. Another member of the development team made the decision to drop the original table, and we don't have a backup of that table (it is a new table, being used as a summary table).
The main known difference between the attached SQL for the table and the original is that the original had Foreign Keys to other tables. If you feel this might be relevant, I can attempt to find the foreign keys that were in place, along with the table definitions of those the target tables.
MDEV-14021 has a similar crash (same assertion fail), so setting as relates to (I don't know enough about this bug to say if it is the same or not).
Attachments
Issue Links
- duplicates
-
-
- Closed
-
-
-
- Closed
-
- relates to
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
Activity
Here is at least one (non-deterministic) test case which causes the same assertion failure on non-debug builds, and a similar one on debug builds. Run with --repeat=N --mem, it usually fails for me within 5 attempts, but it can vary on different machines and builds.
--source include/have_innodb.inc
|
|
|
CREATE TABLE t1 ( |
pk INT, |
i INT, |
PRIMARY KEY (pk), |
KEY(i), |
FOREIGN KEY (pk) REFERENCES t1 (i) |
) ENGINE=InnoDB;
|
|
|
--connect (con1,localhost,root,,test)
|
--send
|
ALTER TABLE t1 ADD FOREIGN KEY (i) REFERENCES t1 (pk); |
|
|
--connection default
|
INSERT INTO t1 SELECT * FROM t1; |
PREPARE stmt FROM 'INSERT INTO t1 SELECT * FROM t1'; |
EXECUTE stmt; |
ALTER TABLE t1 FORCE; |
|
|
# Cleanup
|
--connection con1
|
--reap
|
--disconnect con1
|
--connection default
|
DROP TABLE t1; |
|
10.2 non-debug dc2856ad6 |
2018-12-21 23:50:49 0x7fc0902d9700 InnoDB: Assertion failure in file /data/src/10.2/storage/innobase/row/row0merge.cc line 4465
|
InnoDB: Failing assertion: table->get_ref_count() == 0
|
|
|
#4 0x00007fc09660d3fa in abort () from /lib/x86_64-linux-gnu/libc.so.6
|
#5 0x000055db865a32a3 in ut_dbg_assertion_failed (expr=expr@entry=0x55db86dfa3b0 "table->get_ref_count() == 0", file=file@entry=0x55db86df9950 "/data/src/10.2/storage/innobase/row/row0merge.cc", line=line@entry=4465) at /data/src/10.2/storage/innobase/ut/ut0dbg.cc:60
|
#6 0x000055db86ab5254 in row_merge_drop_table (trx=trx@entry=0x7fc090576198, table=<optimized out>) at /data/src/10.2/storage/innobase/row/row0merge.cc:4465
|
#7 0x000055db86a1fcda in ha_innobase::commit_inplace_alter_table (this=0x7fc03c093880, altered_table=<optimized out>, ha_alter_info=<optimized out>, commit=<optimized out>) at /data/src/10.2/storage/innobase/handler/handler0alter.cc:9085
|
#8 0x000055db866ddce6 in mysql_inplace_alter_table (target_mdl_request=0x7fc0902d4c20, alter_ctx=0x7fc0902d57e0, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, ha_alter_info=0x7fc0902d4b90, altered_table=0x7fc03c029a88, table=0x7fc03c0a6e68, table_list=0x7fc03c00f168, thd=0x7fc03c0009a8) at /data/src/10.2/sql/sql_table.cc:7391
|
#9 mysql_alter_table (thd=0x7fc03c0009a8, new_db=<optimized out>, new_name=<optimized out>, create_info=<optimized out>, table_list=0x7fc03c00f168, alter_info=<optimized out>, order_num=0, order=0x0, ignore=false) at /data/src/10.2/sql/sql_table.cc:9392
|
#10 0x000055db86726a2d in Sql_cmd_alter_table::execute (this=0x2, thd=0x7fc03c0009a8) at /data/src/10.2/sql/sql_alter.cc:329
|
#11 0x000055db8664e0bc in mysql_execute_command (thd=0x7fc03c0009a8) at /data/src/10.2/sql/sql_parse.cc:6227
|
#12 0x000055db8665642a in mysql_parse (thd=0x7fc03c0009a8, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /data/src/10.2/sql/sql_parse.cc:8014
|
#13 0x000055db86659fa4 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7fc03c0009a8, packet=packet@entry=0x7fc03c006ce9 "ALTER TABLE t1 FORCE", packet_length=packet_length@entry=20, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /data/src/10.2/sql/sql_parse.cc:1825
|
#14 0x000055db8665a9d9 in do_command (thd=0x7fc03c0009a8) at /data/src/10.2/sql/sql_parse.cc:1379
|
#15 0x000055db86723d44 in do_handle_one_connection (connect=connect@entry=0x55db88db2d78) at /data/src/10.2/sql/sql_connect.cc:1335
|
#16 0x000055db86723ee4 in handle_one_connection (arg=arg@entry=0x55db88db2d78) at /data/src/10.2/sql/sql_connect.cc:1241
|
#17 0x000055db869e8994 in pfs_spawn_thread (arg=0x55db88d74df8) at /data/src/10.2/storage/perfschema/pfs.cc:1862
|
#18 0x00007fc0980c0494 in start_thread (arg=0x7fc0902d9700) at pthread_create.c:333
|
#19 0x00007fc0966c193f in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
|
10.2 debug dc2856ad6 |
mysqld: /data/src/10.2/storage/innobase/handler/handler0alter.cc:7881: bool commit_try_rebuild(Alter_inplace_info*, ha_innobase_inplace_ctx*, TABLE*
|
, const TABLE*, trx_t*, const char*): Assertion `user_table->get_ref_count() == 1' failed.
|
181221 23:51:34 [ERROR] mysqld got signal 6 ;
|
|
|
#7 0x00007f44935faee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
|
#8 0x0000558e03fdb82a in commit_try_rebuild (ha_alter_info=0x7f448c264610, ctx=0x7f443c013ad8, altered_table=0x7f443c051c50, old_table=0x7f443c08a7f0, trx=0x7f448d56e3a8, table_name=0x7f443c08727d "t1") at /data/src/10.2/storage/innobase/handler/handler0alter.cc:7881
|
#9 0x0000558e03fd7e95 in ha_innobase::commit_inplace_alter_table (this=0x7f443c1333d8, altered_table=0x7f443c051c50, ha_alter_info=0x7f448c264610, commit=true) at /data/src/10.2/storage/innobase/handler/handler0alter.cc:8660
|
#10 0x0000558e03c8c337 in handler::ha_commit_inplace_alter_table (this=0x7f443c1333d8, altered_table=0x7f443c051c50, ha_alter_info=0x7f448c264610, commit=true) at /data/src/10.2/sql/handler.cc:4231
|
#11 0x0000558e03ad9ffa in mysql_inplace_alter_table (thd=0x7f443c000b00, table_list=0x7f443c012520, table=0x7f443c08a7f0, altered_table=0x7f443c051c50, ha_alter_info=0x7f448c264610, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7f448c264680, alter_ctx=0x7f448c265240) at /data/src/10.2/sql/sql_table.cc:7391
|
#12 0x0000558e03adf53b in mysql_alter_table (thd=0x7f443c000b00, new_db=0x7f443c012b30 "test", new_name=0x0, create_info=0x7f448c265e50, table_list=0x7f443c012520, alter_info=0x7f448c265da0, order_num=0, order=0x0, ignore=false) at /data/src/10.2/sql/sql_table.cc:9392
|
#13 0x0000558e03b5a89f in Sql_cmd_alter_table::execute (this=0x7f443c012b38, thd=0x7f443c000b00) at /data/src/10.2/sql/sql_alter.cc:329
|
#14 0x0000558e03a11985 in mysql_execute_command (thd=0x7f443c000b00) at /data/src/10.2/sql/sql_parse.cc:6227
|
#15 0x0000558e03a167e7 in mysql_parse (thd=0x7f443c000b00, rawbuf=0x7f443c012448 "ALTER TABLE t1 FORCE", length=20, parser_state=0x7f448c267200, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:8014
|
#16 0x0000558e03a0411f in dispatch_command (command=COM_QUERY, thd=0x7f443c000b00, packet=0x7f443c096191 "ALTER TABLE t1 FORCE", packet_length=20, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1825
|
#17 0x0000558e03a02a82 in do_command (thd=0x7f443c000b00) at /data/src/10.2/sql/sql_parse.cc:1379
|
#18 0x0000558e03b55535 in do_handle_one_connection (connect=0x558e06be3df0) at /data/src/10.2/sql/sql_connect.cc:1335
|
#19 0x0000558e03b552c2 in handle_one_connection (arg=0x558e06be3df0) at /data/src/10.2/sql/sql_connect.cc:1241
|
#20 0x0000558e03f7b1fc in pfs_spawn_thread (arg=0x558e06b2a1f0) at /data/src/10.2/storage/perfschema/pfs.cc:1862
|
#21 0x00007f44950b6494 in start_thread (arg=0x7f448c268700) at pthread_create.c:333
|
#22 0x00007f44936b793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
Reproducible on 10.2, 10.3, 10.4.
On 10.0 and 10.1 ALTER TABLE t1 FORCE fails immediately with 1205: Lock wait timeout exceeded; try restarting transaction, which of course is strange, because the default lock wait timeout is quite long and can't be exceeded so quickly.
If we allow the statement to fail (add --error 0,ER_LOCK_WAIT_TIMEOUT before the statement), on 10.1 the test non-deterministically hangs upon DROP TABLE for 300 seconds, then gives up. I'm not sure where 300 seconds comes from.
The processlist says
+----+------+-----------------+------+---------+------+------------------+------------------+----------+
|
| Id | User | Host | db | Command | Time | State | Info | Progress |
|
+----+------+-----------------+------+---------+------+------------------+------------------+----------+
|
| 8 | root | localhost | test | Query | 84 | Unlocking tables | DROP TABLE t1 | 0.000 |
|
| 10 | root | localhost:58919 | NULL | Query | 0 | init | show processlist | 0.000 |
|
+----+------+-----------------+------+---------+------+------------------+------------------+----------+
|
Metadata lock info says
MariaDB [(none)]> select * from information_schema.metadata_lock_info;
|
+-----------+-------------------------+---------------+----------------------+--------------+------------+
|
| THREAD_ID | LOCK_MODE | LOCK_DURATION | LOCK_TYPE | TABLE_SCHEMA | TABLE_NAME |
|
+-----------+-------------------------+---------------+----------------------+--------------+------------+
|
| 8 | MDL_INTENTION_EXCLUSIVE | NULL | Global read lock | | |
|
| 8 | MDL_EXCLUSIVE | NULL | Table metadata lock | test | t1 |
|
| 8 | MDL_INTENTION_EXCLUSIVE | NULL | Schema metadata lock | test | |
|
+-----------+-------------------------+---------------+----------------------+--------------+------------+
|
3 rows in set (0.00 sec)
|
And the stack trace from the hanging process is
|
10.1 9f4a4cb40 |
Thread 2 (Thread 0x7f84224c1b00 (LWP 31871)):
|
#0 0x00007f842071d233 in select () from /lib/x86_64-linux-gnu/libc.so.6
|
#1 0x00007f8419b6ef30 in os_thread_sleep (tm=20000) at /data/src/10.1/storage/innobase/os/os0thread.cc:283
|
#2 0x00007f8419beb4c8 in fil_wait_crypt_bg_threads (table=0x7f840a8d90f8) at /data/src/10.1/storage/innobase/row/row0mysql.cc:3313
|
#3 0x00007f8419bed4c4 in row_drop_table_for_mysql (name=0x7f84224bdc20 "test/t1", trx=0x7f840a46ae78, drop_db=false, create_failed=0, nonatomic=true) at /data/src/10.1/storage/innobase/row/row0mysql.cc:4174
|
#4 0x00007f8419ae59b2 in ha_innodb::delete_table (this=0x7f840a70d970, name=0x7f84224bf770 "./test/t1") at /data/src/10.1/storage/innobase/handler/ha_innodb.cc:12592
|
#5 0x0000562958aad4bc in handler::ha_delete_table (this=0x7f840a70d970, name=0x7f84224bf770 "./test/t1") at /data/src/10.1/sql/handler.cc:4317
|
#6 0x0000562958aa862f in ha_delete_table (thd=0x7f8416fc7070, table_type=0x7f841fc37470, path=0x7f84224bf770 "./test/t1", db=0x7f840a70d740 "test", alias=0x7f840a70d118 "t1", generate_warning=true) at /data/src/10.1/sql/handler.cc:2385
|
#7 0x000056295891b9d3 in mysql_rm_table_no_locks (thd=0x7f8416fc7070, tables=0x7f840a70d150, if_exists=false, drop_temporary=false, drop_view=false, dont_log_query=false, dont_free_locks=false) at /data/src/10.1/sql/sql_table.cc:2470
|
#8 0x000056295891abfd in mysql_rm_table (thd=0x7f8416fc7070, tables=0x7f840a70d150, if_exists=0 '\000', drop_temporary=0 '\000') at /data/src/10.1/sql/sql_table.cc:2085
|
#9 0x0000562958867bb3 in mysql_execute_command (thd=0x7f8416fc7070) at /data/src/10.1/sql/sql_parse.cc:4257
|
#10 0x000056295887168b in mysql_parse (thd=0x7f8416fc7070, rawbuf=0x7f840a70d088 "DROP TABLE t1", length=13, parser_state=0x7f84224c05e0) at /data/src/10.1/sql/sql_parse.cc:7467
|
#11 0x000056295885fedc in dispatch_command (command=COM_QUERY, thd=0x7f8416fc7070, packet=0x7f8416fd9071 "DROP TABLE t1", packet_length=13) at /data/src/10.1/sql/sql_parse.cc:1495
|
#12 0x000056295885ec61 in do_command (thd=0x7f8416fc7070) at /data/src/10.1/sql/sql_parse.cc:1124
|
#13 0x0000562958999988 in do_handle_one_connection (thd_arg=0x7f8416fc7070) at /data/src/10.1/sql/sql_connect.cc:1330
|
#14 0x00005629589996ec in handle_one_connection (arg=0x7f8416fc7070) at /data/src/10.1/sql/sql_connect.cc:1242
|
#15 0x0000562958d57982 in pfs_spawn_thread (arg=0x7f841b3f3f70) at /data/src/10.1/storage/perfschema/pfs.cc:1861
|
#16 0x00007f8422150494 in start_thread (arg=0x7f84224c1b00) at pthread_create.c:333
|
#17 0x00007f842072493f in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
On 10.0 the test (also non-deterministically) fails with
bug.ref3 'xtradb' [ fail ] Found warnings/errors in server log file!
|
Test ended at 2018-12-21 23:59:49
|
line
|
2018-12-21 23:59:49 7fcefed18700 InnoDB: Warning: MySQL is trying to drop table `test`.`t1`
|
^ Found warnings in /data/bld/10.0/mysql-test/var/log/mysqld.1.err
|
Assigning to marko for the initial look. Possibly it belongs to svoj instead.
Also, maybe we will need to split the two issues – assertion failures for 10.2+ and the hang for 10.0/10.1. I think we have had several users' reports about server hanging in 'Unlocking tables', they might be related.
I ran elenst’s test with the following instrumentation on top of 10.2:
diff --git a/storage/innobase/include/dict0dict.ic b/storage/innobase/include/dict0dict.ic
|
index a10bf769773..7b83647469a 100644
|
--- a/storage/innobase/include/dict0dict.ic
|
+++ b/storage/innobase/include/dict0dict.ic
|
@@ -25,6 +25,7 @@ Created 1/8/1996 Heikki Tuuri
|
***********************************************************************/
|
|
#include "fsp0sysspace.h"
|
+#include "my_stacktrace.h"
|
|
/*********************************************************************//**
|
Gets the minimum number of bytes per character.
|
@@ -1498,6 +1499,9 @@ dict_table_t::acquire()
|
{
|
ut_ad(mutex_own(&dict_sys->mutex));
|
my_atomic_add32_explicit(&n_ref_count, 1, MY_MEMORY_ORDER_RELAXED);
|
+ if (id < 18) return;
|
+ ib::info() << "acquired " << n_ref_count << "," << id << "," << name;
|
+ my_print_stacktrace(NULL, 0);
|
}
|
|
/** Release the table handle.
|
@@ -1509,6 +1513,9 @@ dict_table_t::release()
|
int32 n = my_atomic_add32_explicit(
|
&n_ref_count, -1, MY_MEMORY_ORDER_RELAXED);
|
ut_ad(n > 0);
|
+ if (id < 18) return n == 1;
|
+ ib::info() << "released " << n << "," << id << "," << name;
|
+ my_print_stacktrace(NULL, 0);
|
return n == 1;
|
}
|
|
|
This will significantly reduce the probability of crashing for me, but it does still fail.
Here is some edited output for the table ID 20, which was user_table->id in the core dump:
2019-03-06 13:29:38 140283319162624 [Note] InnoDB: acquired 1,20,`test`.`#sql-2d09_a`
|
stack_bottom = 0x0 thread_stack 0x0
|
mysys/stacktrace.c:267(my_print_stacktrace)[0x5580993e8ca9]
|
:0(dict_table_t::acquire())[0x5580991e9828]
|
dict/dict0dict.cc:1212(dict_table_open_on_name(char const*, unsigned long, unsigned long, dict_err_ignore_t))[0x5580991d1c28]
|
:0(create_table_info_t::create_table_update_dict())[0x558098f5a73d]
|
:0(ha_innobase::create(char const*, TABLE*, HA_CREATE_INFO*, bool, trx_t*))[0x558098f6f489]
|
sql/handler.cc:4442(handler::ha_create(char const*, TABLE*, HA_CREATE_INFO*))[0x558098d9abc8]
|
/dev/shm/10.2/sql/mysqld(ha_create_table(THD*, char const*, char const*, char const*, HA_CREATE_INFO*, st_mysql_const_unsigned_lex_string*)+0x27f)[0x558098d9ba0f]
|
sql/sql_table.cc:9505(mysql_alter_table(THD*, char*, char*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool))[0x558098c5f3f0]
|
…
|
2019-03-06 13:29:38 140283319469824 [Note] InnoDB: acquired 2,20,`test`.`#sql-2d09_a`
|
stack_bottom = 0x0 thread_stack 0x0
|
mysys/stacktrace.c:267(my_print_stacktrace)[0x5580993e8ca9]
|
:0(dict_table_t::acquire())[0x5580991e9828]
|
dict/dict0dict.cc:1212(dict_table_open_on_name(char const*, unsigned long, unsigned long, dict_err_ignore_t))[0x5580991d1c28]
|
:0(ha_innobase::open_dict_table(char const*, char const*, bool, dict_err_ignore_t))[0x558098f4f273]
|
:0(ha_innobase::open(char const*, int, unsigned int))[0x558098f4e240]
|
/dev/shm/10.2/sql/mysqld(handler::ha_open(TABLE*, char const*, int, unsigned int)+0xe3)[0x558098d95953]
|
/dev/shm/10.2/sql/mysqld(open_table_from_share(THD*, TABLE_SHARE*, char const*, unsigned int, unsigned int, unsigned int, TABLE*, bool)+0xaf1)[0x558098c83d11]
|
sql/sql_base.cc:1920(open_table(THD*, TABLE_LIST*, Open_table_context*))[0x558098b6b945]
|
/dev/shm/10.2/sql/mysqld(open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*)+0x413)[0x558098b6d7d3]
|
sql/sql_prepare.cc:1807(select_like_stmt_test_with_open(Prepared_statement*, TABLE_LIST*, int (*)(THD*), unsigned long))[0x558098be2d81]
|
sql/sql_prepare.cc:2240(mysql_test_insert_select(Prepared_statement*, TABLE_LIST*))[0x558098bdaad7]
|
sql/sql_prepare.cc:2844(mysql_sql_stmt_prepare(THD*))[0x558098bdc833]
|
sql/sql_parse.cc:3543(mysql_execute_command(THD*))[0x558098bc213c]
|
sql/sql_class.h:2279(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x558098bbe433]
|
sql/sql_parse.cc:1831(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x558098bbb230]
|
/dev/shm/10.2/sql/mysqld(do_command(THD*)+0x4da)[0x558098bbce9a]
|
sql/sql_connect.cc:1336(do_handle_one_connection(CONNECT*))[0x558098cb5aa0]
|
…
|
2019-03-06 13:29:39 140283319162624 [Note] InnoDB: released 2,20,`test`.`#sql-2d09_a`
|
stack_bottom = 0x0 thread_stack 0x0
|
mysys/stacktrace.c:267(my_print_stacktrace)[0x5580993e8ca9]
|
:0(dict_table_t::release())[0x558098f712fe]
|
dict/dict0dict.cc:503(dict_table_close(dict_table_t*, unsigned long, unsigned long))[0x5580991cf674]
|
:0(create_table_info_t::create_table_update_dict())[0x558098f5ab83]
|
:0(ha_innobase::create(char const*, TABLE*, HA_CREATE_INFO*, bool, trx_t*))[0x558098f6f489]
|
sql/handler.cc:4442(handler::ha_create(char const*, TABLE*, HA_CREATE_INFO*))[0x558098d9abc8]
|
/dev/shm/10.2/sql/mysqld(ha_create_table(THD*, char const*, char const*, char const*, HA_CREATE_INFO*, st_mysql_const_unsigned_lex_string*)+0x27f)[0x558098d9ba0f]
|
sql/sql_table.cc:9505(mysql_alter_table(THD*, char*, char*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool))[0x558098c5f3f0]
|
…
|
2019-03-06 13:29:39 140283319162624 [Note] InnoDB: acquired 2,20,`test`.`#sql-2d09_a`
|
stack_bottom = 0x0 thread_stack 0x0
|
mysys/stacktrace.c:267(my_print_stacktrace)[0x5580993e8ca9]
|
:0(dict_table_t::acquire())[0x5580991e9828]
|
dict/dict0dict.cc:1212(dict_table_open_on_name(char const*, unsigned long, unsigned long, dict_err_ignore_t))[0x5580991d1c28]
|
:0(ha_innobase::open_dict_table(char const*, char const*, bool, dict_err_ignore_t))[0x558098f4f273]
|
:0(ha_innobase::open(char const*, int, unsigned int))[0x558098f4e240]
|
/dev/shm/10.2/sql/mysqld(handler::ha_open(TABLE*, char const*, int, unsigned int)+0xe3)[0x558098d95953]
|
/dev/shm/10.2/sql/mysqld(open_table_from_share(THD*, TABLE_SHARE*, char const*, unsigned int, unsigned int, unsigned int, TABLE*, bool)+0xaf1)[0x558098c83d11]
|
sql/temporary_tables.cc:1091(THD::open_temporary_table(TMP_TABLE_SHARE*, char const*, bool))[0x558098d2f364]
|
/dev/shm/10.2/sql/mysqld(THD::create_and_open_tmp_table(handlerton*, st_mysql_const_unsigned_lex_string*, char const*, char const*, char const*, bool)+0x76)[0x558098d2ef36]
|
sql/sql_table.cc:9514(mysql_alter_table(THD*, char*, char*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool))[0x558098c5f430]
|
/dev/shm/10.2/sql/mysqld(Sql_cmd_alter_table::execute(THD*)+0x4b0)[0x558098cb9760]
|
/dev/shm/10.2/sql/mysqld(mysql_execute_command(THD*)+0x122e)[0x558098bc0f3e]
|
…
|
2019-03-06 13:29:39 140283319162624 [Note] InnoDB: released 2,20,`test`.`#sql-2d09_a`
|
stack_bottom = 0x0 thread_stack 0x0
|
mysys/stacktrace.c:267(my_print_stacktrace)[0x5580993e8ca9]
|
:0(dict_table_t::release())[0x558098f712fe]
|
dict/dict0dict.cc:503(dict_table_close(dict_table_t*, unsigned long, unsigned long))[0x5580991cf674]
|
row/row0mysql.cc:1038(row_prebuilt_free(row_prebuilt_t*, unsigned long))[0x55809906a55c]
|
handler/ha_innodb.cc:6709(ha_innobase::close())[0x558098f4f791]
|
/dev/shm/10.2/sql/mysqld(handler::ha_close()+0x91)[0x558098d95e41]
|
/dev/shm/10.2/sql/mysqld(closefrm(TABLE*)+0x5e)[0x558098c8425e]
|
sql/temporary_tables.cc:1213(THD::close_temporary_table(TABLE*))[0x558098d31af7]
|
sql/temporary_tables.cc:1457(THD::free_temporary_table(TABLE*))[0x558098d306f7]
|
/dev/shm/10.2/sql/mysqld(THD::drop_temporary_table(TABLE*, bool*, bool)+0x160)[0x558098d31200]
|
sql/sql_table.cc:9663(mysql_alter_table(THD*, char*, char*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool))[0x558098c61e26]
|
/dev/shm/10.2/sql/mysqld(Sql_cmd_alter_table::execute(THD*)+0x4b0)[0x558098cb9760]
|
/dev/shm/10.2/sql/mysqld(mysql_execute_command(THD*)+0x122e)[0x558098bc0f3e]
|
… (snip quite a few operations for table ID 19)
|
2019-03-06 13:29:41 140283319162624 [Note] InnoDB: acquired 2,20,`test`.`#sql-2d09_a`
|
stack_bottom = 0x0 thread_stack 0x0
|
mysys/stacktrace.c:267(my_print_stacktrace)[0x5580993e8ca9]
|
:0(dict_table_t::acquire())[0x5580991e9828]
|
dict/dict0dict.cc:1212(dict_table_open_on_name(char const*, unsigned long, unsigned long, dict_err_ignore_t))[0x5580991d1c28]
|
:0(innobase_rename_table(trx_t*, char const*, char const*, bool, bool))[0x558098f6ff2c]
|
:0(ha_innobase::rename_table(char const*, char const*))[0x558098f5b860]
|
/dev/shm/10.2/sql/mysqld(mysql_rename_table(handlerton*, char const*, char const*, char const*, char const*, unsigned int)+0x2bb)[0x558098c595db]
|
/dev/shm/10.2/sql/mysqld(mysql_alter_table(THD*, char*, char*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool)+0x5fd2)[0x558098c62842]
|
/dev/shm/10.2/sql/mysqld(Sql_cmd_alter_table::execute(THD*)+0x4b0)[0x558098cb9760]
|
/dev/shm/10.2/sql/mysqld(mysql_execute_command(THD*)+0x122e)[0x558098bc0f3e]
|
…
|
2019-03-06 13:29:41 140283319162624 [Note] InnoDB: released 2,20,`test`.`#sql-2d09_a`
|
stack_bottom = 0x0 thread_stack 0x0
|
mysys/stacktrace.c:267(my_print_stacktrace)[0x5580993e8ca9]
|
:0(dict_table_t::release())[0x558098f712fe]
|
dict/dict0dict.cc:503(dict_table_close(dict_table_t*, unsigned long, unsigned long))[0x5580991cf674]
|
handler/ha_innodb.cc:13441(innobase_rename_table(trx_t*, char const*, char const*, bool, bool))[0x558098f70006]
|
:0(ha_innobase::rename_table(char const*, char const*))[0x558098f5b860]
|
/dev/shm/10.2/sql/mysqld(mysql_rename_table(handlerton*, char const*, char const*, char const*, char const*, unsigned int)+0x2bb)[0x558098c595db]
|
/dev/shm/10.2/sql/mysqld(mysql_alter_table(THD*, char*, char*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool)+0x5fd2)[0x558098c62842]
|
/dev/shm/10.2/sql/mysqld(Sql_cmd_alter_table::execute(THD*)+0x4b0)[0x558098cb9760]
|
/dev/shm/10.2/sql/mysqld(mysql_execute_command(THD*)+0x122e)[0x558098bc0f3e]
|
…
|
2019-03-06 13:29:42 140283319162624 [Note] InnoDB: acquired 2,20,`test`.`#sql-2d09_a`
|
stack_bottom = 0x0 thread_stack 0x0
|
mysys/stacktrace.c:267(my_print_stacktrace)[0x5580993e8ca9]
|
:0(dict_table_t::acquire())[0x5580991e9828]
|
dict/dict0dict.cc:1212(dict_table_open_on_name(char const*, unsigned long, unsigned long, dict_err_ignore_t))[0x5580991d1c28]
|
row/row0mysql.cc:4177(row_rename_table_for_mysql(char const*, char const*, trx_t*, bool, bool))[0x558099072b5c]
|
:0(innobase_rename_table(trx_t*, char const*, char const*, bool, bool))[0x558098f70044]
|
:0(ha_innobase::rename_table(char const*, char const*))[0x558098f5b860]
|
/dev/shm/10.2/sql/mysqld(mysql_rename_table(handlerton*, char const*, char const*, char const*, char const*, unsigned int)+0x2bb)[0x558098c595db]
|
/dev/shm/10.2/sql/mysqld(mysql_alter_table(THD*, char*, char*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool)+0x5fd2)[0x558098c62842]
|
/dev/shm/10.2/sql/mysqld(Sql_cmd_alter_table::execute(THD*)+0x4b0)[0x558098cb9760]
|
/dev/shm/10.2/sql/mysqld(mysql_execute_command(THD*)+0x122e)[0x558098bc0f3e]
|
…
|
2019-03-06 13:29:42 140283319162624 [Note] InnoDB: released 2,20,`test`.`t1`
|
stack_bottom = 0x0 thread_stack 0x0
|
mysys/stacktrace.c:267(my_print_stacktrace)[0x5580993e8ca9]
|
:0(dict_table_t::release())[0x558098f712fe]
|
dict/dict0dict.cc:503(dict_table_close(dict_table_t*, unsigned long, unsigned long))[0x5580991cf674]
|
:0(row_rename_table_for_mysql(char const*, char const*, trx_t*, bool, bool))[0x55809907391f]
|
:0(innobase_rename_table(trx_t*, char const*, char const*, bool, bool))[0x558098f70044]
|
:0(ha_innobase::rename_table(char const*, char const*))[0x558098f5b860]
|
/dev/shm/10.2/sql/mysqld(mysql_rename_table(handlerton*, char const*, char const*, char const*, char const*, unsigned int)+0x2bb)[0x558098c595db]
|
/dev/shm/10.2/sql/mysqld(mysql_alter_table(THD*, char*, char*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool)+0x5fd2)[0x558098c62842]
|
/dev/shm/10.2/sql/mysqld(Sql_cmd_alter_table::execute(THD*)+0x4b0)[0x558098cb9760]
|
/dev/shm/10.2/sql/mysqld(mysql_execute_command(THD*)+0x122e)[0x558098bc0f3e]
|
… (snip a couple of operations on ID 19, which had been renamed to sql2 name)
|
2019-03-06 13:29:43 140283319469824 [Note] InnoDB: acquired 2,20,`test`.`t1`
|
stack_bottom = 0x0 thread_stack 0x0
|
mysys/stacktrace.c:267(my_print_stacktrace)[0x5580993e8ca9]
|
:0(dict_table_t::acquire())[0x5580991e9828]
|
dict/dict0dict.cc:1212(dict_table_open_on_name(char const*, unsigned long, unsigned long, dict_err_ignore_t))[0x5580991d1c28]
|
:0(ha_innobase::open_dict_table(char const*, char const*, bool, dict_err_ignore_t))[0x558098f4f273]
|
:0(ha_innobase::open(char const*, int, unsigned int))[0x558098f4e240]
|
/dev/shm/10.2/sql/mysqld(handler::ha_open(TABLE*, char const*, int, unsigned int)+0xe3)[0x558098d95953]
|
/dev/shm/10.2/sql/mysqld(open_table_from_share(THD*, TABLE_SHARE*, char const*, unsigned int, unsigned int, unsigned int, TABLE*, bool)+0xaf1)[0x558098c83d11]
|
sql/sql_base.cc:1920(open_table(THD*, TABLE_LIST*, Open_table_context*))[0x558098b6b945]
|
/dev/shm/10.2/sql/mysqld(open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*)+0xb47)[0x558098b6df07]
|
sql/sql_base.cc:4767(open_and_lock_tables(THD*, DDL_options_st const&, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*))[0x558098b6f83b]
|
sql/sql_parse.cc:4556(mysql_execute_command(THD*))[0x558098bc172b]
|
sql/sql_prepare.cc:4805(Prepared_statement::execute(String*, bool))[0x558098bdfed0]
|
sql/sql_prepare.cc:4234(Prepared_statement::execute_loop(String*, bool, unsigned char*, unsigned char*))[0x558098bddcab]
|
sql/sql_class.h:1342(mysql_sql_stmt_execute(THD*))[0x558098bdda67]
|
sql/sql_parse.cc:3548(mysql_execute_command(THD*))[0x558098bc20ee]
|
sql/sql_class.h:2279(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x558098bbe433]
|
…
|
2019-03-06 13:29:43 140283319469824 [Note] InnoDB: acquired 3,20,`test`.`t1`
|
stack_bottom = 0x0 thread_stack 0x0
|
mysys/stacktrace.c:267(my_print_stacktrace)[0x5580993e8ca9]
|
:0(dict_table_t::acquire())[0x5580991e9828]
|
dict/dict0dict.cc:1212(dict_table_open_on_name(char const*, unsigned long, unsigned long, dict_err_ignore_t))[0x5580991d1c28]
|
:0(ha_innobase::open_dict_table(char const*, char const*, bool, dict_err_ignore_t))[0x558098f4f273]
|
:0(ha_innobase::open(char const*, int, unsigned int))[0x558098f4e240]
|
/dev/shm/10.2/sql/mysqld(handler::ha_open(TABLE*, char const*, int, unsigned int)+0xe3)[0x558098d95953]
|
/dev/shm/10.2/sql/mysqld(open_table_from_share(THD*, TABLE_SHARE*, char const*, unsigned int, unsigned int, unsigned int, TABLE*, bool)+0xaf1)[0x558098c83d11]
|
sql/sql_base.cc:1920(open_table(THD*, TABLE_LIST*, Open_table_context*))[0x558098b6b945]
|
/dev/shm/10.2/sql/mysqld(open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*)+0xb47)[0x558098b6df07]
|
sql/sql_prepare.cc:1807(select_like_stmt_test_with_open(Prepared_statement*, TABLE_LIST*, int (*)(THD*), unsigned long))[0x558098be2d81]
|
sql/sql_prepare.cc:2240(mysql_test_insert_select(Prepared_statement*, TABLE_LIST*))[0x558098bdaad7]
|
/dev/shm/10.2/sql/mysqld(Prepared_statement::reprepare()+0xf5)[0x558098be0205]
|
sql/sql_prepare.cc:4272(Prepared_statement::execute_loop(String*, bool, unsigned char*, unsigned char*))[0x558098bddee4]
|
sql/sql_class.h:1342(mysql_sql_stmt_execute(THD*))[0x558098bdda67]
|
sql/sql_parse.cc:3548(mysql_execute_command(THD*))[0x558098bc20ee]
|
sql/sql_class.h:2279(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x558098bbe433]
|
…
|
2019-03-06 13:29:43 140283319469824 [Note] InnoDB: acquired 4,20,`test`.`t1`
|
stack_bottom = 0x0 thread_stack 0x0
|
mysys/stacktrace.c:267(my_print_stacktrace)[0x5580993e8ca9]
|
:0(dict_table_t::acquire())[0x5580991e9828]
|
dict/dict0dict.cc:1212(dict_table_open_on_name(char const*, unsigned long, unsigned long, dict_err_ignore_t))[0x5580991d1c28]
|
:0(ha_innobase::open_dict_table(char const*, char const*, bool, dict_err_ignore_t))[0x558098f4f273]
|
:0(ha_innobase::open(char const*, int, unsigned int))[0x558098f4e240]
|
/dev/shm/10.2/sql/mysqld(handler::ha_open(TABLE*, char const*, int, unsigned int)+0xe3)[0x558098d95953]
|
/dev/shm/10.2/sql/mysqld(open_table_from_share(THD*, TABLE_SHARE*, char const*, unsigned int, unsigned int, unsigned int, TABLE*, bool)+0xaf1)[0x558098c83d11]
|
sql/sql_base.cc:1920(open_table(THD*, TABLE_LIST*, Open_table_context*))[0x558098b6b945]
|
/dev/shm/10.2/sql/mysqld(open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*)+0x413)[0x558098b6d7d3]
|
sql/sql_prepare.cc:1807(select_like_stmt_test_with_open(Prepared_statement*, TABLE_LIST*, int (*)(THD*), unsigned long))[0x558098be2d81]
|
sql/sql_prepare.cc:2240(mysql_test_insert_select(Prepared_statement*, TABLE_LIST*))[0x558098bdaad7]
|
/dev/shm/10.2/sql/mysqld(Prepared_statement::reprepare()+0xf5)[0x558098be0205]
|
sql/sql_prepare.cc:4272(Prepared_statement::execute_loop(String*, bool, unsigned char*, unsigned char*))[0x558098bddee4]
|
sql/sql_class.h:1342(mysql_sql_stmt_execute(THD*))[0x558098bdda67]
|
sql/sql_parse.cc:3548(mysql_execute_command(THD*))[0x558098bc20ee]
|
sql/sql_class.h:2279(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x558098bbe433]
|
…
|
2019-03-06 13:29:43 140283319469824 [Note] InnoDB: released 4,20,`test`.`t1`
|
stack_bottom = 0x0 thread_stack 0x0
|
mysys/stacktrace.c:267(my_print_stacktrace)[0x5580993e8ca9]
|
:0(dict_table_t::release())[0x558098f712fe]
|
dict/dict0dict.cc:503(dict_table_close(dict_table_t*, unsigned long, unsigned long))[0x5580991cf674]
|
row/row0mysql.cc:1038(row_prebuilt_free(row_prebuilt_t*, unsigned long))[0x55809906a55c]
|
handler/ha_innodb.cc:6709(ha_innobase::close())[0x558098f4f791]
|
/dev/shm/10.2/sql/mysqld(handler::ha_close()+0x91)[0x558098d95e41]
|
/dev/shm/10.2/sql/mysqld(closefrm(TABLE*)+0x5e)[0x558098c8425e]
|
sql/table_cache.cc:223(intern_close_table(TABLE*))[0x558098d2dcdb]
|
sql/sql_table.cc:7279(mysql_inplace_alter_table(THD*, TABLE_LIST*, TABLE*, TABLE*, Alter_inplace_info*, enum_alter_inplace_result, MDL_request*, Alter_table_ctx*))[0x558098c61a45]
|
/dev/shm/10.2/sql/mysqld(Sql_cmd_alter_table::execute(THD*)+0x4b0)[0x558098cb9760]
|
/dev/shm/10.2/sql/mysqld(mysql_execute_command(THD*)+0x122e)[0x558098bc0f3e]
|
sql/sql_class.h:2279(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x558098bbe433]
|
…
|
2019-03-06 13:29:44 140283319469824 [Note] InnoDB: released 3,20,`test`.`t1`
|
stack_bottom = 0x0 thread_stack 0x0
|
mysys/stacktrace.c:267(my_print_stacktrace)[0x5580993e8ca9]
|
:0(dict_table_t::release())[0x558098f712fe]
|
dict/dict0dict.cc:503(dict_table_close(dict_table_t*, unsigned long, unsigned long))[0x5580991cf674]
|
row/row0mysql.cc:1038(row_prebuilt_free(row_prebuilt_t*, unsigned long))[0x55809906a55c]
|
handler/ha_innodb.cc:6709(ha_innobase::close())[0x558098f4f791]
|
/dev/shm/10.2/sql/mysqld(handler::ha_close()+0x91)[0x558098d95e41]
|
/dev/shm/10.2/sql/mysqld(closefrm(TABLE*)+0x5e)[0x558098c8425e]
|
sql/table_cache.cc:223(intern_close_table(TABLE*))[0x558098d2dcdb]
|
sql/sql_table.cc:7279(mysql_inplace_alter_table(THD*, TABLE_LIST*, TABLE*, TABLE*, Alter_inplace_info*, enum_alter_inplace_result, MDL_request*, Alter_table_ctx*))[0x558098c61a45]
|
/dev/shm/10.2/sql/mysqld(Sql_cmd_alter_table::execute(THD*)+0x4b0)[0x558098cb9760]
|
/dev/shm/10.2/sql/mysqld(mysql_execute_command(THD*)+0x122e)[0x558098bc0f3e]
|
sql/sql_class.h:2279(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x558098bbe433]
|
…
|
2019-03-06 13:29:44 140283319469824 [Note] InnoDB: acquired 1,21,`test`.`#sql-2d09_9`
|
stack_bottom = 0x0 thread_stack 0x0
|
mysys/stacktrace.c:267(my_print_stacktrace)[0x5580993e8ca9]
|
:0(dict_table_t::acquire())[0x5580991e9828]
|
dict/dict0dict.cc:1212(dict_table_open_on_name(char const*, unsigned long, unsigned long, dict_err_ignore_t))[0x5580991d1c28]
|
handler0alter.cc:0(prepare_inplace_alter_table_dict(Alter_inplace_info*, TABLE const*, TABLE const*, char const*, unsigned long, unsigned long, unsigned long, bool, bool))[0x558098f7c937]
|
handler/handler0alter.cc:6292(ha_innobase::prepare_inplace_alter_table(TABLE*, Alter_inplace_info*))[0x558098f77643]
|
sql/sql_table.cc:7329(mysql_inplace_alter_table(THD*, TABLE_LIST*, TABLE*, TABLE*, Alter_inplace_info*, enum_alter_inplace_result, MDL_request*, Alter_table_ctx*))[0x558098c61c09]
|
/dev/shm/10.2/sql/mysqld(Sql_cmd_alter_table::execute(THD*)+0x4b0)[0x558098cb9760]
|
/dev/shm/10.2/sql/mysqld(mysql_execute_command(THD*)+0x122e)[0x558098bc0f3e]
|
… (snip only a little bit of stack trace)
|
mysqld: /mariadb/10.2/storage/innobase/handler/handler0alter.cc:7906: bool commit_try_rebuild(Alter_inplace_info *, ha_innobase_inplace_ctx *, TABLE *, const TABLE *, trx_t *, const char *): Assertion `user_table->get_ref_count() == 1' failed.
|
svoj, I think that the problem is the second acquisition. Either the PREPARE stmt or EXECUTE stmt is accessing the wrong table (with #sql name). I suppose that the EXECUTE stmt should be blocked while the first ALTER TABLE (which uses ALGORITHM=COPY) is executing. The wrong reference-count is merely caught during the second ALTER TABLE. This lingering reference should also cause a hang during DROP TABLE or similar.
Should've been fixed by MDEV-16060. Feel free to reopen if the problem persists.
Verified test case provided by Elena to fail reliably without MDEV-16060 and not failing with it.
Hi @Elena Stepanova
Please find attached. Note this is the current config file, but I am not aware of any changes since creating the ticket (but I can't guarantee it).
Thanks,
Robert my.cnf