[MDEV-14545] Backup fails due to MLOG_INDEX_LOAD record Created: 2017-11-30  Updated: 2020-08-25  Resolved: 2018-03-13

Status: Closed
Project: MariaDB Server
Component/s: Backup
Affects Version/s: 10.2, 10.3
Fix Version/s: 10.2.14, 10.3.6

Type: Bug Priority: Critical
Reporter: Andrii Nikitin (Inactive) Assignee: Thirunarayanan Balathandayuthapani
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Blocks
blocks MDEV-14425 Change the InnoDB redo log format to ... Closed
Duplicate
is duplicated by MDEV-15625 Mariabackup cannot prepare backup Closed
is duplicated by MDEV-19322 mariabackup gets an InnoDB assertion ... Closed
Problem/Incident
causes MDEV-15682 mariabackup.unsupported_redo fails in... Closed
causes MDEV-15737 assertion in mariabackup.exe!recv_cal... Closed
Relates
relates to MDEV-13563 lock DDL for mariabackup in 10.2+ Closed
relates to MDEV-13564 TRUNCATE TABLE and undo tablespace tr... Closed
relates to MDEV-16809 Allow full redo logging for ALTER TABLE Closed
relates to MDEV-14420 [Draft] Assertion failure in file /d... Closed
Sprint: 5.5.59, 10.1.31, 10.2.13, 10.2.14

 Description   

This is probably duplicate of MDEV-14420, just creating backup - related case anyway.
The assert is shown when table is altered immediately after creation:

2017-11-30 13:54:26 140458257676096 [Note] InnoDB: Ignoring data file 'test/t.ibd' with space ID 5, since the redo log references test/t.ibd with space ID 4.
 
2017-11-30 13:54:26 0x7fbefc8df740  InnoDB: Assertion failure in file /home/a/env1/m8-10.2/src/storage/innobase/log/log0recv.cc line 2382
 
InnoDB: Failing assertion: type != MLOG_INDEX_LOAD || srv_operation == SRV_OPERATION_NORMAL
 
...
 
/lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7f5909b6a37a]
 
mysys/stacktrace.c:268(my_print_stacktrace)[0x5628f4935d7c]
 
log/log0recv.cc:2381(recv_parse_log_recs)[0x5628f4de489d]
 
log/log0recv.cc:2910(recv_group_scan_log_recs(log_group_t*, unsigned long, unsigned long*, bool))[0x5628f4de4c45]
 
log/log0recv.cc:3202(recv_recovery_from_checkpoint_start(unsigned long))[0x5628f4de6768]
 
srv/srv0start.cc:2243(innobase_start_or_create_for_mysql())[0x5628f4e80889]
 
mariabackup/xtrabackup.cc:1654(innodb_init)[0x5628f4953485]
 
mariabackup/xtrabackup.cc:5293(main)[0x5628f4937731]

With following test in mariabackup suite (consider similar test for crash recovery):

#--source include/innodb_page_size.inc
 
 
 
 
 
call mtr.add_suppression("InnoDB: New log files created");
 
 
 
let $basedir=$MYSQLTEST_VARDIR/tmp/backup;
 
let $incremental_dir=$MYSQLTEST_VARDIR/tmp/backup_inc1;
 
 
 
CREATE TABLE t(i INT PRIMARY KEY auto_increment, a int) ENGINE INNODB;
 
alter table t ENGINE=INNODB;
 
 
 
INSERT INTO t(a) select 1 union select 2 union select 3;
 
 
 
echo # Create full backup , modify table, then create incremental/differential backup;
 
--disable_result_log
 
exec $XTRABACKUP --defaults-file=$MYSQLTEST_VARDIR/my.cnf  --backup --target-dir=$basedir;
 
--enable_result_log
 
 
 
# --source include/restart_mysqld.inc
 
 
 
