Details
-
Bug
-
Status: Closed (View Workflow)
-
Blocker
-
Resolution: Fixed
-
None
-
None
-
10.11.10
Compiled with debugging
Description
Trace after crash with: mariabackup.alter_copy_race
It always crashes when I run the above test case.
The result from queries just before the failure was:
# xtrabackup backup
|
CREATE TABLE t1(i int) ENGINE=InnoDB; |
INSERT into t1 values(1); |
connect con2, localhost, root,,; |
connection con2; |
set lock_wait_timeout=1; |
SET debug_sync='copy_data_between_tables_before_reset_backup_lock SIGNAL go WAIT_FOR after_backup_stage_block_ddl'; |
SET debug_sync='alter_table_after_temp_table_drop SIGNAL temp_table_dropped'; |
SET debug_sync='now WAIT_FOR after_backup_stage_start';ALTER TABLE test.t1 FORCE, algorithm=COPY;| |
connection default; |
Backtrace:
Thread 1 (Thread 0x7ffff11fd700 (LWP 7099)):
|
#0 0x00007ffff6453d2b in raise () from /lib64/libc.so.6
|
#1 0x00007ffff6455394 in abort () from /lib64/libc.so.6
|
#2 0x000000000172677e in ut_dbg_assertion_failed (expr=0x19ab8ef "opt_no_lock", file=0x19ab2e8 "/my/maria-10.11/extra/mariabackup/xtrabackup.cc", line=1214) at /my/maria-10.11/storage/innobase/ut/ut0dbg.cc:60
|
#3 0x000000000089aa9f in backup_file_op_fail (space_id=6, type=144, name=0x7ffff120e016 "", len=28, new_name=0x0, new_len=0) at /my/maria-10.11/extra/mariabackup/xtrabackup.cc:1214
|
#4 0x000000000158b23e in recv_sys_t::parse<recv_buf, (recv_sys_t::store)1> (this=0x260fc80 <recv_sys>, l=..., if_exists=false) at /my/maria-10.11/storage/innobase/log/log0recv.cc:3072
|
#5 0x00000000015869c8 in recv_sys_t::parse_mtr<(recv_sys_t::store)1> (if_exists=false) at /my/maria-10.11/storage/innobase/log/log0recv.cc:3115
|
#6 0x00000000015869e2 in recv_sys_t::parse_mmap<(recv_sys_t::store)1> (if_exists=false) at /my/maria-10.11/storage/innobase/log/log0recv.cc:3127
|
#7 0x000000000089e9ea in xtrabackup_copy_mmap_logfile () at /my/maria-10.11/extra/mariabackup/xtrabackup.cc:3423
|
#8 0x000000000089edee in xtrabackup_copy_logfile () at /my/maria-10.11/extra/mariabackup/xtrabackup.cc:3487
|
#9 0x000000000089f88f in log_copying_thread () at /my/maria-10.11/extra/mariabackup/xtrabackup.cc:3654
|
#10 0x00000000008b7e80 in std::__invoke_impl<void, void (*)()> (__f=@0x3299698: 0x89f862 <log_copying_thread()>) at /usr/include/c++/7/bits/invoke.h:60
|
#11 0x00000000008b311a in std::__invoke<void (*)()> (__fn=@0x3299698: 0x89f862 <log_copying_thread()>) at /usr/include/c++/7/bits/invoke.h:95
|
#12 0x00000000008c79f2 in std::thread::_Invoker<std::tuple<void (*)()> >::_M_invoke<0ul> (this=0x3299698) at /usr/include/c++/7/thread:234
|
#13 0x00000000008c79c3 in std::thread::_Invoker<std::tuple<void (*)()> >::operator() (this=0x3299698) at /usr/include/c++/7/thread:243
|
#14 0x00000000008c79a2 in std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)()> > >::_M_run (this=0x3299690) at /usr/include/c++/7/thread:186
|
#15 0x00007ffff609f713 in ?? () from /usr/lib64/libstdc++.so.6
|
#16 0x00007ffff75256ea in start_thread () from /lib64/libpthread.so.0
|
#17 0x00007ffff652150f in clone () from /lib64/libc.so.6
|
The code where it fails:
1213
|
if (fail) { |
1214
|
ut_a(opt_no_lock);
|
1215
|
die("DDL operation detected in the late phase of backup." |
1216
|
"Backup is inconsistent. Remove --no-lock option to fix."); |
I checked with gdb that opt_no_lock == 0
'type' in backup_file_op_fail(uint32_t space_id, int type..) is 144 == FILE_DELETE
spacename = "mysql/innodb_table_stats"
Attachments
Activity
The bug was that backup_file_op_fail() was using a static variable initialized by arguments.
This does not work as the static variables will only be initialized on the first call and after that
has a wrong value.
Fixed by removing 'static'.
Here is the stack traces to all calls to file_space_t::drop():
fil/fil0fil.cc:1612(fil_space_t::drop(unsigned int, pfs_os_file_t*))[0x1644240]
fil/fil0fil.cc:1702(fil_delete_tablespace(unsigned int))[0x16449d7]
dict/drop.cc:281(trx_t::commit(std::vector<pfs_os_file_t, std::allocator<pfs_os_file_t> >&))[0x1638389]
handler/ha_innodb.cc:13716(ha_innobase::delete_table(char const*))[0x12b26c6]
sql/handler.cc:582(hton_drop_table(handlerton*, char const*))[0xd6b005]
sql/temporary_tables.cc:707(THD::rm_temporary_table(handlerton*, char const*))[0xc9aecd]
sql/temporary_tables.cc:1483(THD::free_tmp_table_share(TMP_TABLE_SHARE*, bool))[0xc9cd7b]
sql/temporary_tables.cc:675(THD::drop_temporary_table(TABLE*, bool*, bool))[0xc9ad77]
sql/sql_table.cc:11783(mysql_alter_table(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, Table_specification_st*, TABLE_LIST*, Recreate_info*, Alter_info*, unsigned int, st_order*, bool, bool))[0xacd9fd]
sql/sql_alter.cc:688(Sql_cmd_alter_table::execute(THD*))[0xb84fca]
sql/sql_parse.cc:6153(mysql_execute_command(THD*, bool))[0x9a575e]
sql/sql_parse.cc:8174(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x9ab50a]
sql/sql_parse.cc:1908(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x998083]
Other call:
fil/fil0fil.cc:1612(fil_space_t::drop(unsigned int, pfs_os_file_t*))[0x1644240]
fil/fil0fil.cc:1702(fil_delete_tablespace(unsigned int))[0x16449d7]
dict/drop.cc:281(trx_t::commit(std::vector<pfs_os_file_t, std::allocator<pfs_os_file_t> >&))[0x1638389]
handler/ha_innodb.cc:13716(ha_innobase::delete_table(char const*))[0x12b26c6]
sql/handler.cc:582(hton_drop_table(handlerton*, char const*))[0xd6b005]
sql/handler.cc:3224(ha_delete_table(THD*, handlerton*, char const*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, bool))[0xd713fa]
sql/sql_table.cc:1637(mysql_rm_table_no_locks(THD*, TABLE_LIST*, st_mysql_const_lex_string const*, st_ddl_log_state*, bool, bool, bool, bool, bool, bool))[0xab0501]
sql/sql_table.cc:1211(mysql_rm_table(THD*, TABLE_LIST*, bool, bool, bool, bool))[0xaaf3f6]
sql/sql_parse.cc:5057(mysql_execute_command(THD*, bool))[0x9a17be]
sql/sql_parse.cc:8174(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x9ab50a]