[MDEV-26296] Galera test failure on galera_unicode_identifiers Created: 2021-08-03  Updated: 2023-04-04  Resolved: 2023-04-04

Status: Closed
Project: MariaDB Server
Component/s: Galera, Tests
Affects Version/s: 10.6
Fix Version/s: N/A

Type: Bug Priority: Critical
Reporter: Jan Lindström (Inactive) Assignee: Jan Lindström
Resolution: Cannot Reproduce Votes: 0
Labels: affects-tests


 Description   

galera.galera_unicode_identifiers 'innodb' w1 [ fail ]  timeout after 900 seconds
        Test ended at 2021-07-27 02:41:03
 
Test case timeout after 900 seconds
 
== /dev/shm/var/1/log/galera_unicode_identifiers.log == 
UNIQUE `index name with space` (`second column with space`)
) engine=innodb;
INSERT INTO `table with space` VALUES (1, 1);
CREATE DATABASE `база`;
USE `база`;
CREATE TABLE `таблица` (
`първа_колона` INTEGER PRIMARY KEY,
`втора_колона` INTEGER,
UNIQUE `индекс` (`втора_колона`)
) engine=innodb;
INSERT INTO `таблица` VALUES (1, 1);
CREATE DATABASE `втора база`;
USE `втора база`;
CREATE TABLE `втора таблица` (
`първа колона` INTEGER,
`втора колона` INTEGER,
KEY `първи индекс` (`първа колона`)
) engine=innodb;
INSERT INTO `втора таблица` VALUES (1, 1);
connection node_2;
 
 == /dev/shm/var/1/tmp/analyze-timeout-mysqld.2.err ==
mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to local server through socket '/dev/shm/var/tmp/1/mysqld.2.sock' (111)
 
 == /dev/shm/var/1/tmp/analyze-timeout-mysqld.1.err ==
mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to local server through socket '/dev/shm/var/tmp/1/mysqld.1.sock' (111)
 
 
 - found 'core' (0/0)
 
Trying 'dbx' to get a backtrace
 
Trying 'gdb' to get a backtrace from coredump /dev/shm/var/1/log/galera.galera_unicode_identifiers-innodb/mysqld.2/data/core
Core generated by '/usr/sbin/mariadbd'
Output from gdb follows. The first stack trace is from the failing thread.
The following stack traces are from all threads (so the failing one is
duplicated).
--------------------------
 
warning: Can't open file anon_inode:[io_uring] which was expanded to anon_inode:[io_uring] during file-backed mapping note processing
 
warning: Can't open file anon_inode:[io_uring] which was expanded to anon_inode:[io_uring] during file-backed mapping note processing
 
warning: Can't open file /dev/shm/var/1/mysqld.2/data/galera.cache during file-backed mapping note processing
 
warning: Can't open file /dev/shm/var/1/mysqld.2/data/tc.log during file-backed mapping note processing
[New LWP 20254]
[New LWP 20255]
[New LWP 20256]
[New LWP 20518]
[New LWP 20522]
[New LWP 20525]
[New LWP 20529]
[New LWP 20260]
[New LWP 21543]
[New LWP 20257]
[New LWP 20258]
[New LWP 20259]
[New LWP 20528]
[New LWP 20530]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/sbin/mariadbd --defaults-group-suffix=.2 --defaults-file=/dev/shm/var/1/my'.
Program terminated with signal SIGABRT, Aborted.
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
56	../sysdeps/unix/sysv/linux/pthread_kill.c: No such file or directory.
[Current thread is 1 (Thread 0x7f80a4f9c040 (LWP 20254))]
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
#1  0x0000562d1cdc9b49 in my_write_core (sig=sig@entry=6) at ./mysys/stacktrace.c:424
#2  0x0000562d1c896380 in handle_fatal_signal (sig=6) at ./sql/signal_handler.cc:344
#3  <signal handler called>
#4  0x00007f80a53863ff in __GI___poll (fds=0x562d1ffb9208, nfds=2, timeout=timeout@entry=-1) at ../sysdeps/unix/sysv/linux/poll.c:29
#5  0x0000562d1c59eeaa in poll (__timeout=-1, __nfds=<optimized out>, __fds=<optimized out>) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
#6  handle_connections_sockets () at ./sql/mysqld.cc:6110
#7  0x0000562d1c59fec8 in mysqld_main (argc=<optimized out>, argv=<optimized out>) at ./sql/mysqld.cc:5815
#8  0x00007f80a52b9d0a in __libc_start_main (main=0x562d1c564df0 <main(int, char**)>, argc=23, argv=0x7ffcf97de298, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffcf97de288) at ../csu/libc-start.c:308
#9  0x0000562d1c5947ca in _start () at ./sql/my_decimal.h:147
 
Thread 14 (Thread 0x7f80716fe700 (LWP 20530)):
#0  futex_abstimed_wait_cancelable (private=0, abstime=0x7f80716fdd60, clockid=1903156288, expected=0, futex_word=0x562d1d63eaac <thread_cache+44>) at ../sysdeps/nptl/futex-internal.h:323
#1  __pthread_cond_wait_common (abstime=0x7f80716fdd60, clockid=1903156288, mutex=0x562d1d63eaf0 <thread_cache+112>, cond=0x562d1d63ea80 <thread_cache>) at pthread_cond_wait.c:520
#2  __pthread_cond_timedwait (cond=cond@entry=0x562d1d63ea80 <thread_cache>, mutex=mutex@entry=0x562d1d63eaf0 <thread_cache+112>, abstime=abstime@entry=0x7f80716fdd60) at pthread_cond_wait.c:656
#3  0x0000562d1c55d0ee in psi_cond_timedwait (that=that@entry=0x562d1d63ea80 <thread_cache>, mutex=mutex@entry=0x562d1d63eaf0 <thread_cache+112>, abstime=abstime@entry=0x7f80716fdd60, file=file@entry=0x562d1ce694cb "./sql/thread_cache.h", line=line@entry=176) at ./mysys/my_thr_init.c:609
#4  0x0000562d1c4febdb in inline_mysql_cond_timedwait (src_file=0x562d1ce694cb "./sql/thread_cache.h", src_line=176, abstime=0x7f80716fdd60, mutex=<optimized out>, that=<optimized out>) at ./include/mysql/psi/mysql_thread.h:1086
#5  Thread_cache::park (this=<optimized out>) at ./sql/thread_cache.h:176
#6  do_handle_one_connection (connect=<optimized out>, put_in_cache=true) at ./sql/sql_connect.cc:1423
#7  0x0000562d1c77e1ad in handle_one_connection (arg=arg@entry=0x562d1ffaeac8) at ./sql/sql_connect.cc:1312
#8  0x0000562d1cacf0e9 in pfs_spawn_thread (arg=0x562d1ffdee68) at ./storage/perfschema/pfs.cc:2201
#9  0x00007f80a5779ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#10 0x00007f80a5390def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 13 (Thread 0x7f8071794700 (LWP 20528)):
#0  0x00007f80a52cfba2 in __GI___sigtimedwait (set=set@entry=0x7f8071793c70, info=info@entry=0x7f8071793cf0, timeout=timeout@entry=0x0) at ../sysdeps/unix/sysv/linux/sigtimedwait.c:29
#1  0x00007f80a52cfc07 in __GI___sigwaitinfo (set=set@entry=0x7f8071793c70, info=info@entry=0x7f8071793cf0) at ../sysdeps/unix/sysv/linux/sigwaitinfo.c:25
#2  0x0000562d1c596f03 in my_sigwait (code=<synthetic pointer>, sig=0x7f8071793c68, set=0x7f8071793c70) at ./include/my_pthread.h:195
#3  signal_hand (arg=arg@entry=0x0) at ./sql/mysqld.cc:3111
#4  0x0000562d1cacf0e9 in pfs_spawn_thread (arg=0x562d1ff1c098) at ./storage/perfschema/pfs.cc:2201
#5  0x00007f80a5779ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#6  0x00007f80a5390def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 12 (Thread 0x7f80a01f6700 (LWP 20259)):
#0  futex_wait_cancelable (private=0, expected=0, futex_word=0x7f80880133f4) at ../sysdeps/nptl/futex-internal.h:186
#1  __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x7f8088013398, cond=0x7f80880133c8) at pthread_cond_wait.c:508
#2  __pthread_cond_wait (cond=cond@entry=0x7f80880133c8, mutex=mutex@entry=0x7f8088013398) at pthread_cond_wait.c:638
#3  0x0000562d1cb4c771 in inline_mysql_cond_wait (src_file=0x562d1cff35e2 "./sql/wsrep_thd.h", src_line=69, mutex=0x7f8088013398, that=0x7f80880133c8) at ./include/mysql/psi/mysql_thread.h:1072
#4  Wsrep_thd_queue::pop_front (this=0x7f8088013340) at ./sql/wsrep_thd.h:69
#5  wsrep_rollback_process (rollbacker=0x7f8088000c58, arg=<optimized out>) at ./sql/wsrep_thd.cc:236
#6  0x0000562d1cb3e3bf in start_wsrep_THD (arg=arg@entry=0x562d1fa14560) at ./sql/wsrep_mysqld.h:579
#7  0x0000562d1cacf0e9 in pfs_spawn_thread (arg=0x562d1fa017e8) at ./storage/perfschema/pfs.cc:2201
#8  0x00007f80a5779ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#9  0x00007f80a5390def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 11 (Thread 0x7f8091ffa700 (LWP 20258)):
#0  futex_wait_cancelable (private=0, expected=0, futex_word=0x562d1f9abbc8) at ../sysdeps/nptl/futex-internal.h:186
#1  __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x562d1f9abb78, cond=0x562d1f9abba0) at pthread_cond_wait.c:508
#2  __pthread_cond_wait (cond=cond@entry=0x562d1f9abba0, mutex=mutex@entry=0x562d1f9abb78) at pthread_cond_wait.c:638
#3  0x00007f80a0c0173d in gu::Lock::wait (this=<synthetic pointer>, this=<synthetic pointer>, cond=@0x562d1f9abba0: {cond = {__data = {{__wseq = 1070, __wseq32 = {__low = 1070, __high = 0}}, {__g1_start = 1066, __g1_start32 = {__low = 1066, __high = 0}}, __g_refs = {2, 0}, __g_size = {0, 0}, __g1_orig_size = 4, __wrefs = 8, __g_signals = {0, 0}}, __size = ".\004\000\000\000\000\000\000*\004\000\000\000\000\000\000\002", '\000' <repeats 15 times>, "\004\000\000\000\b\000\000\000\000\000\000\000\000\000\000", __align = 1070}, ref_count = 1}) at ./galerautils/src/gu_mutex.hpp:86
#4  RecvBuf::front (timeout=<optimized out>, this=0x562d1f9abb78) at ./gcs/src/gcs_gcomm.cpp:114
#5  gcomm_recv (backend=<optimized out>, msg=0x562d1f9e94f0, timeout=9223372035999999999) at ./gcs/src/gcs_gcomm.cpp:610
#6  0x00007f80a0befe7d in core_msg_recv (timeout=9223372035999999999, recv_msg=0x562d1f9e94f0, backend=0x562d1f9e9650) at ./gcs/src/gcs_core.cpp:480
#7  gcs_core_recv (conn=0x562d1f9e9490, recv_act=recv_act@entry=0x7f8091ff9ce0, timeout=<optimized out>) at ./gcs/src/gcs_core.cpp:1201
#8  0x00007f80a0beb572 in gcs_recv_thread (arg=<optimized out>) at ./gcs/src/gcs.cpp:1413
#9  0x00007f80a5779ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#10 0x00007f80a5390def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 10 (Thread 0x7f80927fb700 (LWP 20257)):
#0  0x00007f80a5391116 in epoll_wait (epfd=6, events=events@entry=0x7f80927fa3e0, maxevents=maxevents@entry=128, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
#1  0x00007f80a0cd6f1f in asio::detail::epoll_reactor::run (this=0x562d1f9d10a0, block=block@entry=true, ops=@0x7f80927faae8: {<asio::detail::noncopyable> = {<No data fields>}, front_ = 0x0, back_ = 0x0}) at ./asio/asio/detail/impl/epoll_reactor.ipp:391
#2  0x00007f80a0cd7989 in asio::detail::task_io_service::do_run_one (this=this@entry=0x562d1fa14a30, lock=@0x7f80927faab0: {<asio::detail::noncopyable> = {<No data fields>}, mutex_ = @0x562d1fa14a60, locked_ = false}, this_thread=@0x7f80927faae0: {<asio::detail::thread_info_base> = {<asio::detail::noncopyable> = {<No data fields>}, reusable_memory_ = 0x0}, private_op_queue = {<asio::detail::noncopyable> = {<No data fields>}, front_ = 0x0, back_ = 0x0}, private_outstanding_work = 0}, ec=@0x7f80927faaa0: {_M_value = 0, _M_cat = 0x7f80a5767160}) at ./asio/asio/detail/impl/task_io_service.ipp:355
#3  0x00007f80a0cd1771 in asio::detail::task_io_service::run (ec=@0x7f80927faaa0: {_M_value = 0, _M_cat = 0x7f80a5767160}, this=0x562d1fa14a30) at ./asio/asio/detail/impl/task_io_service.ipp:148
#4  asio::io_service::run (this=<optimized out>, this=<optimized out>) at ./asio/asio/impl/io_service.ipp:58
#5  gu::AsioIoService::run (this=<optimized out>) at ./galerautils/src/gu_asio.cpp:700
#6  0x00007f80a0c05cc3 in GCommConn::run (this=0x562d1f9ab980) at ./gcs/src/gcs_gcomm.cpp:435
#7  0x00007f80a0c06289 in run_fn (arg=<optimized out>) at ./gcs/src/gcs_gcomm.cpp:304
#8  0x00007f80a5779ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#9  0x00007f80a5390def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 9 (Thread 0x7f8073fff700 (LWP 21543)):
#0  syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1  0x0000562d1cc5ac73 in srw_mutex::wait (lk=<optimized out>, this=0x562d1d5bd008 <dict_sys+72>) at ./storage/innobase/sync/srw_lock.cc:224
#2  srw_mutex::wait_and_lock (this=this@entry=0x562d1d5bd008 <dict_sys+72>) at ./storage/innobase/sync/srw_lock.cc:262
#3  0x0000562d1cc5b0bf in srw_mutex::wr_lock (this=0x562d1d5bd008 <dict_sys+72>) at ./storage/innobase/include/srw_lock.h:70
#4  ssux_lock_low::wr_lock (this=0x562d1d5bd008 <dict_sys+72>) at ./storage/innobase/include/srw_lock.h:212
#5  srw_lock::psi_wr_lock (this=this@entry=0x562d1d5bd000 <dict_sys+64>, file=file@entry=0x562d1d01b1a8 "./storage/innobase/dict/dict0dict.cc", line=line@entry=1366) at ./storage/innobase/sync/srw_lock.cc:328
#6  0x0000562d1cce7105 in srw_lock::wr_lock (line=1366, file=0x562d1d01b1a8 "./storage/innobase/dict/dict0dict.cc", this=0x562d1d5bd000 <dict_sys+64>) at ./storage/innobase/include/srw_lock.h:423
#7  dict_sys_t::lock (line=1366, file=0x562d1d01b1a8 "./storage/innobase/dict/dict0dict.cc", this=0x562d1d5bcfc0 <dict_sys>) at ./storage/innobase/dict/dict0dict.cc:1071
#8  dict_sys_t::evict_table_LRU (this=0x562d1d5bcfc0 <dict_sys>, half=half@entry=false) at ./storage/innobase/dict/dict0dict.cc:1366
#9  0x0000562d1cc582e8 in srv_master_do_idle_tasks (counter_time=646228731) at ./storage/innobase/srv/srv0srv.cc:1584
#10 srv_master_callback () at ./storage/innobase/srv/srv0srv.cc:1641
#11 0x0000562d1cd618cb in tpool::thread_pool_generic::timer_generic::run (this=0x562d1fa50ca0) at ./tpool/tpool_generic.cc:313
#12 tpool::thread_pool_generic::timer_generic::execute (arg=0x562d1fa50ca0) at ./tpool/tpool_generic.cc:333
#13 0x0000562d1cd62782 in tpool::task::execute (this=0x562d1fa50ce0) at ./tpool/task.cc:52
#14 tpool::task::execute (this=0x562d1fa50ce0) at ./tpool/task.cc:42
#15 0x0000562d1cd6168f in tpool::thread_pool_generic::worker_main (this=0x562d1fa5d380, thread_var=0x562d1fa922c0) at ./tpool/tpool_generic.cc:550
#16 0x00007f80a566ced0 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
#17 0x00007f80a5779ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#18 0x00007f80a5390def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 8 (Thread 0x7f80a01ab700 (LWP 20260)):
#0  syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1  0x0000562d1cc5ac73 in srw_mutex::wait (lk=<optimized out>, this=0x7f8071996938) at ./storage/innobase/sync/srw_lock.cc:224
#2  srw_mutex::wait_and_lock (this=this@entry=0x7f8071996938) at ./storage/innobase/sync/srw_lock.cc:262
#3  0x0000562d1cbda3fc in srw_mutex::wr_lock (this=0x7f8071996938) at ./storage/innobase/include/srw_lock.h:70
#4  ssux_lock_low::wr_lock (this=0x7f8071996938) at ./storage/innobase/include/srw_lock.h:212
#5  sux_lock<ssux_lock_low>::x_lock_upgraded (this=0x7f8071996938) at ./storage/innobase/include/sux_lock.h:412
#6  mtr_t::page_lock (this=this@entry=0x7f80a01a6510, block=block@entry=0x7f80719968c0, rw_latch=rw_latch@entry=2) at ./storage/innobase/mtr/mtr0mtr.cc:1076
#7  0x0000562d1ccc41c4 in buf_page_get_low (page_id={m_id = 12}, zip_size=<optimized out>, rw_latch=<optimized out>, guess=<optimized out>, mode=<optimized out>, mtr=<optimized out>, err=<optimized out>, allow_ibuf_merge=<optimized out>) at ./storage/innobase/buf/buf0buf.cc:2981
#8  0x0000562d1ccad07b in btr_cur_search_to_nth_level_func (index=index@entry=0x562d1fc553d0, level=level@entry=0, tuple=tuple@entry=0x7f8078011190, mode=mode@entry=PAGE_CUR_LE, latch_mode=<optimized out>, latch_mode@entry=2, cursor=cursor@entry=0x7f80a01a5de0, ahi_latch=<optimized out>, mtr=<optimized out>, autoinc=<optimized out>) at ./storage/innobase/btr/btr0cur.cc:1611
#9  0x0000562d1cc1b523 in btr_pcur_open_low (level=<optimized out>, mtr=0x7f80a01a6510, autoinc=<optimized out>, cursor=0x7f80a01a5de0, latch_mode=2, mode=PAGE_CUR_LE, tuple=0x7f8078011190, index=0x562d1fc553d0) at ./storage/innobase/include/btr0pcur.ic:439
#10 row_ins_clust_index_entry_low (flags=0, mode=2, index=0x562d1fc553d0, n_uniq=2, entry=0x7f8078011190, n_ext=0, thr=0x7f807c052020) at ./storage/innobase/row/row0ins.cc:2607
#11 0x0000562d1cc1d1b8 in row_ins_clust_index_entry (index=0x562d1fc553d0, entry=0x7f8078011190, thr=0x7f807c052020, n_ext=0) at ./storage/innobase/row/row0ins.cc:3235
#12 0x0000562d1cc1d9d5 in row_ins_index_entry (thr=0x7f807c052020, entry=<optimized out>, index=<optimized out>) at ./storage/innobase/row/row0ins.cc:3361
#13 row_ins_index_entry_step (thr=0x7f807c052020, node=0x7f807c051eb0) at ./storage/innobase/row/row0ins.cc:3529
#14 row_ins (thr=0x7f807c052020, node=0x7f807c051eb0) at ./storage/innobase/row/row0ins.cc:3675
#15 row_ins_step (thr=thr@entry=0x7f807c052020) at ./storage/innobase/row/row0ins.cc:3821
#16 0x0000562d1cc01bd6 in que_thr_step (thr=0x7f807c052020) at ./storage/innobase/que/que0que.cc:632
#17 que_run_threads_low (thr=<optimized out>) at ./storage/innobase/que/que0que.cc:709
#18 que_run_threads (thr=thr@entry=0x7f807c052020) at ./storage/innobase/que/que0que.cc:729
#19 0x0000562d1cc2ccc2 in row_create_index_for_mysql (index=<optimized out>, index@entry=0x7f807c038650, trx=trx@entry=0x7f8072998230, field_lengths=field_lengths@entry=0x7f807c044918, mode=<optimized out>, key_id=<optimized out>) at ./storage/innobase/row/row0mysql.cc:2394
#20 0x0000562d1cb890e2 in create_index (trx=<optimized out>, form=<optimized out>, table=<optimized out>, key_num=<optimized out>) at ./storage/innobase/handler/ha_innodb.cc:10946
#21 0x0000562d1cb86834 in create_table_info_t::create_table (this=0x7f80a01a73c0, create_fk=<optimized out>) at ./storage/innobase/handler/ha_innodb.cc:12617
#22 0x0000562d1cb8ad6d in ha_innobase::create (this=<optimized out>, name=0x7f80a01a8cc0 "./database@0020with@0020space/table@0020with@0020space", form=<optimized out>, create_info=<optimized out>, file_per_table=<optimized out>, trx=0x7f8072998230) at ./storage/innobase/handler/ha_innodb.cc:13135
#23 0x0000562d1c8a0080 in handler::ha_create (this=<optimized out>, name=<optimized out>, form=0x7f80a01a7960, info_arg=0x7f80a01a91b0) at ./sql/handler.cc:5405
#24 0x0000562d1c8a091a in ha_create_table (thd=thd@entry=0x7f807c000c58, path=<optimized out>, db=0x7f807c00cb58 "database with space", table_name=0x7f807c00c400 "table with space", create_info=create_info@entry=0x7f80a01a91b0, frm=frm@entry=0x7f80a01a8cb0, skip_frm_file=false) at ./sql/handler.cc:5870
#25 0x0000562d1c712e46 in create_table_impl (thd=thd@entry=0x7f807c000c58, ddl_log_state_create=ddl_log_state_create@entry=0x7f80a01a8f60, ddl_log_state_rm=<optimized out>, orig_db=@0x7f807c00c490: {str = 0x7f807c00cb58 "database with space", length = 19}, orig_table_name=@0x7f807c00c4a0: {str = 0x7f807c00c400 "table with space", length = 16}, db=@0x7f807c00c490: {str = 0x7f807c00cb58 "database with space", length = 19}, table_name=@0x7f807c00c4a0: {str = 0x7f807c00c400 "table with space", length = 16}, path=@0x7f80a01a8ca0: {str = 0x7f80a01a8cc0 "./database@0020with@0020space/table@0020with@0020space", length = 54}, options=<optimized out>, create_info=0x7f80a01a91b0, alter_info=0x7f80a01a90c0, create_table_mode=0, is_trans=0x7f80a01a8f5f, key_info=0x7f80a01a8c98, key_count=0x7f80a01a8c94, frm=0x7f80a01a8cb0) at ./sql/sql_table.cc:4447
#26 0x0000562d1c713354 in mysql_create_table_no_lock (thd=thd@entry=0x7f807c000c58, ddl_log_state_create=ddl_log_state_create@entry=0x7f80a01a8f60, ddl_log_state_rm=ddl_log_state_rm@entry=0x7f80a01a8f80, db=db@entry=0x7f807c00c490, table_name=table_name@entry=0x7f807c00c4a0, create_info=create_info@entry=0x7f80a01a91b0, alter_info=0x7f80a01a90c0, is_trans=0x7f80a01a8f5f, create_table_mode=0, table_list=0x7f807c00c478) at ./sql/sql_table.cc:4546
#27 0x0000562d1c713739 in mysql_create_table (thd=thd@entry=0x7f807c000c58, create_table=create_table@entry=0x7f807c00c478, create_info=create_info@entry=0x7f80a01a91b0, alter_info=alter_info@entry=0x7f80a01a90c0) at ./sql/sql_table.cc:4658
#28 0x0000562d1c714fc9 in Sql_cmd_create_table_like::execute (this=<optimized out>, thd=0x7f807c000c58) at ./sql/sql_table.cc:11778
#29 0x0000562d1c66fd79 in mysql_execute_command (thd=0x7f807c000c58, is_called_from_prepared_stmt=<optimized out>) at ./sql/sql_parse.cc:5993
#30 0x0000562d1c671007 in mysql_parse (thd=0x7f807c000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x7f80a01a9920) at ./sql/sql_parse.cc:8026
#31 0x0000562d1c9b19dc in Query_log_event::do_apply_event (this=0x7f807c0226f8, rgi=0x7f807c01d220, query_arg=0x7f807c025d32 "CREATE TABLE `table with space` (\n`column with space` INTEGER AUTO_INCREMENT PRIMARY KEY,\n`second column with space` INTEGER,\nUNIQUE `index name with space` (`second column with space`)\n) engine=innod"..., q_len_arg=<optimized out>) at ./sql/sql_class.h:233
#32 0x0000562d1cb4b769 in Log_event::apply_event (rgi=<optimized out>, this=0x7f807c0226f8) at ./sql/log_event.h:1516
#33 wsrep_apply_events (thd=thd@entry=0x7f807c000c58, rli=<optimized out>, events_buf=<optimized out>, buf_len=0) at ./sql/wsrep_applier.cc:208
#34 0x0000562d1cb3354c in apply_events (err=@0x7f80a01a9c80: {buffer_ = std::vector of length 0, capacity 0}, data=@0x7f80a01a9ce0: {ptr_ = 0x7f809420e2f0, size_ = 535}, rli=<optimized out>, thd=<optimized out>) at ./wsrep-lib/include/wsrep/buffer.hpp:47
#35 Wsrep_high_priority_service::apply_toi (this=0x7f80a01aacc0, ws_meta=<optimized out>, data=@0x7f80a01a9ce0: {ptr_ = 0x7f809420e2f0, size_ = 535}, err=@0x7f80a01a9c80: {buffer_ = std::vector of length 0, capacity 0}) at ./sql/wsrep_high_priority_service.cc:406
#36 0x0000562d1ce49934 in apply_toi (data=@0x7f80a01a9ce0: {ptr_ = 0x7f809420e2f0, size_ = 535}, ws_meta=@0x7f80a01a9d00: {gtid_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, id_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, data_ = {buf = '\000' <repeats 15 times>}}, data_ = {buf = '\000' <repeats 15 times>}}, seqno_ = {seqno_ = -1}}, id_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, data_ = {buf = '\000' <repeats 15 times>}}, data_ = {buf = "\244\n5S\356\242\021\353\260\330\322\064VHt\203"}}, seqno_ = {seqno_ = 2467}}, stid_ = {server_id_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, data_ = {buf = '\000' <repeats 15 times>}}, data_ = {buf = "\244\n\005(\356\242\021\353\207t\017e\004'\256\002"}}, transaction_id_ = {id_ = 18446744073709551615}, client_id_ = {id_ = 346}}, depends_on_ = {seqno_ = 2466}, flags_ = 11}, ws_handle=@0x7f80a01a9cf0: {transaction_id_ = {id_ = 18446744073709551615}, opaque_ = 0x7f807c039480}, high_priority_service=@0x7f80a01aacc0: {_vptr.high_priority_service = 0x562d1d566170 <vtable for Wsrep_applier_service+16>, server_state_ = @0x562d1f9a3060, must_exit_ = false}, provider=@0x562d1f8a6010: {_vptr.provider = 0x562d1d572138 <vtable for wsrep::wsrep_provider_v26+16>, server_state_ = @0x562d1f9a3060}) at ./wsrep-lib/src/server_state.cpp:461
#37 wsrep::server_state::on_apply (this=<optimized out>, high_priority_service=@0x7f80a01aacc0: {_vptr.high_priority_service = 0x562d1d566170 <vtable for Wsrep_applier_service+16>, server_state_ = @0x562d1f9a3060, must_exit_ = false}, ws_handle=@0x7f80a01a9cf0: {transaction_id_ = {id_ = 18446744073709551615}, opaque_ = 0x7f807c039480}, ws_meta=@0x7f80a01a9d00: {gtid_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, id_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, data_ = {buf = '\000' <repeats 15 times>}}, data_ = {buf = '\000' <repeats 15 times>}}, seqno_ = {seqno_ = -1}}, id_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, data_ = {buf = '\000' <repeats 15 times>}}, data_ = {buf = "\244\n5S\356\242\021\353\260\330\322\064VHt\203"}}, seqno_ = {seqno_ = 2467}}, stid_ = {server_id_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, data_ = {buf = '\000' <repeats 15 times>}}, data_ = {buf = "\244\n\005(\356\242\021\353\207t\017e\004'\256\002"}}, transaction_id_ = {id_ = 18446744073709551615}, client_id_ = {id_ = 346}}, depends_on_ = {seqno_ = 2466}, flags_ = 11}, data=<optimized out>) at ./wsrep-lib/src/server_state.cpp:1126
#38 0x0000562d1ce5a825 in wsrep::high_priority_service::apply (data=@0x7f80a01a9ce0: {ptr_ = 0x7f809420e2f0, size_ = 535}, ws_meta=@0x7f80a01a9d00: {gtid_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, id_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, data_ = {buf = '\000' <repeats 15 times>}}, data_ = {buf = '\000' <repeats 15 times>}}, seqno_ = {seqno_ = -1}}, id_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, data_ = {buf = '\000' <repeats 15 times>}}, data_ = {buf = "\244\n5S\356\242\021\353\260\330\322\064VHt\203"}}, seqno_ = {seqno_ = 2467}}, stid_ = {server_id_ = {static undefined_ = {static undefined_ = <same as static member of an already seen type>, data_ = {buf = '\000' <repeats 15 times>}}, data_ = {buf = "\244\n\005(\356\242\021\353\207t\017e\004'\256\002"}}, transaction_id_ = {id_ = 18446744073709551615}, client_id_ = {id_ = 346}}, depends_on_ = {seqno_ = 2466}, flags_ = 11}, ws_handle=@0x7f80a01a9cf0: {transaction_id_ = {id_ = 18446744073709551615}, opaque_ = 0x7f807c039480}, this=<optimized out>) at ./wsrep-lib/include/wsrep/high_priority_service.hpp:47
#39 (anonymous namespace)::apply_cb (ctx=ctx@entry=0x7f80a01aacc0, wsh=wsh@entry=0x7f80a01a9f30, flags=<optimized out>, flags@entry=69, buf=buf@entry=0x7f80a01a9f40, meta=meta@entry=0x7f80a01aa1f0, exit_loop=exit_loop@entry=0x7f80a01aa1af) at ./wsrep-lib/src/wsrep_provider_v26.cpp:504
#40 0x00007f80a0b8fae1 in galera::TrxHandleSlave::apply (this=this@entry=0x7f807c039480, recv_ctx=recv_ctx@entry=0x7f80a01aacc0, apply_cb=0x562d1ce5a720 <(anonymous namespace)::apply_cb(void*, wsrep_ws_handle_t const*, uint32_t, wsrep_buf_t const*, wsrep_trx_meta_t const*, wsrep_bool_t*)>, meta=@0x7f80a01aa1f0: {gtid = {uuid = {data = "\244\n5S\356\242\021\353\260\330\322\064VHt\203", alignment = 16938498817999047332}, seqno = 2467}, stid = {node = {data = "\244\n\005(\356\242\021\353\207t\017e\004'\256\002", alignment = 16938498817274481316}, trx = 18446744073709551615, conn = 346}, depends_on = 2466}, exit_loop=exit_loop@entry=@0x7f80a01aa1af: false) at ./galera/src/trx_handle.cpp:391
#41 0x00007f80a0b9e75f in galera::ReplicatorSMM::apply_trx (this=0x562d1f9d78a0, recv_ctx=0x7f80a01aacc0, ts=@0x7f807c039480: {<galera::TrxHandle> = {_vptr.TrxHandle = 0x7f80a0d61918 <vtable for galera::TrxHandleSlave+16>, static TRXHANDLE_FLAGS_MASK = 33791, static EXPLICIT_ROLLBACK_FLAGS = 10, static FLAGS_MATCH_API_FLAGS = true, static num_states_ = 12, state_ = {delete_ = false, trans_map_ = 0x7f80a0d66c00 <galera::TrxHandleSlave::trans_map_>, state_ = {first = galera::TrxHandle::S_COMMITTING, second = 1310}, state_hist_ = std::vector of length 3, capacity 4 = {{first = galera::TrxHandle::S_REPLICATING, second = 0}, {first = galera::TrxHandle::S_CERTIFYING, second = 3232}, {first = galera::TrxHandle::S_APPLYING, second = 482}}}, source_id_ = {data = "\244\n\005(\356\242\021\353\207t\017e\004'\256\002", alignment = 16938498817274481316}, conn_id_ = 346, trx_id_ = 18446744073709551615, timestamp_ = 646068556878, version_ = 5, write_set_flags_ = 69, local_ = false, master_ = false}, static trans_map_ = {impl_ = std::unordered_map with 4 elements = {[{from_ = galera::TrxHandle::S_COMMITTING, to_ = galera::TrxHandle::S_COMMITTED}] = {pre_guard_ = empty std::__cxx11::list, post_guard_ = empty std::__cxx11::list, pre_action_ = empty std::__cxx11::list, post_action_ = empty std::__cxx11::list}, [{from_ = galera::TrxHandle::S_APPLYING, to_ = galera::TrxHandle::S_COMMITTING}] = {pre_guard_ = empty std::__cxx11::list, post_guard_ = empty std::__cxx11::list, pre_action_ = empty std::__cxx11::list, post_action_ = empty std::__cxx11::list}, [{from_ = galera::TrxHandle::S_CERTIFYING, to_ = galera::TrxHandle::S_APPLYING}] = {pre_guard_ = empty std::__cxx11::list, post_guard_ = empty std::__cxx11::list, pre_action_ = empty std::__cxx11::list, post_action_ = empty std::__cxx11::list}, [{from_ = galera::TrxHandle::S_REPLICATING, to_ = galera::TrxHandle::S_CERTIFYING}] = {pre_guard_ = empty std::__cxx11::list, post_guard_ = empty std::__cxx11::list, pre_action_ = empty std::__cxx11::list, post_action_ = empty std::__cxx11::list}}}, local_seqno_ = 178, global_seqno_ = 2467, last_seen_seqno_ = 2466, depends_seqno_ = 2466, ends_nbo_ = -1, mem_pool_ = @0x562d1f9d80d0, write_set_ = {header_ = {static MAGIC_BYTE = 71 'G', static V3_CHECKSUM_SIZE = 8, static V3_ANNOT_FLAG = 1 '\001', static V3_UNORD_FLAG = 2 '\002', static V3_MAGIC_OFF = 0, static V3_HEADER_VERS_OFF = 1, static V3_HEADER_SIZE_OFF = 2, static V3_SETS_OFF = 3, static V3_FLAGS_OFF = 4, static V3_PA_RANGE_OFF = 6, static V3_LAST_SEEN_OFF = 8, static V3_SEQNO_OFF = 8, static V3_TIMESTAMP_OFF = 16, static V3_SOURCE_ID_OFF = 24, static V3_CONN_ID_OFF = 40, static V3_TRX_ID_OFF = 48, static V3_CRC_OFF = 56, static V3_SIZE = 64, static V3 = {header_ver_ = 1, header_size_ = 2, sets_ = 3, flags_ = 4, pa_range_ = 6, last_seen_ = 8, seqno_ = 8, timestamp_ = 16, source_id_ = 24, conn_id_ = 40, trx_id_ = 48, crc_ = 56}, static MAX_HEADER_SIZE = 64, local_ = '\000' <repeats 63 times>, ptr_ = 0x7f809420e270 "", ver_ = galera::WriteSetNG::VER5, size_ = 64 '@', chksm_ = {<No data fields>}}, size_ = 664, keys_ = {<gu::RecordSetIn<galera::KeySet::KeyPart>> = {<gu::RecordSetInBase> = {<gu::RecordSet> = {static MAX_VERSION = gu::RecordSet::VER2, static VER2_ALIGNMENT = 8, size_ = 40, count_ = 2, version_ = 2 '\002', check_type_ = 3 '\003', alignment_ = 8 '\b'}, head_ = 0x7f809420e2b0 "", next_ = 40, begin_ = 24}, <No data fields>}, version_ = galera::KeySet::FLAT8}, data_ = {<gu::RecordSetIn<galera::DataSet::RecordIn>> = {<gu::RecordSetInBase> = {<gu::RecordSet> = {static MAX_VERSION = gu::RecordSet::VER2, static VER2_ALIGNMENT = 8, size_ = 559, count_ = 1, version_ = 2 '\002', check_type_ = 3 '\003', alignment_ = 8 '\b'}, head_ = 0x7f809420e2d8 "", next_ = 559, begin_ = 24}, <No data fields>}, version_ = galera::DataSet::VER1}, unrd_ = {<gu::RecordSetIn<galera::DataSet::RecordIn>> = {<gu::RecordSetInBase> = {<gu::RecordSet> = {static MAX_VERSION = gu::RecordSet::VER2, static VER2_ALIGNMENT = 8, size_ = 0, count_ = 0, version_ = 0 '\000', check_type_ = 0 '\000', alignment_ = 0 '\000'}, head_ = 0x0, next_ = 0, begin_ = 0}, <No data fields>}, version_ = galera::DataSet::EMPTY}, annt_ = 0x0, check_thr_id_ = 0, check_thr_ = false, check_ = true, static SIZE_THRESHOLD = 4194304}, buf_ = 0x7f807c039480, action_ = {first = 0x7f809420e270, second = 664}, certified_ = true, committed_ = false, exit_loop_ = false, cert_bypass_ = false, queued_ = false}) at ./galera/src/replicator_smm.cpp:504
#42 0x00007f80a0ba3574 in galera::ReplicatorSMM::process_trx (this=0x562d1f9d78a0, recv_ctx=0x7f80a01aacc0, ts_ptr=@0x7f80a01aa670: {px = 0x7f807c039480, pn = {pi_ = 0x7f8078097a20}}) at ./galera/src/replicator_smm.cpp:2127
#43 0x00007f80a0bce94f in galera::GcsActionSource::process_writeset (this=0x562d1f9e2ac0, recv_ctx=0x7f80a01aacc0, act=@0x7f80a01aa6e0: {seqno_g = 2467, seqno_l = 178, buf = 0x7f809420e270, size = 664, type = GCS_ACT_WRITESET}, exit_loop=@0x7f80a01aa8ef: false) at ./galera/src/gcs_action_source.cpp:62
#44 0x00007f80a0bcf412 in galera::GcsActionSource::process (this=0x562d1f9e2ac0, recv_ctx=0x7f80a01aacc0, exit_loop=@0x7f80a01aa8ef: false) at ./galera/src/gcs_action_source.cpp:183
#45 0x00007f80a0ba39c8 in galera::ReplicatorSMM::async_recv (this=0x562d1f9d78a0, recv_ctx=0x7f80a01aacc0) at ./galera/src/replicator_smm.cpp:390
#46 0x00007f80a0b7e4ed in galera_recv (gh=<optimized out>, recv_ctx=<optimized out>) at ./galera/src/wsrep_provider.cpp:236
#47 0x0000562d1ce5adee in wsrep::wsrep_provider_v26::run_applier (this=<optimized out>, applier_ctx=<optimized out>) at ./wsrep-lib/src/wsrep_provider_v26.cpp:796
#48 0x0000562d1cb4d593 in wsrep_replication_process (thd=0x7f807c000c58, arg=<optimized out>) at ./sql/wsrep_thd.cc:57
#49 0x0000562d1cb3e3bf in start_wsrep_THD (arg=arg@entry=0x562d1fa2c190) at ./sql/wsrep_mysqld.h:579
#50 0x0000562d1cacf0e9 in pfs_spawn_thread (arg=0x562d1fa01c38) at ./storage/perfschema/pfs.cc:2201
#51 0x00007f80a5779ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#52 0x00007f80a5390def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 7 (Thread 0x7f8071749700 (LWP 20529)):
#0  futex_wait_cancelable (private=0, expected=0, futex_word=0x562d1d6413e8 <COND_manager+40>) at ../sysdeps/nptl/futex-internal.h:186
#1  __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x562d1d641400 <LOCK_manager>, cond=0x562d1d6413c0 <COND_manager>) at pthread_cond_wait.c:508
#2  __pthread_cond_wait (cond=cond@entry=0x562d1d6413c0 <COND_manager>, mutex=mutex@entry=0x562d1d641400 <LOCK_manager>) at pthread_cond_wait.c:638
#3  0x0000562d1c55d075 in psi_cond_wait (that=that@entry=0x562d1d6413c0 <COND_manager>, mutex=mutex@entry=0x562d1d641400 <LOCK_manager>, file=file@entry=0x562d1ce7d05f "./sql/sql_manager.cc", line=line@entry=103) at ./mysys/my_thr_init.c:596
#4  0x0000562d1c4f80e6 in inline_mysql_cond_wait (that=0x562d1d6413c0 <COND_manager>, mutex=0x562d1d641400 <LOCK_manager>, src_file=0x562d1ce7d05f "./sql/sql_manager.cc", src_line=103) at ./include/mysql/psi/mysql_thread.h:1070
#5  handle_manager (arg=arg@entry=0x0) at ./sql/sql_manager.cc:103
#6  0x0000562d1cacf0e9 in pfs_spawn_thread (arg=0x562d1ff6a4d8) at ./storage/perfschema/pfs.cc:2201
#7  0x00007f80a5779ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#8  0x00007f80a5390def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 6 (Thread 0x7f80637fe700 (LWP 20525)):
#0  futex_abstimed_wait_cancelable (private=0, abstime=0x7f80637fdd00, clockid=1669323872, expected=0, futex_word=0x562d1fa92468) at ../sysdeps/nptl/futex-internal.h:323
#1  __pthread_cond_wait_common (abstime=0x7f80637fdd00, clockid=1669323872, mutex=0x562d1fa5d490, cond=0x562d1fa92440) at pthread_cond_wait.c:520
#2  __pthread_cond_clockwait (abstime=0x7f80637fdd00, clockid=1669323872, mutex=0x562d1fa5d490, cond=0x562d1fa92440) at pthread_cond_wait.c:677
#3  __pthread_cond_clockwait (cond=cond@entry=0x562d1fa92440, mutex=0x562d1fa5d490, clockid=1669323872, clockid@entry=1, abstime=abstime@entry=0x7f80637fdd00) at pthread_cond_wait.c:665
#4  0x0000562d1cd5f960 in std::condition_variable::__wait_until_impl<std::chrono::duration<long, std::ratio<1l, 1000000000l> > > (__lock=@0x7f80637fdd50: {_M_device = 0x562d1fa5d490, _M_owns = true}, __lock=@0x7f80637fdd50: {_M_device = 0x562d1fa5d490, _M_owns = true}, __atime=<optimized out>, this=0x562d1fa92440) at /usr/include/c++/10/bits/std_mutex.h:123
#5  std::condition_variable::wait_until<std::chrono::duration<long, std::ratio<1l, 1000000000l> > > (__atime=<optimized out>, __lock=@0x7f80637fdd50: {_M_device = 0x562d1fa5d490, _M_owns = true}, this=0x562d1fa92440) at /usr/include/c++/10/condition_variable:119
#6  std::condition_variable::wait_for<long, std::ratio<1l, 1000l> > (__rtime=@0x562d1fa5d4b8: {__r = 60000}, __rtime=@0x562d1fa5d4b8: {__r = 60000}, __lock=@0x7f80637fdd50: {_M_device = 0x562d1fa5d490, _M_owns = true}, this=0x562d1fa92440) at /usr/include/c++/10/condition_variable:172
#7  tpool::thread_pool_generic::wait_for_tasks (this=this@entry=0x562d1fa5d380, lk=@0x7f80637fdd50: {_M_device = 0x562d1fa5d490, _M_owns = true}, thread_data=thread_data@entry=0x562d1fa92440) at ./tpool/tpool_generic.cc:450
#8  0x0000562d1cd6000d in tpool::thread_pool_generic::get_task (this=0x562d1fa5d380, thread_var=0x562d1fa92440, t=0x7f80637fdda8) at ./tpool/tpool_generic.cc:503
#9  0x0000562d1cd6169d in tpool::thread_pool_generic::worker_main (this=0x562d1fa5d380, thread_var=0x562d1fa92440) at ./tpool/tpool_generic.cc:548
#10 0x00007f80a566ced0 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
#11 0x00007f80a5779ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#12 0x00007f80a5390def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 5 (Thread 0x7f8071594700 (LWP 20522)):
#0  futex_wait_cancelable (private=0, expected=0, futex_word=0x562d1d5bbed8 <buf_pool+17304>) at ../sysdeps/nptl/futex-internal.h:186
#1  __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x562d1d5bbe40 <buf_pool+17152>, cond=0x562d1d5bbeb0 <buf_pool+17264>) at pthread_cond_wait.c:508
#2  __pthread_cond_wait (cond=cond@entry=0x562d1d5bbeb0 <buf_pool+17264>, mutex=mutex@entry=0x562d1d5bbe40 <buf_pool+17152>) at pthread_cond_wait.c:638
#3  0x0000562d1ccce7a7 in buf_flush_page_cleaner () at ./storage/innobase/buf/buf0flu.cc:2201
#4  0x00007f80a566ced0 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
#5  0x00007f80a5779ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#6  0x00007f80a5390def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 4 (Thread 0x7f8073597700 (LWP 20518)):
#0  futex_abstimed_wait_cancelable (private=0, abstime=0x7f8073596d10, clockid=1935240224, expected=0, futex_word=0x562d1de72e28 <COND_checkpoint+40>) at ../sysdeps/nptl/futex-internal.h:323
#1  __pthread_cond_wait_common (abstime=0x7f8073596d10, clockid=1935240224, mutex=0x562d1de72e40 <LOCK_checkpoint>, cond=0x562d1de72e00 <COND_checkpoint>) at pthread_cond_wait.c:520
#2  __pthread_cond_timedwait (cond=cond@entry=0x562d1de72e00 <COND_checkpoint>, mutex=mutex@entry=0x562d1de72e40 <LOCK_checkpoint>, abstime=abstime@entry=0x7f8073596d10) at pthread_cond_wait.c:656
#3  0x0000562d1c55d0ee in psi_cond_timedwait (that=0x562d1de72e00 <COND_checkpoint>, mutex=0x562d1de72e40 <LOCK_checkpoint>, abstime=abstime@entry=0x7f8073596d10, file=file@entry=0x562d1cfd7578 "./storage/maria/ma_servicethread.c", line=line@entry=115) at ./mysys/my_thr_init.c:609
#4  0x0000562d1c50df6a in inline_mysql_cond_timedwait (src_file=0x562d1cfd7578 "./storage/maria/ma_servicethread.c", src_line=115, abstime=0x7f8073596d10, mutex=<optimized out>, that=<optimized out>) at ./include/mysql/psi/mysql_thread.h:1086
#5  my_service_thread_sleep (control=control@entry=0x562d1d5a2bc0 <checkpoint_control>, sleep_time=sleep_time@entry=30000000000) at ./storage/maria/ma_servicethread.c:115
#6  0x0000562d1ca6207f in ma_checkpoint_background (arg=arg@entry=0x1e) at ./storage/maria/ma_checkpoint.c:707
#7  0x0000562d1cacf0e9 in pfs_spawn_thread (arg=0x562d1fa5fdf8) at ./storage/perfschema/pfs.cc:2201
#8  0x00007f80a5779ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#9  0x00007f80a5390def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 3 (Thread 0x7f80a09f7700 (LWP 20256)):
#0  futex_wait_cancelable (private=0, expected=0, futex_word=0x562d1f9d8060) at ../sysdeps/nptl/futex-internal.h:186
#1  __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x562d1f9d8010, cond=0x562d1f9d8038) at pthread_cond_wait.c:508
#2  __pthread_cond_wait (cond=cond@entry=0x562d1f9d8038, mutex=mutex@entry=0x562d1f9d8010) at pthread_cond_wait.c:638
#3  0x00007f80a0bc9933 in gu::Lock::wait (this=<synthetic pointer>, this=<synthetic pointer>, cond=@0x562d1f9d8038: {cond = {__data = {{__wseq = 14, __wseq32 = {__low = 14, __high = 0}}, {__g1_start = 10, __g1_start32 = {__low = 10, __high = 0}}, __g_refs = {2, 0}, __g_size = {0, 0}, __g1_orig_size = 4, __wrefs = 8, __g_signals = {0, 0}}, __size = "\016\000\000\000\000\000\000\000\n\000\000\000\000\000\000\000\002", '\000' <repeats 15 times>, "\004\000\000\000\b\000\000\000\000\000\000\000\000\000\000", __align = 14}, ref_count = 1}) at ./galerautils/src/gu_lock.hpp:46
#4  galera::ServiceThd::thd_func (arg=0x562d1f9d7ff8) at ./galera/src/galera_service_thd.cpp:30
#5  0x00007f80a5779ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#6  0x00007f80a5390def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 2 (Thread 0x7f80a0d7d700 (LWP 20255)):
#0  futex_abstimed_wait_cancelable (private=0, abstime=0x7f80a0d7cd80, clockid=-1596470160, expected=0, futex_word=0x562d1df123ac <COND_timer+44>) at ../sysdeps/nptl/futex-internal.h:323
#1  __pthread_cond_wait_common (abstime=0x7f80a0d7cd80, clockid=-1596470160, mutex=0x562d1df123c0 <LOCK_timer>, cond=0x562d1df12380 <COND_timer>) at pthread_cond_wait.c:520
#2  __pthread_cond_timedwait (cond=cond@entry=0x562d1df12380 <COND_timer>, mutex=mutex@entry=0x562d1df123c0 <LOCK_timer>, abstime=abstime@entry=0x7f80a0d7cd80) at pthread_cond_wait.c:656
#3  0x0000562d1c55d0ee in psi_cond_timedwait (that=that@entry=0x562d1df12380 <COND_timer>, mutex=mutex@entry=0x562d1df123c0 <LOCK_timer>, abstime=abstime@entry=0x7f80a0d7cd80, file=file@entry=0x562d1d02c6d0 "./mysys/thr_timer.c", line=line@entry=321) at ./mysys/my_thr_init.c:609
#4  0x0000562d1c55d3d2 in inline_mysql_cond_timedwait (that=0x562d1df12380 <COND_timer>, mutex=0x562d1df123c0 <LOCK_timer>, src_file=0x562d1d02c6d0 "./mysys/thr_timer.c", src_line=321, abstime=0x7f80a0d7cd80) at ./include/mysql/psi/mysql_thread.h:1086
#5  timer_handler (arg=arg@entry=0x0) at ./mysys/thr_timer.c:321
#6  0x0000562d1cacf0e9 in pfs_spawn_thread (arg=0x562d1f9a2b28) at ./storage/perfschema/pfs.cc:2201
#7  0x00007f80a5779ea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
#8  0x00007f80a5390def in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
Thread 1 (Thread 0x7f80a4f9c040 (LWP 20254)):
#0  __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
#1  0x0000562d1cdc9b49 in my_write_core (sig=sig@entry=6) at ./mysys/stacktrace.c:424
#2  0x0000562d1c896380 in handle_fatal_signal (sig=6) at ./sql/signal_handler.cc:344
#3  <signal handler called>
#4  0x00007f80a53863ff in __GI___poll (fds=0x562d1ffb9208, nfds=2, timeout=timeout@entry=-1) at ../sysdeps/unix/sysv/linux/poll.c:29
#5  0x0000562d1c59eeaa in poll (__timeout=-1, __nfds=<optimized out>, __fds=<optimized out>) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
#6  handle_connections_sockets () at ./sql/mysqld.cc:6110
#7  0x0000562d1c59fec8 in mysqld_main (argc=<optimized out>, argv=<optimized out>) at ./sql/mysqld.cc:5815
#8  0x00007f80a52b9d0a in __libc_start_main (main=0x562d1c564df0 <main(int, char**)>, argc=23, argv=0x7ffcf97de298, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffcf97de288) at ../csu/libc-start.c:308
#9  0x0000562d1c5947ca in _start () at ./sql/my_decimal.h:147
 
 - deleting it, already saved 0
 - found 'core' (0/0)
 
