Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-14545

Backup fails due to MLOG_INDEX_LOAD record

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Critical
    • Resolution: Fixed
    • Affects Version/s: 10.2, 10.3
    • Fix Version/s: 10.2.14, 10.3.6
    • Component/s: Backup
    • Labels:
      None
    • 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
      

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                thiru Thirunarayanan Balathandayuthapani
                Reporter:
                anikitin Andrii Nikitin (Inactive)
              • Votes:
                0 Vote for this issue
                Watchers:
                6 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: