Skip to content

Commit 2d54bdb

Browse files
dtcpatriciodtcpatricio
committed
Bug#37486661 ndb_metadata thread can deadlock with truncate table
Summary: Prevent errors through lock corruption during TRUNCATE by not closing and reopening the NDB shared table handler while the table is recreated. Problem: When running continuous TRUNCATE SQL commands, while concurrently performing a NDB Backup, the MySQL Server could hang or ultimately crash. The hang and crash occurred around the same code point, at thr_lock(..), respectively with `wait_for_lock` and `has_old_lock`. Analysis: The order of operations of the TRUNCATE command, at the NDB plugin layer, can be narrowed to three main operations: 1. CLOSE table (ha_ndbcluster::close) 2. CREATE TABLE (TRUNCATE <=> DROP AND CREATE with ha_ndbcluster::create) 3. OPEN table (ha_ndbcluster::open) By observing the patterns, it is seen that if the Table undergoing TRUNCATE is still under BACKUP then the DROP fails and thus step (2) returns early. This causes the NDB_SHARE, a similar table handle as TABLE_SHARE, to continue to exist. On a success case, DROP would cause NDB_SHARE to be marked as dropped (ref count = 0) and CREATE would create a new NDB_SHARE. On a failed DROP case, the original NDB_SHARE is not marked as dropped. At this point, the OPEN step (3) is run and one of the operations is to initialize the thr_lock data for the handler, linking it with the NDB_SHARE thr_lock, and setting it into TL_UNLOCK. But, the NDB_SHARE and the handler's thr_lock data was LOCK'ed (specifically TL_WRITE_ALLOW_WRITE) therefore the aforementioned operation (set to TL_UNLOCK) effectively tramples the current lock data. The result is a badly cleaned and "unlocked" lock. The subsequent operations on that Table that require SQL locks might find the two problematic scenarios: 1. Found old lock with an owner and will wait thus, but that owner has already exited and trampled the lock 2. Will find old lock with some bad data and will SIGSEGV when reading the owner. Solution: Going back the call trace for the TRUNCATE command, the following list is an approximate order of operations: - OPEN table (SQL code) - LOCK table (1) (SQL code) - CLOSE table (NDB code) - TRUNCATE table, i.e., DROP/CREATE (2) (NDB code) - OPEN table (3) (NDB code) - UNLOCK table (4) (SQL code) - CLOSE TABLE (SQL code) The Table is already opened before TRUNCATE of SE is called. Therefore, if CLOSE and OPEN around TRUNCATE (ha_ndbcluster::create) can be ignored, then the LOCK structure remains untouched. The Table is already CLOSED when UNLOCKED, so it is expected that the resources the HANDLER has established when OPEN (buffers, etc) are to be freed. More specifically: On success: - DROP will mark the existing (locked) NDB_SHARE as Dropped (not yet physically released as the session has a reference to it) - OPEN will create a new NDB_SHARE (2 shares will exist) - UNLOCK will remove locks from old NDB_SHARE - CLOSE will reduce ref count on old NDB_SHARE decrementing to zero + freeing it (1 share exists) On failure: - DROP will do nothing - UNLOCK will remove locks from old NDB_SHARE - CLOSE will reduce ref count on old NDB_SHARE, but it will be retained (1 share exists) Change-Id: Ib2cbb3cf49ceac6ad2717e000b5b89beb026e4e4
1 parent 4c1fdd1 commit 2d54bdb

File tree

5 files changed

+322
-9
lines changed

5 files changed

+322
-9
lines changed

‎mysql-test/suite/ndb/r/ndb_truncate_fail.result‎