Trying 'dbx' to get a backtrace
 
Trying 'gdb' to get a backtrace from coredump /dev/shm/var/1/log/galera.galera_unicode_identifiers-innodb/mysqld.1/data/core
Core generated by '/usr/sbin/mariadbd'
Output from gdb follows. The first stack trace is from the failing thread.
The following stack traces are from all threads (so the failing one is
duplicated).
--------------------------
 
warning: Can't open file anon_inode:[io_uring] which was expanded to anon_inode:[io_uring] during file-backed mapping note processing
 
warning: Can't open file anon_inode:[io_uring] which was expanded to anon_inode:[io_uring] during file-backed mapping note processing
 
warning: Can't open file /dev/shm/var/1/mysqld.1/data/galera.cache during file-backed mapping note processing
 
warning: Can't open file /dev/shm/var/1/mysqld.1/data/tc.log during file-backed mapping note processing



 Comments   
Comment by Marko Mäkelä [ 2021-08-03 ]

A few remarks:

  • I suspect that this is related to (but by no means caused by) MDEV-24883. Perhaps this only occurs on platforms that support io_uring?
  • Whenever the test fails due to the InnoDB watchdog tripping (instead of the 15-minute test case timeout killing the test), it may be that the watchdog is issuing a false alarm, and the server is not actually hung, but extremely slow. I would recommend checking traces from sudo perf record and offcputime collected while the test is running.
  • InnoDB assumes that all DDL is covered by MDL_EXCLUSIVE. Would the mysql_create_table() call by Wsrep_high_priority_service::apply_toi() adhere to that? (This should be easy to answer by running the test case under ./mtr --manual-rr and debugging the rr replay.)
