mirror/mariadb
1
0
Fork 0
mirror of https://github.com/MariaDB/server.git synced 2025-03-26 17:08:41 +01:00
Code Issues Projects Releases Packages Wiki Activity Actions1

Implement multiple-signal debug_sync

Browse source 
The patch is inspired from MySQL. Instead of using a single String to
hold the current active debug_sync signal, use a Hash_set to store
LEX_STRINGS. This patch ensures that a signal can not be lost, by being
overwritten by another thread via set DEBUG_SYNC = '... SIGNAL ...';

All signals are kepts "alive" until they are consumed by a wait event.

This requires updating test cases that assume the GLOBAL signal is never
consumed.

Follow-up work needed:
Port the additional syntax that allows one to set multiple signals
and also conditionally deactivate signals when waiting.
This commit is contained in:
Vicențiu Ciorbaru 2021-09-28 22:17:59 +03:00
parent cc08872c16
commit 8885225de6
7 changed files with 162 additions and 48 deletions

39
mysql-test/main/debug_sync.result
View file

@ -2,7 +2,7 @@ SET DEBUG_SYNC= 'RESET';
DROP TABLE IF EXISTS t1;
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: ''
debug_sync ON - current signals: ''
SET DEBUG_SYNC='p0 SIGNAL s1 WAIT_FOR s2 TIMEOUT 6 EXECUTE 2 HIT_LIMIT 3';
SET DEBUG_SYNC='p0 SIGNAL s1 WAIT_FOR s2 TIMEOUT 6 EXECUTE 2';
SET DEBUG_SYNC='p0 SIGNAL s1 WAIT_FOR s2 TIMEOUT 6 HIT_LIMIT 3';
@ -150,34 +150,34 @@ SET @myvar= 'now SIGNAL from_myvar';
SET DEBUG_SYNC= @myvar;
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: 'from_myvar'
debug_sync ON - current signals: 'from_myvar'
SET DEBUG_SYNC= LEFT('now SIGNAL from_function_cut_here', 24);
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: 'from_function'
debug_sync ON - current signals: 'from_myvar,from_function'
SET DEBUG_SYNC= 'now SIGNAL something';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: 'something'
debug_sync ON - current signals: 'something,from_function,from_myvar'
SET DEBUG_SYNC= 'now WAIT_FOR nothing TIMEOUT 0';
Warnings:
Warning #### debug sync point wait timed out
SET DEBUG_SYNC= 'now SIGNAL nothing';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: 'nothing'
debug_sync ON - current signals: 'something,from_function,nothing,from_myvar'
SET DEBUG_SYNC= 'now WAIT_FOR nothing TIMEOUT 0';
SET DEBUG_SYNC= 'now SIGNAL something EXECUTE 0';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: 'nothing'
debug_sync ON - current signals: 'something,from_function,from_myvar'
SET DEBUG_SYNC= 'now WAIT_FOR anotherthing TIMEOUT 0 EXECUTE 0';
SET DEBUG_SYNC= 'now HIT_LIMIT 1';
ERROR HY000: debug sync point hit limit reached
SET DEBUG_SYNC= 'RESET';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: ''
debug_sync ON - current signals: ''
SET DEBUG_SYNC= 'p1abcd SIGNAL s1 EXECUTE 2';
SET DEBUG_SYNC= 'p2abc SIGNAL s2 EXECUTE 2';
SET DEBUG_SYNC= 'p9abcdef SIGNAL s9 EXECUTE 2';
@ -190,23 +190,30 @@ SET DEBUG_SYNC= 'p3abcdef SIGNAL s3 EXECUTE 2';
SET DEBUG_SYNC= 'p4a TEST';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: 's4'
debug_sync ON - current signals: 's4'
SET DEBUG_SYNC= 'p1abcd TEST';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: 's1'
debug_sync ON - current signals: 's4,s1'
SET DEBUG_SYNC= 'p7 TEST';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: 's7'
debug_sync ON - current signals: 's1,s7,s4'
SET DEBUG_SYNC= 'p9abcdef TEST';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: 's9'
debug_sync ON - current signals: 's1,s7,s4,s9'
SET DEBUG_SYNC= 'p3abcdef TEST';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: 's3'
debug_sync ON - current signals: 's1,s3,s4,s9,s7'
SET DEBUG_SYNC= 'now WAIT_FOR s9';
SET DEBUG_SYNC= 'now WAIT_FOR s1';
SET DEBUG_SYNC= 'now WAIT_FOR s4';
SET DEBUG_SYNC= 'now WAIT_FOR s7';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signals: 's3'
SET DEBUG_SYNC= 'p1abcd CLEAR';
SET DEBUG_SYNC= 'p2abc CLEAR';
SET DEBUG_SYNC= 'p5abcde CLEAR';
@ -219,19 +226,19 @@ SET DEBUG_SYNC= 'p7 CLEAR';
SET DEBUG_SYNC= 'p1abcd TEST';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: 's3'
debug_sync ON - current signals: 's3'
SET DEBUG_SYNC= 'p7 TEST';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: 's3'
debug_sync ON - current signals: 's3'
SET DEBUG_SYNC= 'p9abcdef TEST';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: 's3'
debug_sync ON - current signals: 's3'
SET DEBUG_SYNC= 'RESET';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
Variable_name Value
debug_sync ON - current signal: ''
debug_sync ON - current signals: ''
CREATE USER mysqltest_1@localhost;
GRANT SUPER ON *.* TO mysqltest_1@localhost;
connect con1,localhost,mysqltest_1,,;

12
mysql-test/main/debug_sync.test
View file

@ -298,6 +298,16 @@ SET DEBUG_SYNC= 'p9abcdef TEST';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
SET DEBUG_SYNC= 'p3abcdef TEST';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
#
# Wait for all signals currently active except s3.
#
SET DEBUG_SYNC= 'now WAIT_FOR s9';
SET DEBUG_SYNC= 'now WAIT_FOR s1';
SET DEBUG_SYNC= 'now WAIT_FOR s4';
SET DEBUG_SYNC= 'now WAIT_FOR s7';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
#
# Clear the actions.
#
@ -320,7 +330,7 @@ SHOW VARIABLES LIKE 'DEBUG_SYNC';
SET DEBUG_SYNC= 'p9abcdef TEST';
SHOW VARIABLES LIKE 'DEBUG_SYNC';
#
# Now cleanup. Actions are clear already, but signal needs to be cleared.
# Now cleanup. Actions are clear already, but s3 signal needs to be cleared.
#
SET DEBUG_SYNC= 'RESET';
SHOW VARIABLES LIKE 'DEBUG_SYNC';

3
mysql-test/suite/innodb/r/mdev-14846.result
View file

@ -31,11 +31,12 @@ pk f1 f2 f3
3 t q 1
5 z t NULL
SET DEBUG_SYNC='now SIGNAL default_dml';
SET DEBUG_SYNC='now SIGNAL con2_dml';
connection default;
SET DEBUG_SYNC='now WAIT_FOR default_dml';
UPDATE t3 AS alias1 LEFT JOIN t3 AS alias2 ON ( alias1.f1 <> alias1.f2 ) SET alias1.f3 = 59 WHERE ( EXISTS ( SELECT t1.f3 FROM t1 WHERE t1.f1 = alias1.f1 ) ) OR alias2.f1 = 'h';
connect con2,localhost,root,,test;
set debug_sync='now WAIT_FOR default_dml';
set debug_sync='now WAIT_FOR con2_dml';
SET DEBUG_SYNC='now SIGNAL con1_dml2';
disconnect con2;
connection con1;

3
mysql-test/suite/innodb/t/mdev-14846.test
View file

@ -35,6 +35,7 @@ SET DEBUG_SYNC='now WAIT_FOR con1_dml';
begin;
SELECT * FROM t1 for update; # Holds x lock of all records in the table t1
SET DEBUG_SYNC='now SIGNAL default_dml';
SET DEBUG_SYNC='now SIGNAL con2_dml';
--connection default
SET DEBUG_SYNC='now WAIT_FOR default_dml';
@ -42,7 +43,7 @@ SET DEBUG_SYNC='now WAIT_FOR default_dml';
# It holds the lock of all record in t3 and tries to acquire record lock for the table t1.
--connect (con2,localhost,root,,test)
set debug_sync='now WAIT_FOR default_dml';
set debug_sync='now WAIT_FOR con2_dml';
let $wait_condition=
select count(*) > 0 from information_schema.innodb_lock_waits;
--source include/wait_condition.inc

6
mysql-test/suite/sys_vars/r/debug_sync_basic.result
View file

@ -2,17 +2,17 @@ select @@global.debug_sync;
ERROR HY000: Variable 'debug_sync' is a SESSION variable
select @@session.debug_sync;
@@session.debug_sync
ON - current signal: ''
ON - current signals: ''
show global variables like "debug_sync";
Variable_name Value
show session variables like "debug_sync";
Variable_name Value
debug_sync ON - current signal: ''
debug_sync ON - current signals: ''
select * from information_schema.global_variables where variable_name="debug_sync";
VARIABLE_NAME VARIABLE_VALUE
select * from information_schema.session_variables where variable_name="debug_sync";
VARIABLE_NAME VARIABLE_VALUE
DEBUG_SYNC ON - current signal: ''
DEBUG_SYNC ON - current signals: ''
set @@session.debug_sync=1;
ERROR 42000: Incorrect argument type to variable 'debug_sync'
set @@session.debug_sync=1.1;

2
mysql-test/suite/sys_vars/r/sysvars_debug.result
View file

@ -77,7 +77,7 @@ READ_ONLY YES
COMMAND_LINE_ARGUMENT OPTIONAL
GLOBAL_VALUE_PATH NULL
VARIABLE_NAME DEBUG_SYNC
SESSION_VALUE ON - current signal: ''
SESSION_VALUE ON - current signals: ''
GLOBAL_VALUE NULL
GLOBAL_VALUE_ORIGIN COMPILE-TIME
DEFAULT_VALUE

145
sql/debug_sync.cc
View file

@ -67,21 +67,99 @@ struct st_debug_sync_control
};
/**
Definitions for the debug sync facility.
1. Global string variable to hold a "signal" ("signal post", "flag mast").
1. Global string variable to hold a set of of "signals".
2. Global condition variable for signaling and waiting.
3. Global mutex to synchronize access to the above.
*/
struct st_debug_sync_globals
{
String ds_signal; /* signal variable */
Hash_set<LEX_CSTRING> ds_signal_set; /* A set of active signals */
mysql_cond_t ds_cond; /* condition variable */
mysql_mutex_t ds_mutex; /* mutex variable */
ulonglong dsp_hits; /* statistics */
ulonglong dsp_executed; /* statistics */
ulonglong dsp_max_active; /* statistics */
st_debug_sync_globals() : ds_signal_set(PSI_NOT_INSTRUMENTED, signal_key) {};
~st_debug_sync_globals()
{
clear_set();
}
void clear_set()
{
Hash_set<LEX_CSTRING>::Iterator it{ds_signal_set};
LEX_CSTRING *s;
while ((s= it++))
my_free(s);
ds_signal_set.clear();
}
/* Hash key function for ds_signal_set. */
static uchar *signal_key(const LEX_CSTRING *str, size_t *klen, my_bool)
{
*klen= str->length;
return (uchar*) str->str;
}
/**
Return true if the signal is found in global signal list.
@param signal_name Signal name identifying the signal.
@note
If signal is found in the global signal set, it means that the
signal thread has signalled to the waiting thread. This method
must be called with the debug_sync_global.ds_mutex held.
@retval true if signal is found in the global signal list.
@retval false otherwise.
*/
inline bool is_signalled(const String &signal_name)
{
return ds_signal_set.find(signal_name.ptr(), signal_name.length());
}
void clear_signal(const String &signal_name)
{
DBUG_ENTER("clear_signal");
LEX_CSTRING *record= ds_signal_set.find(signal_name.ptr(),
signal_name.length());
if (record)
{
ds_signal_set.remove(record);
my_free(record);
}
DBUG_VOID_RETURN;
}
bool set_signal(const String &signal_name)
{
/* Need to check if the signal is already in the hash set, because
Hash_set doesn't differentiate between OOM and key already in. */
if (is_signalled(signal_name))
return FALSE;
/* LEX_CSTRING and the string allocated with only one malloc. */
LEX_CSTRING *s= (LEX_CSTRING *) my_malloc(PSI_NOT_INSTRUMENTED,
sizeof(LEX_CSTRING) +
signal_name.length() + 1, MYF(0));
char *str= (char *)(s + 1);
memcpy(str, signal_name.ptr(), signal_name.length());
str[signal_name.length()]= '\0';
s->length= signal_name.length();
s->str= str;
if (ds_signal_set.insert(s))
return TRUE;
return FALSE;
}
};
static st_debug_sync_globals debug_sync_global; /* All globals in one object */
/**
@ -161,7 +239,7 @@ int debug_sync_init(void)
int rc;
/* Initialize the global variables. */
debug_sync_global.ds_signal.length(0);
debug_sync_global.clear_set();
if ((rc= mysql_cond_init(key_debug_sync_globals_ds_cond,
&debug_sync_global.ds_cond, NULL)) ||
(rc= mysql_mutex_init(key_debug_sync_globals_ds_mutex,
@ -195,7 +273,7 @@ void debug_sync_end(void)
debug_sync_C_callback_ptr= NULL;
/* Destroy the global variables. */
debug_sync_global.ds_signal.free();
debug_sync_global.clear_set();
mysql_cond_destroy(&debug_sync_global.ds_cond);
mysql_mutex_destroy(&debug_sync_global.ds_mutex);
@ -554,7 +632,7 @@ static void debug_sync_reset(THD *thd)
/* Clear the global signal. */
mysql_mutex_lock(&debug_sync_global.ds_mutex);
debug_sync_global.ds_signal.length(0);
debug_sync_global.clear_set();
mysql_mutex_unlock(&debug_sync_global.ds_mutex);
DBUG_VOID_RETURN;
@ -1325,13 +1403,19 @@ uchar *debug_sync_value_ptr(THD *thd)
if (opt_debug_sync_timeout)
{
static char on[]= "ON - current signal: '";
static char on[]= "ON - current signals: '";
// Ensure exclusive access to debug_sync_global.ds_signal
mysql_mutex_lock(&debug_sync_global.ds_mutex);
size_t lgt= (sizeof(on) /* includes '\0' */ +
debug_sync_global.ds_signal.length() + 1 /* for '\'' */);
size_t lgt= sizeof(on) + 1; /* +1 as we'll have to append ' at the end. */
for (size_t i= 0; i < debug_sync_global.ds_signal_set.size(); i++)
{
/* Assume each signal is separated by a comma, hence +1. */
lgt+= debug_sync_global.ds_signal_set.at(i)->length + 1;
}
char *vend;
char *vptr;
@ -1339,10 +1423,15 @@ uchar *debug_sync_value_ptr(THD *thd)
{
vend= value + lgt - 1; /* reserve space for '\0'. */
vptr= debug_sync_bmove_len(value, vend, STRING_WITH_LEN(on));
vptr= debug_sync_bmove_len(vptr, vend, debug_sync_global.ds_signal.ptr(),
debug_sync_global.ds_signal.length());
if (vptr < vend)
*(vptr++)= '\'';
for (size_t i= 0; i < debug_sync_global.ds_signal_set.size(); i++)
{
const LEX_CSTRING *s= debug_sync_global.ds_signal_set.at(i);
vptr= debug_sync_bmove_len(vptr, vend, s->str, s->length);
if (i != debug_sync_global.ds_signal_set.size() - 1)
*(vptr++)= ',';
}
DBUG_ASSERT(vptr < vend);
*(vptr++)= '\'';
*vptr= '\0'; /* We have one byte reserved for the worst case. */
}
mysql_mutex_unlock(&debug_sync_global.ds_mutex);
@ -1358,6 +1447,9 @@ uchar *debug_sync_value_ptr(THD *thd)
}
/**
Execute requested action at a synchronization point.
@ -1413,12 +1505,12 @@ static void debug_sync_execute(THD *thd, st_debug_sync_action *action)
read access too, to create a memory barrier in order to avoid that
threads just reads an old cached version of the signal.
*/
mysql_mutex_lock(&debug_sync_global.ds_mutex);
if (action->signal.length())
{
/* Copy the signal to the global variable. */
if (debug_sync_global.ds_signal.copy(action->signal))
if (debug_sync_global.set_signal(action->signal))
{
/*
Error is reported by my_malloc().
@ -1461,12 +1553,12 @@ static void debug_sync_execute(THD *thd, st_debug_sync_action *action)
restore_current_mutex = false;
set_timespec(abstime, action->timeout);
DBUG_EXECUTE("debug_sync_exec",
// TODO turn this into a for loop printing.
DBUG_EXECUTE("debug_sync_exec", {
/* Functions as DBUG_PRINT args can change keyword and line nr. */
DBUG_PRINT("debug_sync_exec",
("wait for '%s' at: '%s' curr: '%s'",
sig_wait, dsp_name,
debug_sync_global.ds_signal.c_ptr())););
("wait for '%s' at: '%s'",
sig_wait, dsp_name));});
/*
Wait until global signal string matches the wait_for string.
@ -1474,18 +1566,19 @@ static void debug_sync_execute(THD *thd, st_debug_sync_action *action)
The facility can become disabled when some thread cannot get
the required dynamic memory allocated.
*/
while (stringcmp(&debug_sync_global.ds_signal, &action->wait_for) &&
!(thd->killed & KILL_HARD_BIT) && opt_debug_sync_timeout)
while (!debug_sync_global.is_signalled(action->wait_for) &&
!(thd->killed & KILL_HARD_BIT)&&
opt_debug_sync_timeout)
{
error= mysql_cond_timedwait(&debug_sync_global.ds_cond,
&debug_sync_global.ds_mutex,
&abstime);
DBUG_EXECUTE("debug_sync",
// TODO turn this into a for loop printing.
DBUG_EXECUTE("debug_sync", {
/* Functions as DBUG_PRINT args can change keyword and line nr. */
DBUG_PRINT("debug_sync",
("awoke from %s global: %s error: %d",
sig_wait, debug_sync_global.ds_signal.c_ptr(),
error)););
("awoke from %s error: %d",
sig_wait, error));});
if (unlikely(error == ETIMEDOUT || error == ETIME))
{
// We should not make the statement fail, even if in strict mode.
@ -1498,6 +1591,8 @@ static void debug_sync_execute(THD *thd, st_debug_sync_action *action)
}
error= 0;
}
// TODO conditional on clear-event
debug_sync_global.clear_signal(action->wait_for);
DBUG_EXECUTE("debug_sync_exec",
if (thd->killed)
DBUG_PRINT("debug_sync_exec",
@ -1571,10 +1666,10 @@ static void debug_sync(THD *thd, const char *sync_point_name, size_t name_len)
st_debug_sync_control *ds_control= thd->debug_sync_control;
st_debug_sync_action *action;
DBUG_ENTER("debug_sync");
DBUG_PRINT("debug_sync_point", ("hit: '%s'", sync_point_name));
DBUG_ASSERT(sync_point_name);
DBUG_ASSERT(name_len);
DBUG_ASSERT(ds_control);
DBUG_PRINT("debug_sync_point", ("hit: '%s'", sync_point_name));
/* Statistics. */
ds_control->dsp_hits++;