MDEV-39468 Mariabackup: redo log copier stalls and fails with misleading error message by Thirunarayanan · Pull Request #5375 · MariaDB/server

Thirunarayanan · 2026-07-10T13:22:55Z

Problem:

During backup process, log copier thread stalls at lsn and fails with the misleading "Was only able to copy log from X to Y, not Z; try increasing innodb_log_file_size", even when the redo was intact and the log far from full.

Problem is that copier advances recv_sys.lsn only on CRC-validated mtr, but it parses the redo at the server is concurrently writing. InnoDB rewrites the current partial write block repeatedly as mini-transaction fills it, so an mmap read (or) pread of a page being written can observe a torn/intermediate image of the tail block. If that tail block happens to parse as a longer, still valid crc valid mtr then recv_sys.lsn, recv_sys.offset gets advanced wrongly and points to middle of the mini-transaction. In that case, later parse return GOT_EOF always and copier thread never reaches target and fails

Solution:

Poll the server's durably-flushed LSN (status var Innodb_lsn_flushed) and limit the redo log copier based on it.

backup_log_parse(): parses one mtr and if it exceeds the limit rolls back recv_sys.lsn/offset and reports GOT_EOF; the copier re-parses those bytes on a later pass once the fence has advanced past them. Used on both the mmap and buffered paths.

log_copying_thread(): opens its own connection (it runs concurrently with the main thread, which owns mysql_connection) and refreshes the max_limit for parsing of redo log in each pass.

In the final backup phase (BACKUP STAGE BLOCK_COMMIT) it gates on the exact target max(metadata_last_lsn, metadata_to_lsn). so the last partial block is copied in full up to the target.

The stall diagnostic / retry spin is suppressed on a reached_parse_limit wait so a normal "caught up, wait" is not misreported as drift.

get_log_flushed_lsn(): Added to get log_flushed_lsn from SHOW STATUS outout;

…ing error message Problem: ======== During backup process, log copier thread stalls at lsn and fails with the misleading "Was only able to copy log from X to Y, not Z; try increasing innodb_log_file_size", even when the redo was intact and the log far from full. Problem is that copier advances recv_sys.lsn only on CRC-validated mtr, but it parses the redo at the server is concurrently writing. InnoDB rewrites the current partial write block repeatedly as mini-transaction fills it, so an mmap read (or) pread of a page being written can observe a torn/intermediate image of the tail block. If that tail block happens to parse as a longer, still valid crc valid mtr then recv_sys.lsn, recv_sys.offset gets advanced wrongly and points to middle of the mini-transaction. In that case, later parse return GOT_EOF always and copier thread never reaches target and fails Solution: ========= Poll the server's durably-flushed LSN (status var Innodb_lsn_flushed) and limit the redo log copier based on it. backup_log_parse(): parses one mtr and if it exceeds the limit rolls back recv_sys.lsn/offset and reports GOT_EOF; the copier re-parses those bytes on a later pass once the fence has advanced past them. Used on both the mmap and buffered paths. log_copying_thread(): opens its own connection (it runs concurrently with the main thread, which owns mysql_connection) and refreshes the max_limit for parsing of redo log in each pass. In the final backup phase (BACKUP STAGE BLOCK_COMMIT) it gates on the exact target max(metadata_last_lsn, metadata_to_lsn). so the last partial block is copied in full up to the target. The stall diagnostic / retry spin is suppressed on a reached_parse_limit wait so a normal "caught up, wait" is not misreported as drift. get_log_flushed_lsn(): Added to get log_flushed_lsn from SHOW STATUS outout;

CLAassistant · 2026-07-10T13:23:03Z

Thank you for your submission! We really appreciate it. Like many open source projects, we ask that you sign our Contributor License Agreement before we can accept your contribution.
_{You have signed the CLA already but the status is still pending? Let us recheck it.}

gemini-code-assist

Code Review