Lines changed: 71 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,71 @@
1+
# [connection default]
2+
CALL create_tables(20);
3+
CALL insert_row(20);
4+
SELECT COUNT(*) FROM t1;
5+
COUNT(*)
6+
1
7+
SELECT COUNT(*) FROM t20;
8+
COUNT(*)
9+
1
10+
SET GLOBAL ndb_metadata_sync = 'ON';
11+
# Start truncating
12+
CALL truncate_list(1,10);
13+
# Now fail all drops (1st phase of truncate)
14+
SET @saved_debug = @@GLOBAL.debug;
15+
SET @@GLOBAL.debug = '+d,ndb_fail_drop';
16+
CALL truncate_list(11, 20);
17+
ERROR HY000: Got error 761 'Unable to drop table as backup is in progress' from NDBCLUSTER
18+
CALL truncate_list(11, 20);
19+
ERROR HY000: Got error 761 'Unable to drop table as backup is in progress' from NDBCLUSTER
20+
# t1->t10 must have been truncated
21+
SELECT COUNT(*) FROM t1;
22+
COUNT(*)
23+
0
24+
SELECT COUNT(*) FROM t10;
25+
COUNT(*)
26+
0
27+
# t11->t20 must have failed
28+
SELECT COUNT(*) FROM t11;
29+
COUNT(*)
30+
1
31+
SELECT COUNT(*) FROM t20;
32+
COUNT(*)
33+
1
34+
# [connection server1]
35+
SET DEBUG_SYNC='truncate_stop_after_execute SIGNAL signal1 WAIT_FOR go_signal1';
36+
CALL truncate_list(1,20);
37+
# [connection server2]
38+
CALL truncate_list(1,20);
39+
# [connection default]
40+
SET DEBUG_SYNC='now SIGNAL go_signal1';
41+
# [connection server1]
42+
ERROR HY000: Got error 761 'Unable to drop table as backup is in progress' from NDBCLUSTER
43+
# [connection server2]
44+
# [connection server1]
45+
SET DEBUG_SYNC='truncate_stop_after_execute SIGNAL signal1 WAIT_FOR go_signal1';
46+
CALL truncate_list(1,20);
47+
# [connection server2]
48+
CALL truncate_list(1,20);
49+
# [connection default]
50+
SET DEBUG_SYNC='now SIGNAL go_signal1';
51+
# [connection server1]
52+
ERROR HY000: Got error 761 'Unable to drop table as backup is in progress' from NDBCLUSTER
53+
# [connection server2]
54+
# [connection default]
55+
# Re-insert data to assess that share locks were properly cleaned
56+
CALL insert_row(20);
57+
# All tables should have data (t1->t20 1 row, by server2)
58+
SELECT COUNT(*) FROM t1;
59+
COUNT(*)
60+
1
61+
SELECT COUNT(*) FROM t20;
62+
COUNT(*)
63+
1
64+
# Cleanup
65+
DROP PROCEDURE truncate_list;
66+
SET GLOBAL debug = @saved_debug;
67+
CALL drop_tables(20);
68+
DROP PROCEDURE create_tables;
69+
DROP PROCEDURE drop_tables;
70+
DROP PROCEDURE insert_row;
71+
DROP PROCEDURE truncate_list;

‎mysql-test/suite/ndb/t/ndb_truncate_fail.test‎

Lines changed: 151 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,151 @@
1+
--source include/have_ndb.inc
2+
--source include/have_debug.inc
3+
4+
connect(server1,127.0.0.1,root,,test,$MASTER_MYPORT,);
5+
connect(server2,127.0.0.1,root,,test,$MASTER_MYPORT1,);
6+
--echo # [connection default]
7+
--connection default
8+
9+
--disable_query_log
10+
DELIMITER //;
11+
CREATE PROCEDURE create_tables (IN ntables INT)
12+
BEGIN
13+
SET @idx = 1;
14+
WHILE @idx <= ntables DO
15+
SET @pstmt = CONCAT('CREATE TABLE t', @idx, ' (a INT PRIMARY KEY AUTO_INCREMENT, c CHAR(3)) ENGINE = NDB');
16+
PREPARE stmt FROM @pstmt;
17+
EXECUTE stmt;
18+
DEALLOCATE PREPARE stmt;
19+
SET @idx = @idx + 1;
20+
END WHILE;
21+
END //
22+
23+
CREATE PROCEDURE drop_tables (IN ntables INT)
24+
BEGIN
25+
SET @idx = 1;
26+
WHILE @idx <= ntables DO
27+
SET @pstmt = CONCAT('DROP TABLE t', @idx);
28+
PREPARE stmt FROM @pstmt;
29+
EXECUTE stmt;
30+
DEALLOCATE PREPARE stmt;
31+
SET @idx = @idx + 1;
32+
END WHILE;
33+
END //
34+
35+
CREATE PROCEDURE insert_row (IN ntables INT)
36+
BEGIN
37+
SET @idx = 1;
38+
WHILE @idx <= ntables DO
39+
SET @pstmt = CONCAT('INSERT INTO t', @idx, ' (c) VALUES (\'val\')');
40+
PREPARE stmt FROM @pstmt;
41+
EXECUTE stmt;
42+
DEALLOCATE PREPARE stmt;
43+
SET @idx = @idx + 1;
44+
END WHILE;
45+
END //
46+
47+
CREATE PROCEDURE truncate_list(IN first_tab_idx INT, IN last_tab_idx INT)
48+
BEGIN
49+
SET @idx = first_tab_idx;
50+
WHILE @idx <= last_tab_idx DO
51+
SET @pstmt = CONCAT('TRUNCATE TABLE t', @idx);
52+
PREPARE stmt FROM @pstmt;
53+
EXECUTE stmt;
54+
DEALLOCATE PREPARE stmt;
55+
SET @idx = @idx + 1;
56+
END WHILE;
57+
END //
58+
59+
--connection server2
60+
CREATE PROCEDURE truncate_list(IN first_tab_idx INT, IN last_tab_idx INT)
61+
BEGIN
62+
SET @idx = first_tab_idx;
63+
WHILE @idx <= last_tab_idx DO
64+
SET @pstmt = CONCAT('TRUNCATE TABLE t', @idx);
65+
PREPARE stmt FROM @pstmt;
66+
EXECUTE stmt;
67+
DEALLOCATE PREPARE stmt;
68+
SET @idx = @idx + 1;
69+
END WHILE;
70+
END //
71+
72+
--connection default
73+
DELIMITER ;//
74+
--enable_query_log
75+
76+
CALL create_tables(20);
77+
CALL insert_row(20);
78+
79+
# Data at t1
80+
SELECT COUNT(*) FROM t1;
81+
# Data at t20
82+
SELECT COUNT(*) FROM t20;
83+
SET GLOBAL ndb_metadata_sync = 'ON';
84+
85+
--echo # Start truncating
86+
CALL truncate_list(1,10);
87+
88+
--echo # Now fail all drops (1st phase of truncate)
89+
SET @saved_debug = @@GLOBAL.debug;
90+
SET @@GLOBAL.debug = '+d,ndb_fail_drop';
91+
--error 1296
92+
CALL truncate_list(11, 20);
93+
# repeat once again to stress out share locks
94+
--error 1296
95+
CALL truncate_list(11, 20);
96+
97+
--echo # t1->t10 must have been truncated
98+
SELECT COUNT(*) FROM t1;
99+
SELECT COUNT(*) FROM t10;
100+
--echo # t11->t20 must have failed
101+
SELECT COUNT(*) FROM t11;
102+
SELECT COUNT(*) FROM t20;
103+
104+
# Do the same with two connections. Server1 fails all but server2 queues and is successful
105+
--let $iter=2
106+
while($iter)
107+
{
108+
--echo # [connection server1]
109+
--connection server1
110+
SET DEBUG_SYNC='truncate_stop_after_execute SIGNAL signal1 WAIT_FOR go_signal1';
111+
--send CALL truncate_list(1,20)
112+
113+
--echo # [connection server2]
114+
--connection server2
115+
--send CALL truncate_list(1,20)
116+
117+
--echo # [connection default]
118+
--connection default
119+
SET DEBUG_SYNC='now SIGNAL go_signal1';
120+
121+
--echo # [connection server1]
122+
--connection server1
123+
--error 1296
124+
--reap
125+
--echo # [connection server2]
126+
--connection server2
127+
--reap
128+
129+
--dec $iter
130+
}
131+
132+
--echo # [connection default]
133+
--connection default
134+
--echo # Re-insert data to assess that share locks were properly cleaned
135+
CALL insert_row(20);
136+
--echo # All tables should have data (t1->t20 1 row, by server2)
137+
SELECT COUNT(*) FROM t1;
138+
SELECT COUNT(*) FROM t20;
139+
140+
--echo # Cleanup
141+
--connection server2
142+
DROP PROCEDURE truncate_list;
143+
--connection default
144+
SET GLOBAL debug = @saved_debug;
145+
CALL drop_tables(20);
146+
DROP PROCEDURE create_tables;
147+
DROP PROCEDURE drop_tables;
148+
DROP PROCEDURE insert_row;
149+
DROP PROCEDURE truncate_list;
150+
--disconnect server1
151+
--disconnect server2

‎storage/ndb/plugin/ha_ndbcluster.cc‎

