Details
-
Bug
-
Status: Open (View Workflow)
-
Major
-
Resolution: Unresolved
-
11.4.3, 11.8.6, 12.3.2
-
None
-
None
-
MariaDB 12.3.2, Galera wsrep provider 4.25 (r5d07ad0), rsync SST method
-
Can result in hang or crash
Description
Description
On a Galera cluster node acting as an rsync SST donor, every SHOW STATUS, SHOW GLOBAL STATUS and every SELECT ... FROM information_schema.GLOBAL_STATUS blocks for the entire duration of the SST (which can be hours for large datasets).
The blocked threads sit in the stage Filling schema table and cannot be killed
(KILL QUERY / KILL CONNECTION take effect only when the SST ends).
This is a regression in effect: it only appears once the global variable max_binlog_total_size (introduced in 11.4) is set to a non-zero value. With max_binlog_total_size = 0 (the default) the same SST runs without any hang.
The condition is independent of binlog size or purging — it reproduces with only a few MB of binary logs and a multi-GB limit. It is purely a mutex contention, not a data-volume problem.
Root cause (two interacting sides):
(A) HOLDER — the SST donor thread holds the binlog mutex LOG::LOCK_log over the whole transfer, by design, to keep RESET MASTER / RESET LOGS from running during the file snapshot. This is long-standing, intentional behaviour and harmless on its own.
(B) VICTIM — when max_binlog_total_size != 0, the status variable Binlog_disk_use is materialised on every SHOW [GLOBAL] STATUS via get_binlog_space_total(), which acquires the very same LOCK_log to read the current write position.
(B) therefore blocks behind (A) for the full SST window.
This is destructive in production because monitoring agents (e.g. MaxScale galeramon, mysqld_exporter / Prometheus) poll SHOW [GLOBAL] STATUS every few seconds. Each poll opens a connection that hangs until the SST ends; the hung connections accumulate up to max_connections, after which the node cannot rejoin the cluster once the transfer completes. At SST end all of them are released at once, producing a burst of "Aborted connection ... (Got an error reading communication packets)".
How to reproduce
Minimal, no monitoring stack required. Two-node Galera cluster with wsrep_sst_method = rsync and a binary log enabled on the donor.
1. On the donor, enable binlog and set a non-zero total-size limit:
-- my.cnf: log_bin=ON, wsrep_sst_method=rsync
|
SET GLOBAL max_binlog_total_size = 1073741824; -- 1 GiB; any non-zero value |
2. Trigger an rsync SST from this donor to a joiner. Easiest way to get a long, observable window: join an empty node, OR pause the rsync to widen the window. (For a deterministic pause point, a debug build can stop at the donor-state DBUG_SYNC; on a release build, simply SST a large enough dataset that the transfer lasts long enough to query.)
3. While the SST is in progress, from a separate connection on the donor:
SHOW GLOBAL STATUS; -- hangs until the SST finishes |
SHOW STATUS LIKE 'Binlog_disk_use'; -- hangs as well |
SELECT 1; -- returns immediately (does not take LOCK_log) |
4. Confirm where it is blocked (no debugger needed):
SELECT t.PROCESSLIST_ID, esc.EVENT_NAME AS stage, ewc.EVENT_NAME AS waiting_on |
FROM performance_schema.threads t |
JOIN performance_schema.events_stages_current esc USING (THREAD_ID) |
JOIN performance_schema.events_waits_current ewc USING (THREAD_ID) |
WHERE esc.EVENT_NAME = 'stage/sql/Filling schema table'; |
-- waiting_on => wait/synch/mutex/sql/LOG::LOCK_log
|
|
|
-- Who holds it?
|
SELECT NAME, LOCKED_BY_THREAD_ID |
FROM performance_schema.mutex_instances |
WHERE NAME = 'wait/synch/mutex/sql/LOG::LOCK_log' |
AND LOCKED_BY_THREAD_ID IS NOT NULL; |
-- => the SST donor thread |
5. Negative control — proves the trigger:
SET GLOBAL max_binlog_total_size = 0; -- back to default |
Repeat the SST: SHOW GLOBAL STATUS now returns immediately throughout
the whole transfer. Toggle is fully reproducible.
Suspected source (verified against the mariadb-12.3.2 source tree)
We are confident about the exact code locations; line numbers below are from tag mariadb-12.3.2.
HOLDER — donor holds LOCK_log across the transfer:
// sql/wsrep_sst.cc — sst_donor_thread(), after sst_flush_tables() succeeds:
|
2156: locked= true; |
2157: /* |
2158: Lets also keep statements that modify binary logs (like RESET LOGS,
|
2159: RESET MASTER) from proceeding until the files have been transferred
|
2160: to the joiner node.
|
2161: */
|
2162: if (mysql_bin_log.is_open()) |
2163: mysql_mutex_lock(mysql_bin_log.get_log_lock()); // acquire &LOCK_log |
2165: WSREP_INFO("Donor state reached"); |
2179: goto wait_signal; // wait for rsync transfer |
... // released only on the "continue" signal == SST end: |
2188: if (mysql_bin_log.is_open()) |
2189: mysql_mutex_unlock(mysql_bin_log.get_log_lock());
|
get_log_lock() returns &LOCK_log (sql/log.h:346).
VICTIM — Binlog_disk_use takes the same LOCK_log, but only when the limit is set:
// sql/mysqld.cc:7926 — status variable, always materialised (SHOW_SIMPLE_FUNC):
|
{"Binlog_disk_use", (char*) &show_binlog_space_total, SHOW_SIMPLE_FUNC}, |
|
|
// sql/mysqld.cc:7811 — show_binlog_space_total():
|
7817: if (opt_bin_log && binlog_space_limit) // limit != 0 |
7818: *(ulonglong*) buff= mysql_bin_log.get_binlog_space_total();
|
7819: else |
7820: *(ulonglong*) buff= 0; // no lock taken |
binlog_space_limit is exactly max_binlog_total_size
(sql/sys_vars.cc:1350 -> internal_binlog_space_limit, copied to
binlog_space_limit at sql/mysqld.cc:5876).
// sql/log.cc:6733 — get_binlog_space_total():
|
6736: mysql_mutex_lock(&LOCK_log); // <-- blocks behind the SST donor |
6738: used_space= my_b_tell(&log_file); // just reads the current write pos |
6739: mysql_mutex_lock(&LOCK_index);
|
6740: mysql_mutex_unlock(&LOCK_log);
|
The SHOW STATUS worker therefore is the victim, not the cause: it waits on a plain mutex held by another thread (the donor), and a plain mutex wait has no thd->killed checkpoint — which is exactly why the connections are not killable until the SST releases LOCK_log.
What it is NOT (each ruled out by source and/or performance_schema):
- Not the Galera provider — wsrep->stats_get() takes only transient locks.
- Not InnoDB — InnoDB is idle during the wait; a plain SELECT runs fine.
- Not binlog size / purging — reproduces far below the limit.
Suggested fix
Cleanest fix is on the victim side — Binlog_disk_use should not block
SHOW STATUS behind LOCK_log just to read the current write position:
- take LOCK_log only via try-lock and otherwise return the last known value (a monitoring counter does not need to be exact), or
- read the current write position from an atomic binlog_end_pos instead of under LOCK_log, or
- compute Binlog_disk_use from the tracked binlog_space_total under LOCK_index only.
Optionally, add a thd->killed checkpoint so such waits become killable
(cf. MDEV-12344 class of issues).
Workaround
Set max_binlog_total_size = 0 on every node that can become an rsync SST donor. Verified to remove the hang completely.
Trade-off: the total-binlog-size cap is gone — compensate with binlog_expire_logs_seconds and adequate disk.
Related issues
MDEV-11312— Galera node hangs on SHOW GLOBAL STATUS (donor pile-up,
"Too many connections"): same symptom family.MDEV-12344— crash when killing a hung SHOW STATUS: same
non-killability / mutex-wait class.
Attachments
Issue Links
- relates to
-
MDEV-11312 One Galera node hangs on "show global status"
-
- Closed
-
-
MDEV-12344 Crash after kill of first hanged SHOW STATUS query
-
- Closed
-