This pull request introduces a mechanism in mariabackup to poll InnoDB's durably flushed redo LSN from the running server and use it as a parse limit (max_parse_lsn) for the log copier. This prevents the copier from parsing volatile tail blocks that are still being rewritten, avoiding torn reads and mid-mtr drift. The feedback highlights two important issues in the log copying thread: first, a connection failure (limit_con being NULL) can cause max_parse_lsn to remain stuck and stall the copier, which should be mitigated by falling back to no limit (max_parse_lsn = 0); second, a potential 1-second delay can occur during backup completion if metadata_last_lsn is set to 1 while unlocked, which can be resolved by adding a check before the timed wait.

Important

The consumer version of Gemini Code Assist on GitHub is being sunset. Starting June 18, 2026, new organization installations will be blocked, and all code review activity will officially cease on July 17, 2026.
For more details on the timeline and next steps, please review the Help Documentation.

gemini-code-assist · 2026-07-10T13:25:30Z

+    /* Refresh the max_parse_lsn before each copy pass */
+    const lsn_t final_target= metadata_last_lsn > metadata_to_lsn
+      ? metadata_last_lsn : metadata_to_lsn;
+    if (final_target)
+      max_parse_lsn= final_target;
+    else if (limit_con)
+    {
+      mysql_mutex_unlock(&recv_sys.mutex);
+      lsn_t flushed= get_log_flushed_lsn(limit_con);
+      mysql_mutex_lock(&recv_sys.mutex);
+      if (flushed > log_sys.get_first_lsn())
+        max_parse_lsn= flushed;
+    }


If limit_con fails to connect (for example, due to max_connections exhaustion on the server), limit_con will be NULL. In this case, the else if (limit_con) block is skipped, and max_parse_lsn is never updated during the backup. It remains stuck at the initial flushed LSN, causing the log copier thread to stop copying any new redo log past that point. This will lead to a guaranteed backup failure due to redo log overwrite if the backup takes longer than the log capacity.

To prevent this, if we cannot query the flushed LSN (either because limit_con is NULL or because the query failed/returned 0), we should fall back to max_parse_lsn = 0 (no limit). This restores the pre-existing behavior of copying without a limit, which is a much safer fallback than stalling the copier.

/* Refresh the max_parse_lsn before each copy pass */ const lsn_t final_target= metadata_last_lsn > metadata_to_lsn ? metadata_last_lsn : metadata_to_lsn; if (final_target) max_parse_lsn= final_target; else if (limit_con) { mysql_mutex_unlock(&recv_sys.mutex); lsn_t flushed= get_log_flushed_lsn(limit_con); mysql_mutex_lock(&recv_sys.mutex); if (flushed > log_sys.get_first_lsn()) max_parse_lsn= flushed; else max_parse_lsn= 0; } else { max_parse_lsn= 0; }

gemini-code-assist · 2026-07-10T13:25:30Z

+    if (final_target && final_target <= recv_sys.lsn)
+      break;


If metadata_last_lsn is set to 1 (the stop signal) while the thread is unlocked during get_log_flushed_lsn(), the thread will re-acquire the mutex, run xtrabackup_copy_logfile(false), and then reach the wait condition. Since final_target was evaluated as 0 before the unlock, the check final_target && final_target <= recv_sys.lsn will be false, causing the thread to call mysql_cond_timedwait and sleep for up to xtrabackup_log_copy_interval (default 1 second) before looping and finally breaking.

To avoid this unnecessary 1-second delay during backup completion, we should check if (metadata_last_lsn == 1) break; right before the wait condition.

if (final_target && final_target <= recv_sys.lsn) break; if (metadata_last_lsn == 1) break;

Copilot

Pull request overview

This PR addresses a mariabackup redo-log copier stall/drift issue (MDEV-39468) by fencing redo parsing to the server’s durably flushed LSN (via Innodb_lsn_flushed) and improving the resulting diagnostic messaging when the target LSN cannot be reached.