exec $XTRABACKUP --defaults-file=$MYSQLTEST_VARDIR/my.cnf  --backup --target-dir=$incremental_dir --incremental-basedir=$basedir;
 
 
 
--disable_result_log
 
echo # Prepare full backup, apply incremental one;
 
exec $XTRABACKUP --prepare --apply-log-only --target-dir=$basedir;
 
exec $XTRABACKUP --prepare --target-dir=$basedir --incremental-dir=$incremental_dir ;
 
 
 
let $targetdir=$basedir;
 
-- source include/restart_and_restore.inc
 
--enable_result_log
 
 
 
DROP TABLE t;
 
 
 
# Cleanup
 
rmdir $basedir;
 
rmdir $incremental_dir;

Full output

# ./mtr xa
 
Logging: /home/a/env1/m8-10.2/src/mysql-test/mysql-test-run.pl  xa
 
vardir: /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var
 
Checking leftover processes...
 
Removing old var directory...
 
Creating var directory '/home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var'...
 
Checking supported features...
 
MariaDB Version 10.2.12-MariaDB
 
 - SSL connections supported
 
Collecting tests...
 
Installing system database...
 
 
 
==============================================================================
 
 
 
TEST                                      RESULT   TIME (ms) or COMMENT
 
--------------------------------------------------------------------------
 
 
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
 
main.xa 'innodb'                         [ pass ]   3670
 
call mtr.add_suppression("InnoDB: New log files created");
 
CREATE TABLE t(i INT PRIMARY KEY auto_increment, a int) ENGINE INNODB;
 
alter table t ENGINE=INNODB;
 
INSERT INTO t(a) select 1 union select 2 union select 3;
 
# Create full backup , modify table, then create incremental/differential backup
 
# Prepare full backup, apply incremental one
 
mariabackup.xa                           [ fail ]
 
        Test ended at 2017-11-30 13:55:05
 
 
 
CURRENT_TEST: mariabackup.xa
 
171130 13:55:01 Connecting to MySQL server host: localhost, user: root, password: set, port: 16000, socket: /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/mysqld.1.sock
 
Using server version 10.2.12-MariaDB-log
 
/home/a/env1/m8-10.2/bld/extra/mariabackup/mariabackup based on MariaDB server 10.2.12-MariaDB Linux (x86_64) 
incremental backup from 1645025 is enabled.
 
mariabackup: uses posix_fadvise().
 
mariabackup: cd to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/mysqld.1/data/
 
mariabackup: open files limit requested 1024, set to 1024
 
mariabackup: using the following InnoDB configuration:
 
mariabackup:   innodb_data_home_dir = .
 
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
 
mariabackup:   innodb_log_group_home_dir = ./
 
2017-11-30 13:55:01 140553722062656 [Note] InnoDB: Number of pools: 1
 
171130 13:55:01 >> log scanned up to (1645034)
 
mariabackup: Generating a list of tablespaces
 
2017-11-30 13:55:01 140553722062656 [Warning] InnoDB: Allocated tablespace ID 1 for mysql/innodb_table_stats, old maximum was 0
 
mariabackup: using the full scan for incremental backup
 
171130 13:55:01 [01] Copying ./ibdata1 to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/ibdata1.delta
 
171130 13:55:01 [01]        ...done
 
171130 13:55:01 [01] Copying ./mysql/innodb_table_stats.ibd to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/innodb_table_stats.ibd.delta
 
171130 13:55:01 [01]        ...done
 
171130 13:55:01 [01] Copying ./mysql/innodb_index_stats.ibd to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/innodb_index_stats.ibd.delta
 
171130 13:55:01 [01]        ...done
 
171130 13:55:01 [01] Copying ./test/t.ibd to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/test/t.ibd.delta
 
171130 13:55:01 [01]        ...done
 
171130 13:55:02 >> log scanned up to (1645069)
 
171130 13:55:02 Executing FLUSH NO_WRITE_TO_BINLOG TABLES...
 
