database/mariadb
1
0
Fork 0
mirror of https://github.com/MariaDB/server.git synced 2025-07-30 16:24:05 +03:00
Code Activity

Bug#17283409 4-WAY DEADLOCK: ZOMBIES, PURGING BINLOGS,

Browse Source 
SHOW PROCESSLIST, SHOW BINLOGS

Problem:  A deadlock was occurring when 4 threads were
involved in acquiring locks in the following way
Thread 1: Dump thread ( Slave is reconnecting, so on
              Master, a new dump thread is trying kill
              zombie dump threads. It acquired thread's
              LOCK_thd_data and it is about to acquire
              mysys_var->current_mutex ( which LOCK_log)
Thread 2: Application thread is executing show binlogs and
               acquired LOCK_log and it is about to acquire
               LOCK_index.
Thread 3: Application thread is executing Purge binary logs
               and acquired LOCK_index and it is about to
               acquire LOCK_thread_count.
Thread 4: Application thread is executing show processlist
               and acquired LOCK_thread_count and it is
               about to acquire zombie dump thread's
               LOCK_thd_data.
Deadlock Cycle:
     Thread 1 -> Thread 2 -> Thread 3-> Thread 4 ->Thread 1

The same above deadlock was observed even when thread 4 is
executing 'SELECT * FROM information_schema.processlist' command and
acquired LOCK_thread_count and it is about to acquire zombie
dump thread's LOCK_thd_data.

Analysis:
There are four locks involved in the deadlock.  LOCK_log,
LOCK_thread_count, LOCK_index and LOCK_thd_data.
LOCK_log, LOCK_thread_count, LOCK_index are global mutexes
where as LOCK_thd_data is local to a thread.
We can divide these four locks in two groups.
Group 1 consists of LOCK_log and LOCK_index and the order
should be LOCK_log followed by LOCK_index.
Group 2 consists of other two mutexes
LOCK_thread_count, LOCK_thd_data and the order should
be LOCK_thread_count followed by LOCK_thd_data.
Unfortunately, there is no specific predefined lock order defined
to follow in the MySQL system when it comes to locks across these
two groups. In the above problematic example,
there is no problem in the way we are acquiring the locks
if you see each thread individually.
But If you combine all 4 threads, they end up in a deadlock.

Fix: 
Since everything seems to be fine in the way threads are taking locks,
In this patch We are changing the duration of the locks in Thread 4
to break the deadlock. i.e., before the patch, Thread 4
('show processlist' command) mysqld_list_processes()
function acquires LOCK_thread_count for the complete duration
of the function and it also acquires/releases
each thread's LOCK_thd_data.

LOCK_thread_count is used to protect addition and
deletion of threads in global threads list. While show
process list is looping through all the existing threads,
it will be a problem if a thread is exited but there is no problem
if a new thread is added to the system. Hence a new mutex is
introduced "LOCK_thd_remove" which will protect deletion
of a thread from global threads list. All threads which are
getting exited should acquire LOCK_thd_remove
followed by LOCK_thread_count. (It should take LOCK_thread_count
also because other places of the code still thinks that exit thread
is protected with LOCK_thread_count. In this fix, we are changing
only 'show process list' query logic )
(Eg: unlink_thd logic will be protected with
LOCK_thd_remove).

Logic of mysqld_list_processes(or file_schema_processlist)
will now be protected with 'LOCK_thd_remove' instead of
'LOCK_thread_count'.

Now the new locking order after this patch is:
LOCK_thd_remove -> LOCK_thd_data -> LOCK_log ->
LOCK_index -> LOCK_thread_count
This commit is contained in:
Venkatesh Duggirala
2014-05-08 18:13:01 +05:30
parent 263d47d3a1
commit 33f15dc7ac
15 changed files with 377 additions and 33 deletions
Download Patch File Download Diff File Expand all files Collapse all files

47
mysql-test/r/show_processlist.result Normal file
View File

@ -0,0 +1,47 @@
Bug#17283409 4-WAY DEADLOCK: ZOMBIES, PURGING BINLOGS, SHOW PROCESSLIST,
SHOW BINLOGS
connect connection1,127.0.0.1,root,,test,$MASTER_MYPORT,;
connection default;
SET DEBUG_SYNC='before_one_element_read_from_threads_iterator SIGNAL parked1 WAIT_FOR go';
SHOW PROCESSLIST;
connection connection1;
"Wait_for parked1"
SET DEBUG_SYNC='now WAIT_FOR parked1';
connect connection2,127.0.0.1,root,,test,$MASTER_MYPORT,;
connect connection3,127.0.0.1,root,,test,$MASTER_MYPORT,;
SET DEBUG_SYNC='now SIGNAL go';
connection default;
Id User Host db Command Time State Info
<Id> root <Host> test <Command> <Time> <State> <Info>
<Id> root <Host> test <Command> <Time> <State> <Info>
<Id> root <Host> test <Command> <Time> <State> <Info>
<Id> root <Host> test <Command> <Time> <State> <Info>
SET DEBUG_SYNC='after_one_element_read_from_threads_iterator SIGNAL parked1 WAIT_FOR go';
SHOW PROCESSLIST;
connection connection1;
"Wait_for parked1"
SET DEBUG_SYNC='now WAIT_FOR parked1';
connect connection4,127.0.0.1,root,,test,$MASTER_MYPORT,;
connect connection5,127.0.0.1,root,,test,$MASTER_MYPORT,;
SET DEBUG_SYNC='now SIGNAL go';
connection default;
Id User Host db Command Time State Info
<Id> root <Host> test <Command> <Time> <State> <Info>
<Id> root <Host> test <Command> <Time> <State> <Info>
<Id> root <Host> test <Command> <Time> <State> <Info>
<Id> root <Host> test <Command> <Time> <State> <Info>
SHOW PROCESSLIST;
Id User Host db Command Time State Info
<Id> root <Host> test <Command> <Time> <State> <Info>
<Id> root <Host> test <Command> <Time> <State> <Info>
<Id> root <Host> test <Command> <Time> <State> <Info>
<Id> root <Host> test <Command> <Time> <State> <Info>
<Id> root <Host> test <Command> <Time> <State> <Info>
<Id> root <Host> test <Command> <Time> <State> <Info>
"Cleanup"
SET DEBUG_SYNC='RESET';
disconnect connection1;
disconnect connection2;
disconnect connection3;
disconnect connection4;
disconnect connection5;

43
mysql-test/suite/rpl/r/rpl_4threads_deadlock.result Normal file
View File

@ -0,0 +1,43 @@
include/master-slave.inc
[connection master]
FLUSH LOGS;
SET @save_debug=@@global.debug;
SET GLOBAL DEBUG='+d,before_dump_thread_acquires_current_mutex,processlist_acquiring_dump_threads_LOCK_thd_data';
include/stop_slave.inc
include/start_slave.inc
"Wait_for dump_thread_signal"
SET DEBUG_SYNC='now WAIT_FOR dump_thread_signal';
SET DEBUG_SYNC='show_binlogs_after_lock_log_before_lock_index SIGNAL parked1 WAIT_FOR go';
SHOW BINARY LOGS;
"Wait_for parked1"
SET DEBUG_SYNC='now WAIT_FOR parked1';
SET DEBUG_SYNC='purge_logs_after_lock_index_before_thread_count SIGNAL parked2 WAIT_FOR go';
PURGE BINARY LOGS BEFORE '9999-12-31';
"Wait_for parked2"
SET DEBUG_SYNC='now WAIT_FOR parked2';
SET DEBUG_SYNC='processlist_after_LOCK_thd_count_before_LOCK_thd_data SIGNAL parked3 WAIT_FOR go';
SELECT * FROM information_schema.processlist;
"Wait_for parked3"
SET DEBUG_SYNC='now WAIT_FOR parked3';
SET DEBUG_SYNC='now SIGNAL go';
include/stop_slave.inc
include/start_slave.inc
"Wait_for dump_thread_signal"
SET DEBUG_SYNC='now WAIT_FOR dump_thread_signal';
SET DEBUG_SYNC='show_binlogs_after_lock_log_before_lock_index SIGNAL parked1 WAIT_FOR go';
SHOW BINARY LOGS;
"Wait_for parked1"
SET DEBUG_SYNC='now WAIT_FOR parked1';
SET DEBUG_SYNC='purge_logs_after_lock_index_before_thread_count SIGNAL parked2 WAIT_FOR go';
PURGE BINARY LOGS BEFORE '9999-12-31';
"Wait_for parked2"
SET DEBUG_SYNC='now WAIT_FOR parked2';
SET DEBUG_SYNC='processlist_after_LOCK_thd_count_before_LOCK_thd_data SIGNAL parked3 WAIT_FOR go';
SHOW PROCESSLIST;
"Wait_for parked3"
SET DEBUG_SYNC='now WAIT_FOR parked3';
SET DEBUG_SYNC='now SIGNAL go';
"Cleanup"
SET DEBUG_SYNC='RESET';
SET GLOBAL DEBUG=@save_debug;
include/rpl_end.inc

117
mysql-test/suite/rpl/t/rpl_4threads_deadlock.test Normal file
View File

@ -0,0 +1,117 @@
###############################################################################
# Bug#17283409 4-WAY DEADLOCK: ZOMBIES, PURGING BINLOGS, SHOW PROCESSLIST,
# SHOW BINLOGS
# Problem: A deadlock was occuring when 4 threads were involved in acquiring
# locks
# Thread 1: Dump thread ( Slave is reconnecting, so on Master, a new dump
# thread is trying kill zombie dump threads. It acquired
# thread's LOCK_thd_data and it is about to acquire
# mysys_var->current_mutex ( which LOCK_log)
# Thread 2: Application thread is executing show binlogs and acquired
# LOCK_log and it is about to acquire LOCK_index.
# Thread 3: Applicaiton thread is executing Purge binary logs and acquired
# LOCK_index and it is about to acquire LOCK_thread_count.
# Thread 4: Application thread is executing show processlist and acquired
# LOCK_thread_count and it is about to acquire zombie dump
# thread's LOCK_thd_data.
# Deadlock : Thread 1 -> Thread 2 -> Thread 3-> Thread 4 -> Thread 1
# The same above deadlock was observed when thread 4 is replaced with another
# thread which is executing 'SELECT * FROM information_schema.processlist'
# command and acquired LOCK_thread_count and it is about to acquire zombie
# dump thread's LOCK_thd_data.
# Fix: Introuced a new lock (Lock_thread_remove) which will guard the thread
# deletion (exit process) and the same lock is used in show processlist
# execution instead of LOCK_thread_count. i.e., After the patch, Server allows
# new threads to join the system but it will not any threads to execute its
# 'cleanup' process. Now the new lock order is: LOCK_thread_remove ->
# LOCK_thd_data -> LOCK_log -> LOCK_index -> LOCK_thread_count Both the above
# scenarios are tested with the below test code and it proves that there is no
# deadlock after the fix.
###############################################################################
--source include/have_debug_sync.inc
--source include/have_binlog_format_statement.inc
--source include/master-slave.inc
connect(master2,127.0.0.1,root,,test,$MASTER_MYPORT,);
connect(master3,127.0.0.1,root,,test,$MASTER_MYPORT,);
--connection master
# Create atleast one binary log, otherwise purge logs command, show binary
# logs command do not hit the DEBUG_SYNC points.
FLUSH LOGS;
SET @save_debug=@@global.debug;
SET GLOBAL DEBUG='+d,before_dump_thread_acquires_current_mutex,processlist_acquiring_dump_threads_LOCK_thd_data';
# Iteration 1 with "SHOW PROCESSLIST command"
# Iteration 2 with "SELECT * FROM information_schema.processlist"
--let $iter=2
while ($iter)
{
--connection slave
--source include/stop_slave.inc
--source include/start_slave.inc
# Thread 1
--connection master
--echo "Wait_for dump_thread_signal"
SET DEBUG_SYNC='now WAIT_FOR dump_thread_signal';
# Thread 2
--connection master1
SET DEBUG_SYNC='show_binlogs_after_lock_log_before_lock_index SIGNAL parked1 WAIT_FOR go';
--send SHOW BINARY LOGS
--connection master
echo "Wait_for parked1";
SET DEBUG_SYNC='now WAIT_FOR parked1';
# Thread 3
--connection master2
SET DEBUG_SYNC='purge_logs_after_lock_index_before_thread_count SIGNAL parked2 WAIT_FOR go';
--send PURGE BINARY LOGS BEFORE '9999-12-31'
--connection master
echo "Wait_for parked2";
SET DEBUG_SYNC='now WAIT_FOR parked2';
# Thread 4
--connection master3
SET DEBUG_SYNC='processlist_after_LOCK_thd_count_before_LOCK_thd_data SIGNAL parked3 WAIT_FOR go';
if ($iter == 1)
{
--let $query=SHOW PROCESSLIST
}
if ($iter == 2)
{
--let $query=SELECT * FROM information_schema.processlist
}
--send_eval $query
--connection master
echo "Wait_for parked3";
SET DEBUG_SYNC='now WAIT_FOR parked3';
--connection master
SET DEBUG_SYNC='now SIGNAL go';
# Output of each command vary depends on other tests ran in suite(output vary
# in Pb2 runs), so lets ignore output. Anyways, we are interested in seeing
# that there is no deadlock.
--disable_result_log
--connection master1
--reap
--connection master2
--reap
--connection master3
--reap
--enable_result_log
--dec $iter
}
--echo "Cleanup"
--disconnect master2
--disconnect master3
--connection master
SET DEBUG_SYNC='RESET';
SET GLOBAL DEBUG=@save_debug;
source include/rpl_end.inc;

63
mysql-test/t/show_processlist.test Normal file
View File

@ -0,0 +1,63 @@
###############################################################################
--echo Bug#17283409 4-WAY DEADLOCK: ZOMBIES, PURGING BINLOGS, SHOW PROCESSLIST,
--echo SHOW BINLOGS
# After the fix for bug 17283409, We allow new connections while processing
# 'SHOW PROCESSLIST' command. This test script is to prove that even though we
# allow new connections to come in, 'SHOW PROCESSLIST' will not consider them,
# hence there is no worry of 'SHOW PROCESSLIST' going into a infinite loop if
# new connections are coming in continously.
###############################################################################
--source include/have_debug_sync.inc
--source include/count_sessions.inc
--enable_connect_log
connect(connection1,127.0.0.1,root,,test,$MASTER_MYPORT,);
--connection default
SET DEBUG_SYNC='before_one_element_read_from_threads_iterator SIGNAL parked1 WAIT_FOR go';
--send SHOW PROCESSLIST
--connection connection1
echo "Wait_for parked1";
SET DEBUG_SYNC='now WAIT_FOR parked1';
connect(connection2,127.0.0.1,root,,test,$MASTER_MYPORT,);
connect(connection3,127.0.0.1,root,,test,$MASTER_MYPORT,);
SET DEBUG_SYNC='now SIGNAL go';
--connection default
# We are yet to read the first element from the iterator when connection 2 and
# connection 3 joined the system. So this will show all 4 connections
# ( default + connection 1,2,3).
--replace_column 1 <Id> 3 <Host> 5 <Command> 6 <Time> 7 <State> 8 <Info>
--reap
# Test 2: To prove that connections which joined after reading the
# first element from the thread iterator will not be entertained
SET DEBUG_SYNC='after_one_element_read_from_threads_iterator SIGNAL parked1 WAIT_FOR go';
--send SHOW PROCESSLIST
--connection connection1
echo "Wait_for parked1";
SET DEBUG_SYNC='now WAIT_FOR parked1';
connect(connection4,127.0.0.1,root,,test,$MASTER_MYPORT,);
connect(connection5,127.0.0.1,root,,test,$MASTER_MYPORT,);
SET DEBUG_SYNC='now SIGNAL go';
--connection default
# This will show 4 connections only ( default + connection 1,2,3 ). Connections
# (connection4, connection 5) which entered after reading the first element
# from the iterator will not be processed by show processlist.
--replace_column 1 <Id> 3 <Host> 5 <Command> 6 <Time> 7 <State> 8 <Info>
--reap
#Now try the command once again.
# This will show 6 connections ( default + connection 1,2,3,4,5 )
--replace_column 1 <Id> 3 <Host> 5 <Command> 6 <Time> 7 <State> 8 <Info>
SHOW PROCESSLIST;
--echo "Cleanup"
# Reset DEBUG_SYNC
SET DEBUG_SYNC='RESET';
--disconnect connection1
--disconnect connection2
--disconnect connection3
--disconnect connection4
--disconnect connection5
--disable_connect_log
--source include/wait_until_count_sessions.inc