Changes:

Add a redo-parse fence (max_parse_lsn) and wrapper parsing logic to avoid parsing volatile/torn tail blocks while the server is still rewriting them.
Update log_copying_thread() to refresh the parse limit via a dedicated client connection and suppress misleading “stall” retry logging when the parse fence is reached.
Add get_log_flushed_lsn() helper and update the mariabackup test to expect the new messaging.

Reviewed changes

Copilot reviewed 5 out of 5 changed files in this pull request and generated 4 comments.

Show a summary per file

File	Description
mysql-test/suite/mariabackup/innodb_redo_overwrite.test	Updates log-message assertion for the new “Try increasing…” output.
mysql-test/suite/mariabackup/innodb_redo_overwrite.result	Updates expected test output for the new log-message assertion.
extra/mariabackup/xtrabackup.cc	Implements parse fencing, updates retry/diagnostic behavior, and refreshes fence in the log copy thread.
extra/mariabackup/backup_mysql.h	Exposes `get_log_flushed_lsn()` declaration (adds `<cstdint>` include).
extra/mariabackup/backup_mysql.cc	Implements `get_log_flushed_lsn()` using `SHOW STATUS LIKE 'Innodb_lsn_flushed'`.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

 --enable_result_log

--let SEARCH_PATTERN=Was only able to copy log from \\d+ to \\d+, not \\d+; try increasing innodb_log_file_size\\b
+--let SEARCH_PATTERN=mariabackup: Try increasing the innodb_log_file_size.


 CREATE TABLE t ENGINE=INNODB SELECT seq%10 i FROM seq_0_to_204796;
 # xtrabackup backup
-FOUND 1 /Was only able to copy log from \d+ to \d+, not \d+; try increasing innodb_log_file_size\b/ in backup.log
+FOUND 1 /mariabackup: Try increasing the innodb_log_file_size./ in backup.log


 static void log_copying_thread()
 {
  my_thread_init();
+  MYSQL *limit_con= xb_mysql_connect();
  mysql_mutex_lock(&recv_sys.mutex);


+  if (limit_con)
+    mysql_close(limit_con);
  my_thread_end();
 }


gemini-code-assist Bot reviewed Jul 10, 2026

View reviewed changes

iMineLink requested a review from Copilot July 10, 2026 13:30

Copilot started reviewing on behalf of iMineLink July 10, 2026 13:31 View session

Copilot AI reviewed Jul 10, 2026

View reviewed changes

gkodinov added the MariaDB Corporation label Jul 13, 2026

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Uh oh!

MDEV-39468 Mariabackup: redo log copier stalls and fails with misleading error message#5375

MDEV-39468 Mariabackup: redo log copier stalls and fails with misleading error message#5375
Thirunarayanan wants to merge 1 commit into
10.11from
MDEV-39468

Thirunarayanan commented Jul 10, 2026

Uh oh!

CLAassistant commented Jul 10, 2026

Uh oh!

gemini-code-assist Bot left a comment

Uh oh!

gemini-code-assist Bot Jul 10, 2026

Uh oh!

gemini-code-assist Bot Jul 10, 2026

Uh oh!

Copilot AI left a comment

Uh oh!

Reviewers

Assignees

Labels

Milestone

Development

Uh oh!

4 participants

Uh oh!

Uh oh!

Conversation

Thirunarayanan commented Jul 10, 2026

Problem:

Solution:

Uh oh!

CLAassistant commented Jul 10, 2026

Uh oh!

gemini-code-assist Bot left a comment

Choose a reason for hiding this comment

Code Review

Uh oh!

gemini-code-assist Bot Jul 10, 2026

Choose a reason for hiding this comment

Uh oh!

gemini-code-assist Bot Jul 10, 2026

Choose a reason for hiding this comment

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Reviewed changes

Uh oh!

Reviewers

Assignees

Labels

Milestone

Development

Uh oh!

4 participants