Details
-
Bug
-
Status: Open (View Workflow)
-
Major
-
Resolution: Unresolved
-
11.8.1, 10.11
-
None
-
None
-
debian bookworm/trixie
Description
I've been evaluating a galera upgrade from a standalone mariadb server and it's been working well aside from one major hiccup.
We have a 3-node cluster set up and when stopping a node and starting it again, it sometimes (more often than not) will get completely stuck syncing and never recover unless it is synced fresh (restarts do nothing either)
On the affected node we see it says it's joining:
VARIABLE_NAME VARIABLE_VALUE
wsrep_local_state_comment Joining: receiving State Transfer
wsrep_cluster_size 2
wsrep_cluster_status non-Primary
wsrep_connected ON
wsrep_ready OFF
Looking at "SHOW PROCESSLIST" this shows something along the lines of:
Id User Host db Command Time State Info Progress
|
1 system user NULL Sleep 119 wsrep aborter idle NULL 0.000 |
2 system user NULL Sleep 117 wsrep applier committed NULL 0.000 |
[.. other "wsrep applier committed" omitted, see id gaps ..] |
7 system user NULL Sleep 117 Waiting for certification NULL 0.000 |
20 system user NULL Sleep 117 Waiting for certification NULL 0.000 |
21 system user NULL Sleep 117 Waiting for certification NULL 0.000 |
23 system user NULL Sleep 117 Waiting for certification NULL 0.000 |
25 system user NULL Sleep 117 Waiting for certification NULL 0.000 |
32 system user my_database Sleep 117 Delete_rows_log_event::find_row(1086687) on table `my_table` DELETE FROM `my_table` WHERE `id` = ? 0.000 |
|
Just to clarify it is truly stuck, an hour and a bit later it's still doing it with no change
[...] Sleep 4584 Delete_rows_log_event::find_row(1086687) |
logs indicate the transaction(s?) are waiting on a lock:
[162B blob data]
|
------- TRX HAS BEEN WAITING 50000151 us FOR THIS LOCK TO BE GRANTED: |
RECORD LOCKS space id 38 page no 3 n bits 320 index PRIMARY of table `my_database`.`my_table` trx id 310274935 lock_mode X locks rec but not gap waiting |
Record lock, heap no 133 PHYSICAL RECORD: n_fields 9; compact format; info bits 0 |
0: len 8; hex 000000000017a9c5; asc ;; |
1: len 6; hex 000000000000; asc ;; |
2: len 7; hex 80000000000000; asc ;; |
3: len 8; hex 000000000017aa49; asc I;; |
4: len 8; hex 0000000000000001; asc ;; |
5: len 30; hex 302f302f3230332f682f7a2f612f342f712f687a61347135673065313230; asc 0/0/203/h/z/a/4/q/hza4q5g0e120; (total 50 bytes); |
6: len 8; hex 0000000000000004; asc ;; |
7: len 4; hex 680031cf; asc h 1 ;; |
8: len 4; hex 680031cf; asc h 1 ;; |
------------------
|
The table in question is:
CREATE TABLE `my_table` (
|
`id` bigint(20) unsigned NOT NULL AUTO_INCREMENT, |
`col_a` bigint(20) unsigned NOT NULL, |
`col_b` bigint(20) unsigned NOT NULL, |
`col_c` varchar(255) NOT NULL, |
`col_d` bigint(20) unsigned NOT NULL, |
`created_at` timestamp NULL DEFAULT NULL,
|
`updated_at` timestamp NULL DEFAULT NULL,
|
PRIMARY KEY (`id`),
|
UNIQUE KEY `my_table_part_id_col_b_unique` (`col_b`,`col_a`),
|
KEY `my_table_col_a_foreign` (`col_a`),
|
KEY `my_table_col_b_index` (`col_b`),
|
CONSTRAINT `my_table_col_a_foreign` FOREIGN KEY (`col_a`) REFERENCES `my_table_2` (`id`) ON UPDATE CASCADE
|
) ENGINE=InnoDB AUTO_INCREMENT=256551792 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci |
SHOW ENGINE INNODB STATUS:
=====================================
|
2025-04-16 22:51:12 0x7fa87bed26c0 INNODB MONITOR OUTPUT |
=====================================
|
Per second averages calculated from the last 46 seconds |
-----------------
|
BACKGROUND THREAD
|
-----------------
|
srv_master_thread loops: 0 srv_active, 0 srv_shutdown, 647 srv_idle |
srv_master_thread log flush and writes: 647 |
----------
|
SEMAPHORES
|
----------
|
------------
|
TRANSACTIONS
|
------------
|
Trx id counter 310274953 |
Purge done for trx's n:o < 310274953 undo n:o < 0 state: running |
History list length 611 |
LIST OF TRANSACTIONS FOR EACH SESSION:
|
---TRANSACTION (0x7fa871216080), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871215580), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871214a80), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871213f80), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871213480), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871212980), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871211e80), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871211380), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871210880), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa87120fd80), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa87120f280), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa87120e780), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa87120dc80), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa87120d180), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa87120c680), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION 310274937, ACTIVE 646 sec |
11 lock struct(s), heap size 1128, 5 row lock(s), undo log entries 8 |
MariaDB thread id 25, OS thread handle 140361867732672, query id 38593 Waiting for certification |
---TRANSACTION 310274940, ACTIVE 646 sec |
2 lock struct(s), heap size 1128, 1 row lock(s), undo log entries 1 |
MariaDB thread id 23, OS thread handle 140361860859584, query id 38592 Waiting for certification |
---TRANSACTION 310274932, ACTIVE 646 sec |
11 lock struct(s), heap size 1128, 5 row lock(s), undo log entries 8 |
MariaDB thread id 21, OS thread handle 140361860552384, query id 38583 Waiting for certification |
---TRANSACTION (0x7fa871209a80), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION 310274902, ACTIVE 646 sec |
9 lock struct(s), heap size 1128, 3 row lock(s), undo log entries 5 |
MariaDB thread id 20, OS thread handle 140361860245184, query id 38490 Waiting for certification |
---TRANSACTION 310274935, ACTIVE 646 sec starting index read |
mysql tables in use 2, locked 2 |
LOCK WAIT 6 lock struct(s), heap size 1128, 14 row lock(s), undo log entries 3 |
MariaDB thread id 32, OS thread handle 140361856050880, query id 38573 Delete_rows_log_event::find_row(1086687) on table `my_table` |
DELETE FROM `my_table` WHERE `id` = ?
|
------- TRX HAS BEEN WAITING 46156325 us FOR THIS LOCK TO BE GRANTED: |
RECORD LOCKS space id 38 page no 3 n bits 216 index PRIMARY of table `my_database`.`my_table` trx id 310274935 lock_mode X locks rec but not gap waiting |
Record lock, heap no 133 PHYSICAL RECORD: n_fields 9; compact format; info bits 0 |
0: len 8; hex 000000000017a9c5; asc ;; |
1: len 6; hex 000000000000; asc ;; |
2: len 7; hex 80000000000000; asc ;; |
3: len 8; hex 000000000017aa49; asc I;; |
4: len 8; hex 0000000000000001; asc ;; |
5: len 30; hex 302f302f3230332f682f7a2f612f342f712f687a61347135673065313230; asc 0/0/203/h/z/a/4/q/hza4q5g0e120; (total 50 bytes); |
6: len 8; hex 0000000000000004; asc ;; |
7: len 4; hex 680031cf; asc h 1 ;; |
8: len 4; hex 680031cf; asc h 1 ;; |
|
|
------------------
|
---TRANSACTION (0x7fa871207980), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871206e80), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871206380), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871205880), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871204d80), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871204280), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871203780), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871202c80), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871202180), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION (0x7fa871201680), not started |
0 lock struct(s), heap size 1128, 0 row lock(s) |
---TRANSACTION 310274922, ACTIVE 646 sec |
11 lock struct(s), heap size 1128, 5 row lock(s), undo log entries 5 |
MariaDB thread id 7, OS thread handle 140361885804224, query id 38543 Waiting for certification |
--------
|
FILE I/O
|
--------
|
Pending flushes (fsync): 0 |
729 OS file reads, 0 OS file writes, 7 OS fsyncs |
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s |
---
|
LOG
|
---
|
Log sequence number 19867188721 |
Log flushed up to 19867188721 |
Pages flushed up to 19859901792 |
Last checkpoint at 19859901792 |
----------------------
|
BUFFER POOL AND MEMORY
|
----------------------
|
Total large memory allocated 1107296256 |
Dictionary memory allocated 6710328 |
Buffer pool size 64896 |
Free buffers 63744 |
Database pages 1152 |
Old database pages 413 |
Modified db pages 572 |
Percent of dirty pages(LRU & free pages): 0.881 |
Max dirty pages percent: 90.000 |
Pending reads 0 |
Pending writes: LRU 0, flush list 0 |
Pages made young 6, not young 0 |
0.00 youngs/s, 0.00 non-youngs/s |
Pages read 662, created 490, written 0 |
0.00 reads/s, 0.00 creates/s, 0.00 writes/s |
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000 |
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s |
LRU len: 1152, unzip_LRU len: 0 |
I/O sum[0]:cur[0], unzip sum[0]:cur[0] |
--------------
|
ROW OPERATIONS
|
--------------
|
0 read views open inside InnoDB |
state: sleeping
|
----------------------------
|
END OF INNODB MONITOR OUTPUT
|
============================
|
We've mainly experience this on Debian Bookworm which currently corresponds to: "mariadbd Ver 10.11.11-MariaDB-0+deb12u1 for debian-linux-gnu on x86_64 (Debian 12)"
As a quick test (to see if it was already solved), we also switched one of the nodes to the upcoming Debian Trixie which ships with "mariadbd Ver 11.8.1-MariaDB-2 for debian-linux-gnu on x86_64 (Debian n/a)"
Our config is currently:
50-server.cnf:
[mysqld]
|
user = mysql
|
pid-file = /run/mysqld/mysqld.pid
|
basedir = /usr
|
datadir = /var/lib/mysql
|
tmpdir = /tmp
|
lc-messages-dir = /usr/share/mysql
|
lc-messages = en_US
|
skip-external-locking
|
default_time_zone='+00:00' |
skip-name-resolve
|
performance_schema=ON
|
max_connections = 1000 |
join_buffer_size = 1M
|
thread_cache_size = 1024 |
slow_query_log_file = /var/log/mariadb-slow.log
|
long_query_time = 2 |
log-queries-not-using-indexes
|
innodb_print_all_deadlocks = ON
|
expire_logs_days = 10 |
character-set-server = utf8mb4
|
collation-server = utf8mb4_general_ci
|
innodb_buffer_pool_size = 1G
|
innodb_log_file_size = 256M
|
|
60-galera.cnf:
[mysqld]
|
wsrep_provider=/usr/lib/libgalera_smm.so
|
wsrep_cluster_name = "<redacted cluster name>" |
wsrep_node_name="<redacted node name>" |
wsrep_node_address = "<redacted node ip>" |
wsrep_cluster_address="gcomm://<redacted node1 ip>,<redacted node2 ip>,<redacted node3 ip>" |
|
|
binlog_format=ROW
|
wsrep_on=ON
|
wsrep_sst_method = mariabackup
|
wsrep_sst_auth = <redacted mariabackup user>:<redacted mariabackup password>
|
innodb_flush_log_at_trx_commit=0 |
innodb_autoinc_lock_mode=2 |
# NOTE: also see the issue with wsrep_slave_threads=4 |
# weren't able to reproduce with wsrep_slave_threads=1, but that would limit us to single threaded performance for all writes, correct? |
wsrep_slave_threads=32 |
Let me know if there is any additional information I can provide (I'm not sure of the exact transactions that cause this - if there's a way to get those, I can likely provide them) or any other configuration options to try/I might be missing.
Thanks!
Edit: We've had this happen without a restart of a node now, over night the cluster completely locked up with two nodes stuck on the above bug now.