Aria crash recovery failures (MDEV-19813)

[MDEV-18310] Aria engine: Undo phase failed with "Got error 121 when executing undo undo_key_delete" upon startup on datadir restored from incremental backup Created: 2019-01-19  Updated: 2023-11-22  Resolved: 2019-12-02

Status: Closed
Project: MariaDB Server
Component/s: mariabackup, Storage Engine - Aria
Affects Version/s: 10.4
Fix Version/s: 10.2.30, 10.3.21, 10.4.11

Type: Technical task Priority: Major
Reporter: Elena Stepanova Assignee: Vladislav Lesin
Resolution: Fixed Votes: 0
Labels: None

Attachments: File mbackup_backup_0.log     File mbackup_backup_1.log     File mbackup_backup_2.log     File mbackup_prepare_0.log     File mbackup_prepare_1.log     File mbackup_prepare_2.log     File mbackup_restore.log     File mysql.err     File mysql.err_orig     File trial.log    
Issue Links:
Duplicate
is duplicated by MDEV-18203 Aria engine: Undo phase failed with "... Closed
Relates
relates to MDEV-20578 Got error 126 when executing undo und... Closed

 Description   

Note: see also MDEV-18203 – different error, otherwise the same.

10.4 4edb29380c980

 
2019-01-18 21:26:44 0 [Note] mysqld: Aria engine: starting recovery
 
recovered pages: 0% 10% 20% 30% 40% 50% 60% 70% 80% 90% 100% (20.8 seconds); transactions to roll back: 1
 
Got error 121 when executing undo undo_key_delete
 
2019-01-18 21:27:05 0 [ERROR] mysqld: Aria engine: Undo phase failed
 
tables to flush: 8 7 6 5 4 3 2 1 0
 
2019-01-18 21:27:05 0 [ERROR] mysqld: Aria recovery failed. Please run aria_chk -r on all Aria tables and delete all aria_log.######## files
 
2019-01-18 21:27:05 0 [ERROR] Plugin 'Aria' init function returned error.
 
2019-01-18 21:27:05 0 [ERROR] Plugin 'Aria' registration as a STORAGE ENGINE failed.

The backup dirs are here:
ftp://ftp.askmonty.org/public/mdev18310

backup_before_prepare_0 is the initial full backup
backup_before_prepare_1 is the 1st incremental backup
backup_before_prepare_2 is the 1st incremental backup
backup_0 is the prepared backup after all prepare were executed on it.

To reproduce the failure, restore backup_0 to the datadir and run the server on it. All server default options are sufficient.

If you have doubts about the correctness of prepare, you can run it on non-prepared backups.

mariabackup logs from all stages are attached with hopefully self-explanatory names (mbackup*.log).

I have no information yet whether it affects previous versions.

Notes on the origin of the report

Please be aware it's not necessarily reproducible the same way.

https://travis-ci.org/elenst/travis-tests/jobs/481392097
# 2528 22 2
Server: 10.4 4edb29380c98058a28e49c826bacee9c83473579
Tests: elenst-dev 19e81706fbfffc28d2f71d2c22b361ecd4593d9a
Toolbox: c949673e7706f81f5369ecd91b587b09674ece2b

perl ./runall-new.pl --basedir=/home/travis/server --vardir=/home/travis/logs/vardir --duration=350 --threads=4 --seed=1547846609 --reporters=Backtrace,ErrorLog,Deadlock --skip-gendata --gendata-advanced --views --grammar=conf/mariadb/generic-dml.yy --redefine=conf/mariadb/bulk_insert.yy --mysqld=--log_output=FILE --mysqld=--max-statement-time=20 --mysqld=--lock-wait-timeout=10 --mysqld=--loose-innodb-lock-wait-timeout=5 --mysqld=--loose-debug_assert_on_not_freed_memory=0 --filter=/home/travis/mariadb-toolbox/travis/10.4-combo-filter.ff --engine=Aria --scenario=MariaBackupIncremental


The test log is attached as trial.log

 Comments   
Comment by Michael Widenius [ 2019-10-18 ]

I checked the file backup_0.tar.gz

The reason Aria recover fails is that there are not all Aria redo files in the backup.

The only files that exists is:
aria_log.00000001 of size 83009536
This is in LSN: 1,0x4f2a000 in the aria_recovery.trace file

The undo fails when trying to revert test/t5.

shell> /my/maria-10.4/storage/maria/aria_chk -dvv test/t5.MAI
Aria file: test/t5.MAI
Record format: Block
Crashsafe: yes
Character set: latin1_swedish_ci (8)
File-version: 3
Creation time: 2019-01-18 23:23:34
Check/recover time: 2019-01-18 23:23:34
LSNs: create_rename (1,0x11b21), state_horizon (1,0x9d669e8), skip_redo (1,0x11b8b)

As can be seen in LSN, the last update to the file was for LSN 1,0x9d669e8, which is bigger than what the aria_log could support.

Vlad, can you please verify that mariabackup copies ALL aria_log files!
I will in the mean time add a warning in recovery if we find a LSN on any page that is bigger than the maximum LSN that recovery can restore.

Comment by Vladislav Lesin [ 2019-11-19 ]

The problem is that aria_log* files are not copied on --prepare --incremental step from incremental to destination backup directory. See ibx_copy_incremental_over_full().

Generated at Thu Feb 08 08:43:07 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.