171130 13:55:02 Executing FLUSH TABLES WITH READ LOCK...
 
171130 13:55:02 Starting to backup non-InnoDB tables and files
 
171130 13:55:02 [01] Copying ./mysql/db.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/db.frm
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/db.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/db.MYI
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/db.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/db.MYD
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/host.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/host.frm
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/host.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/host.MYI
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/host.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/host.MYD
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/user.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/user.frm
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/user.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/user.MYI
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/user.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/user.MYD
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/roles_mapping.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/roles_mapping.frm
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/roles_mapping.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/roles_mapping.MYI
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/roles_mapping.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/roles_mapping.MYD
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/func.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/func.frm
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/func.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/func.MYI
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/func.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/func.MYD
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/plugin.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/plugin.frm
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/plugin.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/plugin.MYI
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/plugin.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/plugin.MYD
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/servers.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/servers.frm
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/servers.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/servers.MYI
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/servers.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/servers.MYD
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/tables_priv.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/tables_priv.frm
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/tables_priv.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/tables_priv.MYI
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/tables_priv.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/tables_priv.MYD
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/columns_priv.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/columns_priv.frm
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/columns_priv.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/columns_priv.MYI
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/columns_priv.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/columns_priv.MYD
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/help_topic.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_topic.frm
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/help_topic.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_topic.MYI
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/help_topic.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_topic.MYD
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/help_category.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_category.frm
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/help_category.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_category.MYI
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/help_category.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_category.MYD
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/help_relation.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_relation.frm
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/help_relation.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_relation.MYI
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/help_relation.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_relation.MYD
 
171130 13:55:02 [01]        ...done
 
171130 13:55:02 [01] Copying ./mysql/help_keyword.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_keyword.frm
 
171130 13:55:02 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/help_keyword.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_keyword.MYI
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/help_keyword.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_keyword.MYD
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/time_zone_name.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_name.frm
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/time_zone_name.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_name.MYI
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/time_zone_name.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_name.MYD
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/time_zone.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone.frm
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/time_zone.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone.MYI
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/time_zone.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone.MYD
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/time_zone_transition.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition.frm
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/time_zone_transition.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition.MYI
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/time_zone_transition.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition.MYD
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/time_zone_transition_type.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition_type.frm
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/time_zone_transition_type.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition_type.MYI
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/time_zone_transition_type.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition_type.MYD
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/time_zone_leap_second.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_leap_second.frm
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/time_zone_leap_second.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_leap_second.MYI
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/time_zone_leap_second.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_leap_second.MYD
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/proc.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/proc.frm
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/proc.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/proc.MYI
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/proc.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/proc.MYD
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/procs_priv.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/procs_priv.frm
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/procs_priv.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/procs_priv.MYI
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/procs_priv.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/procs_priv.MYD
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/general_log.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/general_log.frm
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/general_log.CSM to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/general_log.CSM
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/general_log.CSV to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/general_log.CSV
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/slow_log.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/slow_log.frm
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/slow_log.CSM to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/slow_log.CSM
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/slow_log.CSV to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/slow_log.CSV
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/event.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/event.frm
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/event.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/event.MYI
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/event.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/event.MYD
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/innodb_table_stats.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/innodb_table_stats.frm
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/innodb_index_stats.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/innodb_index_stats.frm
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/proxies_priv.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/proxies_priv.frm
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/proxies_priv.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/proxies_priv.MYI
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/proxies_priv.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/proxies_priv.MYD
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/table_stats.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/table_stats.frm
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/table_stats.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/table_stats.MYI
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/table_stats.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/table_stats.MYD
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/column_stats.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/column_stats.frm
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/column_stats.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/column_stats.MYI
 
171130 13:55:03 [01]        ...done
 
171130 13:55:03 [01] Copying ./mysql/column_stats.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/column_stats.MYD
 