Comment by Elena Stepanova [ 2021-08-20 ]

It causes a lot of failures in the buildbot

Comment by Seppo Jaakola [ 2021-08-23 ]

The stack trace has replication applier thread (thread 8) waiting for BP page mutex:

Thread 8 (Thread 0x7f80a01ab700 (LWP 20260)):
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1 0x0000562d1cc5ac73 in srw_mutex::wait (lk=<optimized out>, this=0x7f8071996938) at ./storage/innobase/sync/srw_lock.cc:224
#2 srw_mutex::wait_and_lock (this=this@entry=0x7f8071996938) at ./storage/innobase/sync/srw_lock.cc:262
#3 0x0000562d1cbda3fc in srw_mutex::wr_lock (this=0x7f8071996938) at ./storage/innobase/include/srw_lock.h:70
#4 ssux_lock_low::wr_lock (this=0x7f8071996938) at ./storage/innobase/include/srw_lock.h:212
#5 sux_lock<ssux_lock_low>::x_lock_upgraded (this=0x7f8071996938) at ./storage/innobase/include/sux_lock.h:412
#6 mtr_t::page_lock (this=this@entry=0x7f80a01a6510, block=block@entry=0x7f80719968c0, rw_latch=rw_latch@entry=2) at ./storage/innobase/mtr/mtr0mtr.cc:1076
#7 0x0000562d1ccc41c4 in buf_page_get_low (page_id=

{m_id = 12}

, zip_size=<optimized out>, rw_latch=<optimized out>, guess=<optimized out>, mode=<optimized out>, mtr=<optimized out>, err=<optimized out>, allow_ibuf_merge=<optimized out>) at ./storage/innobase/buf/buf0buf.cc:2981

Because of the test execution timeout, I assume this mutex wait will never end. The applier is executing create table part of CREATE TABLE AS SELECT query, nothing unusual there, also MDL locks protecting this operation should be acquired in native MariaDB style.

Thread 9 is the only potential blocker for the applier, it is executing dict_sys_t::evict_table_LRU:

Thread 9 (Thread 0x7f8073fff700 (LWP 21543)):
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1 0x0000562d1cc5ac73 in srw_mutex::wait (lk=<optimized out>, this=0x562d1d5bd008 <dict_sys+72>) at ./storage/innobase/sync/srw_lock.cc:224
#2 srw_mutex::wait_and_lock (this=this@entry=0x562d1d5bd008 <dict_sys+72>) at ./storage/innobase/sync/srw_lock.cc:262
#3 0x0000562d1cc5b0bf in srw_mutex::wr_lock (this=0x562d1d5bd008 <dict_sys+72>) at ./storage/innobase/include/srw_lock.h:70
#4 ssux_lock_low::wr_lock (this=0x562d1d5bd008 <dict_sys+72>) at ./storage/innobase/include/srw_lock.h:212
#5 srw_lock::psi_wr_lock (this=this@entry=0x562d1d5bd000 <dict_sys+64>, file=file@entry=0x562d1d01b1a8 "./storage/innobase/dict/dict0dict.cc", line=line@entry=1366) at ./storage/innobase/sync/srw_lock.cc:328
#6 0x0000562d1cce7105 in srw_lock::wr_lock (line=1366, file=0x562d1d01b1a8 "./storage/innobase/dict/dict0dict.cc", this=0x562d1d5bd000 <dict_sys+64>) at ./storage/innobase/include/srw_lock.h:423
#7 dict_sys_t::lock (line=1366, file=0x562d1d01b1a8 "./storage/innobase/dict/dict0dict.cc", this=0x562d1d5bcfc0 <dict_sys>) at ./storage/innobase/dict/dict0dict.cc:1071
#8 dict_sys_t::evict_table_LRU (this=0x562d1d5bcfc0 <dict_sys>, half=half@entry=false) at ./storage/innobase/dict/dict0dict.cc:1366

Maybe these two threads are in unresolved deadlock hanging situation.

Comment by Jan Lindström [ 2023-04-04 ]

Could not reproduce locally and based on history has not failed recently. Failure does not look Galera related.

Generated at Thu Feb 08 09:44:14 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.