Race condition between drop table and encryption thread

2022-08-08 11:24:29 13 [ERROR] InnoDB: Operating system error number 9 in a file operation.

2022-08-08 11:24:29 13 [ERROR] InnoDB: Error number 9 means 'Bad file descriptor'

2022-08-08 11:24:29 13 [Note] InnoDB: Some operating system error numbers are described at https://mariadb.com/kb/en/library/operating-system-error-codes/

2022-08-08 11:24:29 13 [ERROR] InnoDB: File (unknown): 'close' returned OS error 209. Cannot continue operation

220808 11:24:29 [ERROR] mysqld got signal 6 ;

Thread 11 hit Breakpoint 4, fil_space_t::set_closing (

    this=0x2f157c5d18a8)

    at /home/mariadb/error9/10.6/storage/innobase/include/fil0fil.h:635

635	    return n_pending.fetch_or(CLOSING, std::memory_order_acquire) &

(rr) p id

$10 = 1427

(rr) p /x n_pending

$6 = {<std::__atomic_base<unsigned int>> = {static _S_alignment = 0x4, 

    _M_i = 0x80000000}, <No data fields>}

(rr) where

#0  fil_space_t::set_closing (this=0x2f157c5d18a8)

    at /home/mariadb/error9/10.6/storage/innobase/include/fil0fil.h:635

#1  0x000056421354b284 in fil_space_t::try_to_close (print_info=false)

    at /home/mariadb/error9/10.6/storage/innobase/fil/fil0fil.cc:103

#2  0x000056421354c1d8 in fil_node_open_file (node=0x2f157c1afc38)

    at /home/mariadb/error9/10.6/storage/innobase/fil/fil0fil.cc:425

#3  0x000056421354d3a8 in fil_space_t::prepare_acquired (

    this=0x2f157c2b4a18)

    at /home/mariadb/error9/10.6/storage/innobase/fil/fil0fil.cc:659

#4  0x0000564213563aa7 in fil_space_t::acquire_if_not_stopped (

    this=0x2f157c2b4a18)

    at /home/mariadb/error9/10.6/storage/innobase/fil/fil0crypt.cc:1345

#5  0x0000564213563dc9 in fil_system_t::default_encrypt_next (

    this=0x564214fb3e40 <fil_system>, space=0x2f157c2b4a18, 

    recheck=false, encrypt=true)

    at /home/mariadb/error9/10.6/storage/innobase/fil/fil0crypt.cc:1411

#6  0x0000564213560529 in fil_space_t::next (space=..., recheck=false, 

    encrypt=true)

    at /home/mariadb/error9/10.6/storage/innobase/fil/fil0crypt.cc:1438

#7  0x0000564213560a47 in fil_crypt_find_space_to_rotate (

    key_state=0x3d626e757be4, state=0x3d626e757bf0, 

    recheck=0x3d626e757bd7)

    at /home/mariadb/error9/10.6/storage/innobase/fil/fil0crypt.cc:1535

#8  0x0000564213562261 in fil_crypt_thread ()

    at /home/mariadb/error9/10.6/storage/innobase/fil/fil0crypt.cc:2034

#9  0x00005642134e63fa in std::__invoke_impl<void, void (*)()> (

    __f=@0x5642170f56d8: 0x564213562176 <fil_crypt_thread()>)

    at /usr/include/c++/7/bits/invoke.h:60

#10 0x00005642134e6101 in std::__invoke<void (*)()> (

    __fn=@0x5642170f56d8: 0x564213562176 <fil_crypt_thread()>)

    at /usr/include/c++/7/bits/invoke.h:95

#11 0x00005642134e6978 in std::thread::_Invoker<std::tuple<void (*)()> >::_M_invoke<0ul> (this=0x5642170f56d8) at /usr/include/c++/7/thread:234

#12 0x00005642134e6949 in std::thread::_Invoker<std::tuple<void (*)()> >::operator() (this=0x5642170f56d8) at /usr/include/c++/7/thread:243

#13 0x00005642134e6928 in std::thread::_State_impl<std::thread::_Invoker---Type <return> to continue, or q <return> to quit---

<std::tuple<void (*)()> > >::_M_run (this=0x5642170f56d0)

    at /usr/include/c++/7/thread:186

#14 0x00007ffe63d316df in ?? ()

   from /usr/lib/x86_64-linux-gnu/libstdc++.so.6

#15 0x00007f8d2bbed6db in start_thread (arg=0x3d626e758700)

    at pthread_create.c:463

#16 0x000024681c88161f in clone ()

    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

(rr) p /x n_pending

$7 = {<std::__atomic_base<unsigned int>> = {static _S_alignment = 0x4, _M_i = 0x80000000}, <No data fields>}

(rr) f 1

#1  0x000056421354b284 in fil_space_t::try_to_close (print_info=false) at /home/mariadb/error9/10.6/storage/innobase/fil/fil0fil.cc:103

103	    if (const auto n= space.set_closing())

(rr) p node->name

$9 = 0x2f157c5d1a08 "./test/tmp27.ibd"

After set_closing():

====================

(rr) p/x space->n_pending

$12 = {<std::__atomic_base<unsigned int>> = {static _S_alignment = 0x4, _M_i = 0xc0000000}, <No data fields>}

(rr) t 2

[Switching to thread 2 (Thread 51839.51932)]

#0  0x0000000070000002 in syscall_traced ()

(rr) where

#0  0x0000000070000002 in syscall_traced ()

#1  0x00007f8d2c2451a4 in _raw_syscall () at /home/roc/rr/rr/src/preload/raw_syscall.S:120

#2  0x00007f8d2c2402ce in traced_raw_syscall (call=<optimized out>) at /home/roc/rr/rr/src/preload/syscallbuf.c:278

#3  0x00007f8d2c2440d3 in syscall_hook_internal (call=0x7f8d287d1fa0) at /home/roc/rr/rr/src/preload/syscallbuf.c:3420

#4  syscall_hook (call=0x7f8d287d1fa0) at /home/roc/rr/rr/src/preload/syscallbuf.c:3454

#5  0x00007f8d2c2400b0 in _syscall_hook_trampoline () at /home/roc/rr/rr/src/preload/syscall_hook.S:313

#6  0x00007f8d2c24010f in __morestack () at /home/roc/rr/rr/src/preload/syscall_hook.S:458

#7  0x00007f8d2c24012b in _syscall_hook_trampoline_48_3d_00_f0_ff_ff () at /home/roc/rr/rr/src/preload/syscall_hook.S:477

#8  0x000024681c876fcd in fdatasync (fd=9) at ../sysdeps/unix/sysv/linux/fdatasync.c:28

#9  0x00005642132eca40 in os_file_sync_posix (file=9) at /home/mariadb/error9/10.6/storage/innobase/os/os0file.cc:839

#10 0x00005642132ecdc5 in os_file_flush_func (file=9) at /home/mariadb/error9/10.6/storage/innobase/os/os0file.cc:924

#11 0x00005642132a6bd4 in pfs_os_file_flush_func (file=..., src_file=0x564213c0f5d0 "/home/mariadb/error9/10.6/storage/innobase/log/log0log.cc", 

    src_line=289) at /home/mariadb/error9/10.6/storage/innobase/include/os0file.inl:347

#12 0x00005642132a809d in file_os_io::flush (this=0x564216fefb90) at /home/mariadb/error9/10.6/storage/innobase/log/log0log.cc:289

#13 0x00005642132a8567 in log_file_t::flush (this=0x564214f74060 <log_sys+480>) at /home/mariadb/error9/10.6/storage/innobase/log/log0log.cc:463

#14 0x00005642132a8d8b in log_t::file::flush (this=0x564214f74040 <log_sys+448>) at /home/mariadb/error9/10.6/storage/innobase/log/log0log.cc:530

#15 0x00005642132a9631 in log_write_flush_to_disk_low (lsn=6903017) at /home/mariadb/error9/10.6/storage/innobase/log/log0log.cc:649

#16 0x00005642132aa3fe in log_write_and_flush () at /home/mariadb/error9/10.6/storage/innobase/log/log0log.cc:903

#17 0x00005642132ded03 in mtr_t::commit_file (this=0x7f8d2c571f20, space=..., name=0x0)

    at /home/mariadb/error9/10.6/storage/innobase/mtr/mtr0mtr.cc:660

#18 0x0000564213551506 in fil_delete_tablespace (id=1427) at /home/mariadb/error9/10.6/storage/innobase/fil/fil0fil.cc:1651

#19 0x0000564213545e54 in trx_t::commit (this=0x4d933b25cb80, deleted=std::vector of length 0, capacity 0)

    at /home/mariadb/error9/10.6/storage/innobase/dict/drop.cc:274

#20 0x00005642131eac35 in ha_innobase::delete_table (this=0x2f157cdfc248, name=0x7f8d2c573460 "./test/tmp27")

    at /home/mariadb/error9/10.6/storage/innobase/handler/ha_innodb.cc:13757

#21 0x0000564212d81099 in hton_drop_table (hton=0x564216bde128, path=0x7f8d2c573460 "./test/tmp27")

    at /home/mariadb/error9/10.6/sql/handler.cc:576

