Details
Description
galera.galera_bf_lock_wait failed on 10.3 ES|]: "sync0policy.ic:64: void MutexDebug<Mutex>::enter(const Mutex*, const char*, unsigned int) [with Mutex = TTASEventMutex<GenericPolicy>]: Assertion `!is_owned()' failed".
It seems to be a sporadic issue and it does not fail on BB.
10.3.27-10, e21d261e7883547608a77a42a6e9626964e67045, sles15 |
galera.galera_bf_lock_wait 'innodb' [ fail ]
|
Test ended at 2021-01-16 07:39:01
|
|
CURRENT_TEST: galera.galera_bf_lock_wait
|
|
|
Server [mysqld.2 - pid: 11265, winpid: 11265, exit: 256] failed during test run
|
Server log from this test:
|
----------SERVER LOG START-----------
|
2021-01-16 7:38:58 0 [Note] WSREP: (7ae2955e, 'tcp://0.0.0.0:16005') turning message relay requesting off
|
mysqld: /home/timofey_turenko_mariadb_com/server/storage/innobase/include/sync0policy.ic:64: void MutexDebug<Mutex>::enter(const Mutex*, const char*, unsigned int) [with Mutex = TTASEventMutex<GenericPolicy>]: Assertion `!is_owned()' failed.
|
210116 7:39:00 [ERROR] mysqld got signal 6 ;
|
This could be because you hit a bug. It is also possible that this binary
|
or one of the libraries it was linked against is corrupt, improperly built,
|
or misconfigured. This error can also be caused by malfunctioning hardware.
|
|
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
|
|
We will try our best to scrape up some info that will hopefully help
|
diagnose the problem, but since we have already crashed,
|
something is definitely wrong and this may fail.
|
|
Server version: 10.3.27-10-MariaDB-enterprise-debug-log
|
key_buffer_size=1048576
|
read_buffer_size=131072
|
max_used_connections=3
|
max_threads=153
|
thread_count=11
|
It is possible that mysqld could use up to
|
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63311 K bytes of memory
|
Hope that's ok; if not, decrease some variables in the equation.
|
|
Thread pointer: 0x7fed54000d50
|
Attempting backtrace. You can use the following information to find out
|
where mysqld died. If you see no messages after this, something went
|
terribly wrong...
|
stack_bottom = 0x7fed78395cb8 thread_stack 0x49000
|
mysys/stacktrace.c:174(my_print_stacktrace)[0x564bab76c044]
|
sql/signal_handler.cc:206(handle_fatal_signal)[0x564baafb7d4e]
|
/lib64/libpthread.so.0(+0x132d0)[0x7fed857b82d0]
|
/lib64/libc.so.6(gsignal+0x110)[0x7fed83497520]
|
/lib64/libc.so.6(abort+0x151)[0x7fed83498b01]
|
/lib64/libc.so.6(+0x31b1a)[0x7fed8348fb1a]
|
/lib64/libc.so.6(+0x31b92)[0x7fed8348fb92]
|
include/sync0policy.h:62(MutexDebug<TTASEventMutex<GenericPolicy> >::Context::Context(latch_id_t))[0x564bab1ea185]
|
include/sync0policy.h:345(GenericPolicy<TTASEventMutex<GenericPolicy> >::enter(TTASEventMutex<GenericPolicy> const&, char const*, unsigned int))[0x564bab1ea31c]
|
handler/ha_innodb.cc:5099(innobase_kill_query(handlerton*, THD*, thd_kill_levels))[0x564bab1dcb1e]
|
sql/handler.cc:849(kill_handlerton(THD*, st_plugin_int**, void*))[0x564baafb8a5a]
|
sql/sql_plugin.cc:2436(plugin_foreach_with_mask(THD*, char (*)(THD*, st_plugin_int**, void*), int, unsigned int, void*))[0x564baad42940]
|
sql/handler.cc:855(ha_kill_query(THD*, thd_kill_levels))[0x564baafbb253]
|
sql/sql_class.cc:1851(THD::awake_no_mutex(killed_state))[0x564baacd774d]
|
psi/mysql_thread.h:778(wsrep_thd_awake)[0x564baaf035ee]
|
handler/ha_innodb.cc:18931(wsrep_innobase_kill_one_trx(void*, trx_t const*, trx_t*, unsigned long))[0x564bab1daea1]
|
lock/lock0lock.cc:1126(wsrep_kill_victim(trx_t const*, ib_lock_t const*))[0x564bab2416fc]
|
lock/lock0lock.cc:1168(lock_rec_other_has_conflicting(unsigned long, buf_block_t const*, unsigned long, trx_t const*))[0x564bab24c0d6]
|
lock/lock0lock.cc:1935(lock_rec_lock(bool, unsigned long, buf_block_t const*, unsigned long, dict_index_t*, que_thr_t*))[0x564bab2509ef]
|
lock/lock0lock.cc:5810(lock_clust_rec_read_check_and_lock(unsigned long, buf_block_t const*, unsigned char const*, dict_index_t*, unsigned short const*, lock_mode, unsigned long, que_thr_t*))[0x564bab2519b2]
|
row/row0sel.cc:1250(sel_set_rec_lock(btr_pcur_t*, unsigned char const*, dict_index_t*, unsigned short const*, unsigned long, unsigned long, que_thr_t*, mtr_t*))[0x564bab3737b7]
|
row/row0sel.cc:5094(row_search_mvcc(unsigned char*, page_cur_mode_t, row_prebuilt_t*, unsigned long, unsigned long))[0x564bab3793f1]
|
handler/ha_innodb.cc:9281(ha_innobase::index_read(unsigned char*, unsigned char const*, unsigned int, ha_rkey_function))[0x564bab1d9070]
|
handler/ha_innodb.cc:9783(ha_innobase::rnd_pos(unsigned char*, unsigned char*))[0x564bab1bcd60]
|
sql/handler.cc:2952(handler::ha_rnd_pos(unsigned char*, unsigned char*))[0x564baafc026b]
|
sql/handler.h:3632(handler::rnd_pos_by_record(unsigned char*))[0x564baafcdcb0]
|
sql/sql_class.h:6456(handler::ha_rnd_pos_by_record(unsigned char*))[0x564bab10bb93]
|
sql/log_event.cc:14641(Update_rows_log_event::do_exec_row(rpl_group_info*))[0x564bab10cef1]
|
sql/log_event.cc:11611(Rows_log_event::do_apply_event(rpl_group_info*))[0x564bab0fa10b]
|
sql/log_event.h:1484(Log_event::apply_event(rpl_group_info*))[0x564baaf0d34f]
|
src/trx_handle.cpp:312(galera::TrxHandle::apply(void*, wsrep_cb_status (*)(void*, void const*, unsigned long, unsigned int, wsrep_trx_meta const*), wsrep_trx_meta const&) const)[0x7fed79e6cf28]
|
src/replicator_smm.cpp:92(apply_trx_ws(void*, wsrep_cb_status (*)(void*, void const*, unsigned long, unsigned int, wsrep_trx_meta const*), wsrep_cb_status (*)(void*, unsigned int, wsrep_trx_meta const*, bool*, bool), galera::TrxHandle const&, wsrep_trx_meta const&))[0x7fed79eba66f]
|
src/replicator_smm.cpp:458(galera::ReplicatorSMM::apply_trx(void*, galera::TrxHandle*))[0x7fed79ebde15]
|
src/replicator_smm.cpp:1258(galera::ReplicatorSMM::process_trx(void*, galera::TrxHandle*))[0x7fed79ec08d6]
|
src/gcs_action_source.cpp:116(galera::GcsActionSource::dispatch(void*, gcs_action const&, bool&))[0x7fed79e98408]
|
src/gcs_action_source.cpp:28(Release::~Release())[0x7fed79e99548]
|
src/replicator_smm.cpp:362(galera::ReplicatorSMM::async_recv(void*))[0x7fed79ec108d]
|
src/wsrep_provider.cpp:271(galera_recv)[0x7fed79edb628]
|
sql/wsrep_thd.cc:470(wsrep_replication_process(THD*))[0x564baaf0e1bc]
|
sql/wsrep_mysqld.cc:2160(start_wsrep_THD)[0x564baaefed05]
|
perfschema/pfs.cc:1872(pfs_spawn_thread)[0x564bab711797]
|
/lib64/libpthread.so.0(+0x84f9)[0x7fed857ad4f9]
|
/lib64/libc.so.6(clone+0x3f)[0x7fed83559fbf]
|
|
Trying to get some variables.
|
Some pointers may be invalid and cause the dump to abort.
|
Query (0x7fed6c005c6b): update t1 set b=connection_id() where a=1
|
|
Connection ID (thread ID): 2
|
Status: NOT_KILLED
|
|
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on
|
|
The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
|
information that should help you find out what is causing the crash.
|
Writing a core file...
|
Working directory at /var/tmp/mtr/mysqld.2/data
|
Resource Limits:
|
Limit Soft Limit Hard Limit Units
|
Max cpu time unlimited unlimited seconds
|
Max file size unlimited unlimited bytes
|
Max data size unlimited unlimited bytes
|
Max stack size 8388608 unlimited bytes
|
Max core file size unlimited unlimited bytes
|
Max resident set unlimited unlimited bytes
|
Max processes 31642 31642 processes
|
Max open files 1024 1024 files
|
Max locked memory 65536 65536 bytes
|
Max address space unlimited unlimited bytes
|
Max file locks unlimited unlimited locks
|
Max pending signals 31642 31642 signals
|
Max msgqueue size 819200 819200 bytes
|
Max nice priority 0 0
|
Max realtime priority 0 0
|
Max realtime timeout unlimited unlimited us
|
Core pattern: |/bin/false
|
|
----------SERVER LOG END-------------
|
mysqltest failed but provided no output
|
The result from queries just before the failure was:
|
< snip >
|
update t1 set b=connection_id() where a=1;
|
commit;
|
SET current_num = current_num + 1;
|
END WHILE;
|
END|
|
connection node_2;
|
connect node_1_p1, 127.0.0.1, root, , test, $NODE_MYPORT_1;
|
SET SESSION wsrep_sync_wait=0;
|
call p1(1000);
|
connect node_1_p2, 127.0.0.1, root, , test, $NODE_MYPORT_1;
|
SET SESSION wsrep_sync_wait=0;
|
call p1(1000);
|
connect node_2_p1, 127.0.0.1, root, , test, $NODE_MYPORT_2;
|
SET SESSION wsrep_sync_wait=0;
|
call p1(1000);
|
connect node_2_p2, 127.0.0.1, root, , test, $NODE_MYPORT_2;
|
SET SESSION wsrep_sync_wait=0;
|
call p1(1000);
|
connection node_1;
|
checking error log for 'BF lock wait long' message for 10 times every 10 seconds ...
|
|
|
|
- saving '/var/tmp/mtr/log/galera.galera_bf_lock_wait-innodb/' to '/var/tmp/mtr/log/galera.galera_bf_lock_wait-innodb/'
|
|
Retrying test galera.galera_bf_lock_wait, attempt(2/3)...
|
|
***Warnings generated in error logs during shutdown after running tests: galera.galera_bf_lock_wait galera.GAL-419
|
|
mysqld: /home/timofey_turenko_mariadb_com/server/storage/innobase/include/sync0policy.ic:64: void MutexDebug<Mutex>::enter(const Mutex*, const char*, unsigned int) [with Mutex = TTASEventMutex<GenericPolicy>]: Assertion `!is_owned()' failed.
|
Attempting backtrace. You can use the following information to find out
|
|
galera.galera_bf_lock_wait 'innodb' [ retry-pass ] 102151
|
|
Retrying test galera.galera_bf_lock_wait, attempt(3/3)...
|
Note: It failed earlier with similar output, see MENT-723.