171130 13:55:03 [01]        ...done
 
171130 13:55:04 [01] Copying ./mysql/index_stats.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/index_stats.frm
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mysql/index_stats.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/index_stats.MYI
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mysql/index_stats.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/index_stats.MYD
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mysql/gtid_slave_pos.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/gtid_slave_pos.MYI
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mysql/gtid_slave_pos.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/gtid_slave_pos.MYD
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mysql/gtid_slave_pos.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/gtid_slave_pos.frm
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./test/t.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/test/t.frm
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./performance_schema/db.opt to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/performance_schema/db.opt
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mtr/db.opt to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/db.opt
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mtr/test_suppressions.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/test_suppressions.frm
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mtr/test_suppressions.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/test_suppressions.MYI
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mtr/test_suppressions.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/test_suppressions.MYD
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mtr/ts_insert.TRN to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/ts_insert.TRN
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mtr/test_suppressions.TRG to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/test_suppressions.TRG
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mtr/global_suppressions.frm to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/global_suppressions.frm
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mtr/global_suppressions.MYI to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/global_suppressions.MYI
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mtr/global_suppressions.MYD to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/global_suppressions.MYD
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mtr/gs_insert.TRN to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/gs_insert.TRN
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying ./mtr/global_suppressions.TRG to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/global_suppressions.TRG
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 Finished backing up non-InnoDB tables and files
 
171130 13:55:04 [01] Copying aria_log_control to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/aria_log_control
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 [01] Copying aria_log.00000001 to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/aria_log.00000001
 
171130 13:55:04 [01]        ...done
 
171130 13:55:04 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS...
 
mariabackup: The latest check point (for incremental): '1645069'
 
mariabackup: Stopping log copying thread.
 
 
 
171130 13:55:04 >> log scanned up to (1645078)
 
171130 13:55:04 Executing UNLOCK TABLES
 
171130 13:55:04 All tables unlocked
 
171130 13:55:04 [00] Copying ib_buffer_pool to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/ib_buffer_pool
 
171130 13:55:04 [00]        ...done
 
171130 13:55:04 Backup created in directory '/home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup_inc1/'
 
171130 13:55:04 [00] Writing backup-my.cnf
 
171130 13:55:04 [00]        ...done
 
171130 13:55:04 [00] Writing xtrabackup_info
 
171130 13:55:04 [00]        ...done
 
mariabackup: Redo log (from LSN 1645034 to 1645078) was copied.
 
171130 13:55:04 completed OK!
 
sh: line 1:  4883 Aborted                 (core dumped) /home/a/env1/m8-10.2/bld/extra/mariabackup/mariabackup --prepare --apply-log-only --target-dir=/home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup 2>&1
 
mysqltest: At line 25: exec of '/home/a/env1/m8-10.2/bld/extra/mariabackup/mariabackup --prepare --apply-log-only --target-dir=/home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup 2>&1' failed, error: 34304, status: 134, errno: 11
 
Output from before failure:
 
/home/a/env1/m8-10.2/bld/extra/mariabackup/mariabackup based on MariaDB server 10.2.12-MariaDB Linux (x86_64) 
mariabackup: cd to /home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/tmp/backup/
 
mariabackup: This target seems to be not prepared yet.
 
mariabackup: using the following InnoDB configuration for recovery:
 
mariabackup:   innodb_data_home_dir = .
 
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
 
mariabackup:   innodb_log_group_home_dir = .
 
mariabackup: Starting InnoDB instance for recovery.
 
mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
 
2017-11-30 13:55:04 140020424640320 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2017-11-30 13:55:04 140020424640320 [Note] InnoDB: Uses event mutexes
 
2017-11-30 13:55:04 140020424640320 [Note] InnoDB: Compressed tables use zlib 1.2.11
 
2017-11-30 13:55:04 140020424640320 [Note] InnoDB: Number of pools: 1
 
2017-11-30 13:55:04 140020424640320 [Note] InnoDB: Using SSE2 crc32 instructions
 
2017-11-30 13:55:04 140020424640320 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
 
2017-11-30 13:55:04 140020424640320 [Note] InnoDB: Completed initialization of buffer pool
 
2017-11-30 13:55:04 140020119742208 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2017-11-30 13:55:04 140020424640320 [Note] InnoDB: Highest supported file format is Barracuda.
 
2017-11-30 13:55:04 140020424640320 [Note] InnoDB: Starting crash recovery from checkpoint LSN=1633766
 
2017-11-30 13:55:04 140020424640320 [Note] InnoDB: Ignoring data file 'test/t.ibd' with space ID 5, since the redo log references test/t.ibd with space ID 4.
 
2017-11-30 13:55:04 0x7f590bac0740  InnoDB: Assertion failure in file /home/a/env1/m8-10.2/src/storage/innobase/log/log0recv.cc line 2382
 
InnoDB: Failing assertion: type != MLOG_INDEX_LOAD || srv_operation == SRV_OPERATION_NORMAL
 
InnoDB: We intentionally generate a memory trap.
 
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
 
InnoDB: If you get repeated assertion failures or crashes, even
 
InnoDB: immediately after the mysqld startup, there may be
 
InnoDB: corruption in the InnoDB tablespace. Please refer to
 
InnoDB: http://dev.mysql.com/doc/refman/5.7/en/forcing-innodb-recovery.html
 
InnoDB: about forcing recovery.
 
171130 13:55:04 [ERROR] mysqld got signal 6 ;
 
This could be because you hit a bug. It is also possible that this binary
 
or one of the libraries it was linked against is corrupt, improperly built,
 
or misconfigured. This error can also be caused by malfunctioning hardware.
 
 
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
 
 
We will try our best to scrape up some info that will hopefully help
 
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
 
 
Server version: 10.2.12-MariaDB
 
key_buffer_size=0
 
read_buffer_size=131072
 
max_used_connections=0
 
max_threads=1
 
thread_count=0
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 5420 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x0
 
Attempting backtrace. You can use the following information to find out
 
where mysqld died. If you see no messages after this, something went
 
terribly wrong...
 
stack_bottom = 0x0 thread_stack 0x49000
 
/home/a/env1/m8-10.2/bld/extra/mariabackup/mariabackup(my_print_stacktrace+0x29)[0x5628f503a079]
 
/home/a/env1/m8-10.2/bld/extra/mariabackup/mariabackup(handle_fatal_signal+0x3bd)[0x5628f4bd4f2d]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x11670)[0x7f590b6ba670]
 
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x9f)[0x7f5909b6877f]
 
/lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7f5909b6a37a]
 
mysys/stacktrace.c:268(my_print_stacktrace)[0x5628f4935d7c]
 
log/log0recv.cc:2381(recv_parse_log_recs)[0x5628f4de489d]
 
log/log0recv.cc:2910(recv_group_scan_log_recs(log_group_t*, unsigned long, unsigned long*, bool))[0x5628f4de4c45]
 
log/log0recv.cc:3202(recv_recovery_from_checkpoint_start(unsigned long))[0x5628f4de6768]
 
srv/srv0start.cc:2243(innobase_start_or_create_for_mysql())[0x5628f4e80889]
 
mariabackup/xtrabackup.cc:1654(innodb_init)[0x5628f4953485]
 
mariabackup/xtrabackup.cc:5293(main)[0x5628f4937731]
 
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf1)[0x7f5909b533f1]
 
/home/a/env1/m8-10.2/bld/extra/mariabackup/mariabackup(_start+0x2a)[0x5628f494c0da]
 
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
 
information that should help you find out what is causing the crash.
 
 
 
 - saving '/home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/log/mariabackup.xa/' to '/home/a/env1/_depot/m-branch/m8-10.2-bld/mysql-test/var/log/mariabackup.xa/'
 