#22 0x0000564212d87453 in ha_delete_table (thd=0x2f157c000d78, hton=0x564216bde128, path=0x7f8d2c573460 "./test/tmp27", db=0x2f157c016c88, 

    alias=0x2f157c016c98, generate_warning=false) at /home/mariadb/error9/10.6/sql/handler.cc:3121

#23 0x0000564212add0ca in quick_rm_table (thd=0x2f157c000d78, base=0x564216bde128, db=0x2f157c016c88, table_name=0x2f157c016c98, flags=0, 

    table_path=0x0) at /home/mariadb/error9/10.6/sql/sql_table.cc:1912

#24 0x000056421293b197 in drop_open_table (thd=0x2f157c000d78, table=0x2f157cdf91a8, db_name=0x2f157c016c88, table_name=0x2f157c016c98)

    at /home/mariadb/error9/10.6/sql/sql_base.cc:1396

#25 0x00005642129a5cd9 in select_create::abort_result_set (this=0x2f157c019d98) at /home/mariadb/error9/10.6/sql/sql_insert.cc:5224

#26 0x0000564212a33845 in handle_select (thd=0x2f157c000d78, lex=0x2f157c005018, result=0x2f157c019d98, setup_tables_done_option=0)

    at /home/mariadb/error9/10.6/sql/sql_select.cc:572

---Type <return> to continue, or q <return> to quit---

#27 0x0000564212afb439 in Sql_cmd_create_table_like::execute (this=0x2f157c016c10, thd=0x2f157c000d78)

    at /home/mariadb/error9/10.6/sql/sql_table.cc:11810

#28 0x00005642129f3442 in mysql_execute_command (thd=0x2f157c000d78, is_called_from_prepared_stmt=false)

    at /home/mariadb/error9/10.6/sql/sql_parse.cc:5997

#29 0x00005642129f94f8 in mysql_parse (thd=0x2f157c000d78, 

    rawbuf=0x2f157c0167a0 "CREATE /* QNO 996 CON_ID 13 */ TABLE tmp27 AS /* `table10_innodb_int_autoinc` */ SELECT DISTINCT BIT_OR( NULL ) AS field1 FROM table10_innodb_int_autoinc GROUP BY /* VALUES( `col_varchar_355_utf8_full"..., length=520, parser_state=0x7f8d2c5743c0)

    at /home/mariadb/error9/10.6/sql/sql_parse.cc:8030

#30 0x00005642129e5987 in dispatch_command (command=COM_QUERY, thd=0x2f157c000d78, 

    packet=0x2f157c00b729 "CREATE /* QNO 996 CON_ID 13 */ TABLE tmp27 AS /* `table10_innodb_int_autoinc` */ SELECT DISTINCT BIT_OR( NULL ) AS field1 FROM table10_innodb_int_autoinc GROUP BY /* VALUES( `col_varchar_355_utf8_full"..., packet_length=521, blocking=true)

    at /home/mariadb/error9/10.6/sql/sql_parse.cc:1896

#31 0x00005642129e4295 in do_command (thd=0x2f157c000d78, blocking=true) at /home/mariadb/error9/10.6/sql/sql_parse.cc:1409

#32 0x0000564212b9f6d5 in do_handle_one_connection (connect=0x56421710f9a8, put_in_cache=true)

    at /home/mariadb/error9/10.6/sql/sql_connect.cc:1418

#33 0x0000564212b9f370 in handle_one_connection (arg=0x56421720dcf8) at /home/mariadb/error9/10.6/sql/sql_connect.cc:1312

#34 0x0000564213101ae3 in pfs_spawn_thread (arg=0x564216bce4f8) at /home/mariadb/error9/10.6/storage/perfschema/pfs.cc:2201

#35 0x00007f8d2bbed6db in start_thread (arg=0x7f8d2c575700) at pthread_create.c:463

#36 0x000024681c88161f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

(rr) p space->id

$13 = 1427

(rr) p *(fil_node_t*) space->chain->start

$14 = {space = 0x2f157c5d18a8, name = 0x2f157c5d1a08 "./test/tmp27.ibd", handle = {m_file = 299, m_psi = 0x0}, on_ssd = 0, punch_hole = 0, 

  atomic_write = 0, is_raw_disk = 0, deferred = 0, size = 6, init_size = 4, max_size = 4294967295, being_extended = {m = {_M_base = {

        static _S_alignment = 1, _M_i = false}}}, chain = {prev = 0x0, next = 0x0}, block_size = 4096}