Lines changed: 63 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -9388,7 +9388,12 @@ int ha_ndbcluster::create(const char *path [[maybe_unused]],
93889388
const char *dbname = table_share->db.str;
93899389
const char *tabname = table_share->table_name.str;
93909390

9391-
ndb_log_info("Creating table '%s.%s'", dbname, tabname);
9391+
{
9392+
const int sql_cmd = thd_sql_command(thd);
9393+
ndb_log_info("%s table '%s.%s'",
9394+
sql_cmd == SQLCOM_TRUNCATE ? "Truncating" : "Creating", dbname,
9395+
tabname);
9396+
}
93929397

93939398
Ndb_schema_dist_client schema_dist_client(thd);
93949399

@@ -10386,21 +10391,40 @@ int ha_ndbcluster::truncate(dd::Table *table_def) {
1038610391
/* Fill in create_info from the open table */
1038710392
HA_CREATE_INFO create_info;
1038810393
update_create_info_from_table(&create_info, table);
10389-
10390-
// Close the table, will always return 0
10391-
(void)close();
10394+
#ifndef NDEBUG
10395+
const NDB_SHARE *old_share_ptr_for_sanity_check = m_share;
10396+
#endif
1039210397

1039310398
// Call ha_ndbcluster::create which will detect that this is a
1039410399
// truncate and thus drop the table before creating it again.
1039510400
const int truncate_error =
1039610401
create(table->s->normalized_path.str, table, &create_info, table_def);
1039710402

10398-
// Open the table again even if the truncate failed, the caller
10399-
// expect the table to be open. Report any error during open.
10400-
const int open_error = open(table->s->normalized_path.str, 0, 0, table_def);
10403+
DBUG_PRINT("debug", ("truncate res: %d", truncate_error));
10404+
#ifndef NDEBUG
10405+
/**
10406+
* This sync point is used by tests that want to assess the
10407+
* concurrency of the truncate, specially the correct state of the
10408+
* THR_LOCK_DATA (m_lock) to avoid deadlocks.
10409+
*/
10410+
if (current_thd) DEBUG_SYNC(current_thd, "truncate_stop_after_execute");
10411+
/**
10412+
* create() creates a new ndb_share, but it is NOT set as this
10413+
* handler's m_share, because the currently opened ndb_share is the
10414+
* old one. This old share will thus be released through the closing
10415+
* of this handler's usage of the table. Following is a sanity check
10416+
* that this handler's share pointer does not change despite there
10417+
* being a new share.
10418+
*/
10419+
if (unlikely(old_share_ptr_for_sanity_check != m_share)) {
10420+
ndb_log_error(
10421+
"Fatal! Truncate table re-create modified "
10422+
"the handler's currently opened share pointer.");
10423+
abort();
10424+
}
10425+
#endif
1040110426

10402-
if (truncate_error) return truncate_error;
10403-
return open_error;
10427+
return truncate_error;
1040410428
}
1040510429

1040610430
int ha_ndbcluster::prepare_inplace__add_index(THD *thd, KEY *key_info,
@@ -11120,6 +11144,11 @@ static bool drop_table_and_related(THD *thd, Ndb *ndb,
1112011144
return false;
1112111145
}
1112211146

11147+
DBUG_EXECUTE_IF("ndb_fail_drop", {
11148+
// Simulate failure. A bogus error code will be set on the caller.
11149+
return false;
11150+
});
11151+
1112311152
// Drop the table
1112411153
if (dict->dropTableGlobal(*table, drop_flags) != 0) {
1112511154
const NdbError &ndb_err = dict->getNdbError();
@@ -11232,6 +11261,11 @@ int drop_table_impl(THD *thd, Ndb *ndb,
1123211261

1123311262
Thd_ndb *thd_ndb = get_thd_ndb(thd);
1123411263
const int dict_error_code = dict->getNdbError().code;
11264+
DBUG_EXECUTE_IF("ndb_fail_drop", {
11265+
int *ec = const_cast<int *>(&dict_error_code);
11266+
// backup in progress (e.g.)
11267+
*ec = 761;
11268+
});
1123511269
// Check if an error has occurred. Note that if the table didn't exist in NDB
1123611270
// (denoted by error codes 709 or 723), it's considered a success
1123711271
if (dict_error_code && dict_error_code != 709 && dict_error_code != 723) {
@@ -11548,6 +11582,7 @@ int ha_ndbcluster::open(const char *path [[maybe_unused]],
1154811582
return HA_ERR_NO_CONNECTION;
1154911583
}
1155011584

11585+
DBUG_EXECUTE("debug", NDB_SHARE::dbg_print_locks(m_share););
1155111586
// Init table lock structure
1155211587
thr_lock_data_init(&m_share->lock, &m_lock, (void *)nullptr);
1155311588

@@ -11864,6 +11899,23 @@ inline void ha_ndbcluster::release_key_fields() {
1186411899
}
1186511900
}
1186611901

11902+
static void check_thr_lock_data_unused(const THR_LOCK_DATA *thr_lock_data) {
11903+
/**
11904+
* Check that the handler is not involved in any SQL (thr_lock) locking before
11905+
* ending its lifecycle.
11906+
*/
11907+
if (unlikely(thr_lock_data->type > TL_UNLOCK)) {
11908+
ndb_log_error(
11909+
"Fatal! Closing handler involved in thr_lock: "
11910+
"thread_id %u "
11911+
"type %u "
11912+
"thr_lock %p",
11913+
thr_lock_data->owner ? thr_lock_data->owner->thread_id : 0,
11914+
thr_lock_data->type, thr_lock_data->lock);
11915+
abort();
11916+
}
11917+
}
11918+
1186711919
/**
1186811920
Close an open ha_ndbcluster instance.
1186911921

@@ -11887,6 +11939,8 @@ inline void ha_ndbcluster::release_key_fields() {
1188711939
int ha_ndbcluster::close(void) {
1188811940
DBUG_TRACE;
1188911941

11942+
check_thr_lock_data_unused(&m_lock);
11943+
1189011944
release_key_fields();
1189111945
release_ndb_share();
1189211946

0 commit comments

Comments
 (0)