--------------------------------------------------------------------------
 
The servers were restarted 1 times
 
Spent 3.670 of 23 seconds executing testcases
 
 
 
Failure: Failed 1/2 tests, 50.00% were successful.
 
 
 
Failing test(s): mariabackup.xa
 
 
 
The log files in var/log may give you some hint of what went wrong.
 
 
 
If you want to report this error, please read first the documentation
 
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html
 
 
 
mysql-test-run: *** ERROR: there were failing test cases



 Comments   
Comment by Marko Mäkelä [ 2017-11-30 ]

This is a known problem of Mariabackup.

The MLOG_INDEX_LOAD record informs Mariabackup that the backup cannot be completed based on the redo log scan, because some information is purposely omitted due to WL#7277 bulk index creation in ALTER TABLE.

To deal with the problem, MDEV-13563 introduced the --lock-ddl-per-table option. When it is specified, Mariabackup will prevent any DDL operations on InnoDB tables while the backup is running.

Comment by Marko Mäkelä [ 2017-11-30 ]

The informational message has nothing to do with the problem.

2017-11-30 13:54:26 140458257676096 [Note] InnoDB: Ignoring data file 'test/t.ibd' with space ID 5, since the redo log references test/t.ibd with space ID 4.

It merely informs that some file was rebuilt with a different tablespace ID, and the recovery is working as expected.

Comment by Andrii Nikitin (Inactive) [ 2017-11-30 ]

marko The test has ALTER before backup was started, so I doubt that --lock-ddl-per-table will help. Do you still think it is expected behaviour? And that crash recovery is not affected (considering MDEV-14420)

Comment by Marko Mäkelä [ 2017-12-01 ]

anikitin, normal crash recovery will work, because the FlushObserver will guarantee that the non-logged pages are written to the data files before redo logging is enabled. This happens before the ALTER TABLE transaction commits.

Comment by Marko Mäkelä [ 2017-12-01 ]

anikitin, I now realize that the fix in MDEV-13563 is not preventing this scenario.
A better fix would be an InnoDB option that will cause full page images to be written to the redo log when the non-logged pages are being written to data files. In this way, the ARIES protocol would be (almost) followed. For practical purposes, it is followed, because at ALTER TABLE commit time, everything would be consistent, and without commit, the affected pages would be freed and their contents treated as garbage.

If MDEV-14425 allows log archiving, we will have to write complete log instead of writing MLOG_INDEX_LOAD records that inform that the log is incomplete. Otherwise the archived log could be useless for restoring a particular old state of the database. Especially if a table-rebuild operation were logged as MLOG_INDEX_LOAD, the archived redo log would become totally useless for that table.

Comment by Andrii Nikitin (Inactive) [ 2017-12-01 ]

I've checked just in case - it still crashes the same way if backup is performed with --lock-ddl-per-table

Comment by Andrii Nikitin (Inactive) [ 2017-12-01 ]

xtrabackup 2.4.7 , 2.4.8 and 2.4.9 do pass with backup of `CREATE TABLE t1(c1 INT); ALTER TABLE t1 ENGINE=InnoDB; INSERT INTO t1 VALUES(1);` , while mariabackup 10.2 (down to 10.2.9 at least) shows the same assert `type != MLOG_INDEX_LOAD`. https://github.com/AndriiNikitin/mariadb-environs-xtrabackup/blob/master/t/MDEV-14145.sh

Comment by Marko Mäkelä [ 2017-12-01 ]

I checked Percona Xtrabackup 2.4, and it is ignoring the MLOG_INDEX_LOAD record when the --log-ddl-per-table option has been specified.

With --log-ddl-per-table, the only way you should be able to get MLOG_INDEX_LOAD records is when an ALTER TABLE operation started before the logic of --log-ddl-per-table was executed. But, we still have to check if all the changes were flushed to the data files as of the LSN. This is what Percona Xtrabackup 2.4 is doing. Mariabackup 10.2 should do the same, but without calling exit() from deep inside InnoDB code.

