|
Also of interest:
- on production, we're running 10.3.25, and that runs smoothly (we've skipped 26 and 27 because of other breaking bugs);
I poked around some in the dump. Thread 68 in dump 1 is here:
static void bg_wsrep_kill_trx(
|
void *void_arg)
|
{
|
bg_wsrep_kill_trx_arg *arg = (bg_wsrep_kill_trx_arg*)void_arg;
|
THD *thd = find_thread_by_id(arg->thd_id, false);
|
trx_t *victim_trx = NULL;
|
bool awake = false;
|
DBUG_ENTER("bg_wsrep_kill_trx");
|
|
if (thd) {
|
wsrep_thd_LOCK(thd); // <-- locked; thread 0x7fa368019568
|
victim_trx = thd_to_trx(thd);
|
lock_mutex_enter(); // <-- mutex_enter(&lock_sys.mutex) WAITING
|
trx_mutex_enter(victim_trx);
|
wsrep_thd_UNLOCK(thd);
|
if (victim_trx->id != arg->trx_id)
|
{
|
trx_mutex_exit(victim_trx);
|
lock_mutex_exit();
|
victim_trx = NULL;
|
wsrep_thd_kill_UNLOCK(thd);
|
}
|
}
|
(gdb) print &lock_sys
|
$22 = (lock_sys_t *) 0x5587b0840480 <lock_sys>
|
(gdb) print lock_sys.mutex.m_impl.m_event
|
$28 = (os_event_t) 0x55881a038e60
|
(gdb) print &((os_event_t) 0x55881a038e60).mutex
|
$32 = (EventMutex *) 0x55881a038e70
|
(gdb) print *(EventMutex*)0x55881a038e70
|
$33 = {m_mutex = {__data = {__lock = 0, __count = 0, __owner = 0, __nusers = 55, __kind = 0, __spins = 0, __elision = 0, __list = {__prev = 0x0, __next = 0x0}}, __size = '\000' <repeats 12 times>, "\067", '\000' <repeats 26 times>, __align = 0}}
|
That thread is what the deadlock checker (dump1:thread170) was waiting for:
Thread 170 (Thread 0x7fa5e8ca5700 (LWP 19772)):
|
#0 __lll_lock_wait () at ../sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
|
#1 0x00007fc58cdd019c in __GI___pthread_mutex_lock (mutex=mutex@entry=0x7fa36801afe8) at ../nptl/pthread_mutex_lock.c:135
|
#2 0x00005587af8c3600 in inline_mysql_mutex_lock (src_file=0x5587aff40518 "/home/buildbot/buildbot/build/mariadb-10.3.28/sql/wsrep_thd.cc", src_line=761, that=0x7fa36801afe8) at ./include/mysql/psi/mysql_thread.h:719
|
#3 wsrep_thd_is_BF (thd=thd@entry=0x7fa368019568, sync=sync@entry=1 '\001') at ./sql/wsrep_thd.cc:761
|
...
|
If I check the changes between 10.3.25 and 10.3.28, I notice that commit 29bbcac adds the bg_wsrep_kill_trx code, where there is only one, not two locks:
commit 29bbcac0ee841faaa68eeb09c86ff825eabbe6b6
|
Author: Sergei Golubchik <serg@mariadb.org>
|
Date: Wed Jan 20 18:22:38 2021 +0100
|
|
MDEV-23328 Server hang due to Galera lock conflict resolution
|
...
|
mutex order violation here.
|
...
|
When a normal KILL statement is executed, [...]
|
victim_thread->LOCK_thd_data -> lock_sys->mutex -> victim_trx->mutex
|
...
|
+ if (thd) {
|
+ victim_trx = thd_to_trx(thd);
|
+ lock_mutex_enter();
|
+ trx_mutex_enter(victim_trx);
|
But then this commit with the obscurely named message "merge" adds the second lock – adding a lock that we now appear to block on:
commit 37e24970cbbcca4102094d177eee570b3338262a
|
Author: Sergei Golubchik <serg@mariadb.org>
|
Date: Tue Feb 2 10:02:48 2021 +0100
|
|
merge
|
|
...
|
--- a/storage/innobase/handler/ha_innodb.cc
|
+++ b/storage/innobase/handler/ha_innodb.cc
|
@@ -18767,15 +18767,17 @@ static void bg_wsrep_kill_trx(
|
DBUG_ENTER("bg_wsrep_kill_trx");
|
|
if (thd) {
|
+ wsrep_thd_LOCK(thd);
|
victim_trx = thd_to_trx(thd);
|
lock_mutex_enter();
|
trx_mutex_enter(victim_trx);
|
+ wsrep_thd_UNLOCK(thd);
|
.. although it does rhyme with "correct lock order" comment in the first commit:
victim_thread->LOCK_thd_data -> lock_sys->mutex -> victim_trx->mutex
|
So.. that would still be the correct order.
I'm probably completely off track about now. Why is lock_mutex_enter() causing a conditional wait? And who is supposed to kick it to life?
|
dump1.txt
