Backup fails when undo truncation log is present

Forgot to mention versions:

MySQL: mysql Ver 8.0.32-24 for Linux on x86_64 (Percona Server (GPL), Release 24, Revision e5c6e9d2)

Xtrabackup: xtrabackup version 8.0.35-30 based on MySQL server 8.0.35 Linux (x86_64) (revision id: 6beb4b49)

Thank you for the report here.

We are seeing the same or similar problems with our backups. Please check below error message.

This has solved for some servers with increasing innodb_max_undo_log_size. But this resolution is inconsistent. We have given innodb_max_undo_log_size size up to 10G (innodb_undo_tablespaces=2) but backup failure happens. Failure is not consistent. Failed backup retry works without any special handling sometimes.

I think that we need to re open this as I’m seeing this same behavior on xtrabackup version 8.0.35-31.

In the error log I found this entry:

And during next backup

I used --lock-ddl-per-table and --lock-ddl, but in both cases it was not ignoring the *_trunc.log files .

Problem:
Backup fails if there is left over undo truncation(_truc.log) file
present in server data/undo directory.

Analysis:
Due to some bugs in MySQL truncation process does not complete,
leaving MySQL instance alive, but with undo truncation logs present.
PXB during backup tries to fix that by invoking srv_undo_tablespace_fixup_num
on server data/undo directory.

Fix:
PXB should not create undo file on server at any circumstances.
Avoid creating any undo file on server during backup.
PXB backup fails if undo truncation happens during backup

Thank you Dmitry Smal for your contribution for initial patch.

I don't have any real workload example at the moment.

But on synthetic tests log looks like.
%%
2022-06-02T19:17:41.165987+03:00 6 [Note] [MY-010559] [Repl] Multi-threaded slave statistics for channel '': seconds elapsed = 120; events assigned = 1057793; worker queues filled over overrun level = 0; waited due a Worker queue full = 0; waited due the total size = 0; waited at clock conflicts = 1060574600 waited (count) when Workers occupied = 16473 waited when Workers occupied = 36708176000
2022-06-02T19:18:47.215585+03:00 0 [Note] [MY-012994] [InnoDB] Truncating UNDO tablespace innodb_undo_001
2022-06-02T19:18:52.637678+03:00 0 [Note] [MY-012994] [InnoDB] Truncating UNDO tablespace innodb_undo_002
2022-06-02T19:19:41.304997+03:00 6 [Note] [MY-010559] [Repl] Multi-threaded slave statistics for channel '': seconds elapsed = 120; events assigned = 1337345; worker queues filled over overrun level = 0; waited due a Worker queue full = 0; waited due the total size = 0; waited at clock conflicts = 1118852000 waited (count) when Workers occupied = 20875 waited when Workers occupied = 47806174800
2022-06-02T19:20:57.049286+03:00 0 [Note] [MY-012994] [InnoDB] Truncating UNDO tablespace innodb_undo_002
2022-06-02T19:21:01.707895+03:00 0 [Note] [MY-012994] [InnoDB] Truncating UNDO tablespace innodb_undo_001
%%