MDEV-13563 implemented --lock-ddl-per-table in Mariabackup. This is essentially an omission in that work; we should have implemented special logic to treat MLOG_INDEX_LOAD.

Comment by Marko Mäkelä [ 2018-02-02 ]

Apart from the MLOG_INDEX_LOAD record that informs that ALGORITHM=INPLACE disabled redo logging, there is another MySQL 5.7 change that can ruin a backup.

As reported in MDEV-13564, TRUNCATE TABLE will use some extra logging, and crash recovery will rely on the fact that it does an extra redo log checkpoint to clear the head of the redo log. But, Mariabackup will not observe this checkpoint; it instead assumes that it can copy and apply the whole log since the checkpoint that was the latest when the backup operation started.

As part of this fix (making --backup abort if a MLOG_INDEX_LOAD record is present in the log), I think that we should also try to detect TRUNCATE TABLE in the log, if it is doable. The record to look for is MLOG_FILE_CREATE2. This record would be emitted by fil_ibd_create(), which appears to be called both by CREATE TABLE and TRUNCATE TABLE. Because the mini-transaction consists of this single record, and because other threads could add mini-transactions in between, it could be hard to reliably distinguish TRUNCATE from CREATE TABLE.

Comment by Thirunarayanan Balathandayuthapani [ 2018-03-09 ]

Yes, I added it to current sprint.

Comment by Thirunarayanan Balathandayuthapani [ 2018-03-10 ]

https://github.com/MariaDB/server/commit/70199cf21152f35012d4ae7c8b37d2f13133e474

markoCan you please review ?

Comment by Marko Mäkelä [ 2018-03-12 ]

OK to push after addressing my review comments.
I think that we can report the file name related to the first encountered MLOG_INDEX_LOAD record.

Comment by Marko Mäkelä [ 2018-03-16 ]

The fix is introducing a memory leak to mariabackup, which can be observed in a cmake -DWITH_ASAN=1 build:

./mtr --mem mariabackup.unsupported_redo


Direct leak of 72 byte(s) in 1 object(s) allocated from:
 
    #0 0x7fc903aecc20 in __interceptor_malloc (/lib/x86_64-linux-gnu/libasan.so.4+0xd9c20)
 
    #1 0x5565a8fb8982 in datafiles_iter_new /mariadb/10.2-ext/extra/mariabackup/xtrabackup.cc:380
 
    #2 0x5565a8fb90b3 in backup_includes /mariadb/10.2-ext/extra/mariabackup/xtrabackup.cc:461
 
    #3 0x5565aa23baf1 in recv_parse_log_recs(unsigned long, store_t, bool) /mariadb/10.2-ext/storage/innobase/log/log0recv.cc:2460
 
    #4 0x5565a8fbfa07 in xtrabackup_copy_log /mariadb/10.2-ext/extra/mariabackup/xtrabackup.cc:2422
 
    #5 0x5565a8fc013e in xtrabackup_copy_logfile /mariadb/10.2-ext/extra/mariabackup/xtrabackup.cc:2490
 
    #6 0x5565a8fc68c3 in xtrabackup_backup_func /mariadb/10.2-ext/extra/mariabackup/xtrabackup.cc:3910
 
    #7 0x5565a8fcf5f6 in main_low /mariadb/10.2-ext/extra/mariabackup/xtrabackup.cc:5575
 
    #8 0x5565a8fcea17 in main /mariadb/10.2-ext/extra/mariabackup/xtrabackup.cc:5378
 
    #9 0x7fc9020cca86 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21a86)

With memory leak checks disabled, the test does pass:

ASAN_OPTIONS=detect_leaks=0,abort_on_error=1 ./mtr --mem mariabackup.unsupported_redo

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