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

InnoDB: Failing assertion: !recv_no_log_write upon --prepare --apply-log-only on the first (full) backup




      10.1 5b827511

      2019-02-16 14:19:31 139676350618560 [Note] InnoDB: Restoring possible half-written data pages from the doublewrite buffer...
      2019-02-16 14:19:32 139676350618560 [Note] InnoDB: Starting a batch to recover 3925 pages from redo log
      2019-02-16 14:19:39 7f08ef431bc0  InnoDB: Assertion failure in thread 139676350618560 in file mtr0mtr.cc line 322
      InnoDB: Failing assertion: !recv_no_log_write
      #4  0x00007f08ed31e3fa in abort () from /lib/x86_64-linux-gnu/libc.so.6
      #5  0x000055da27e57127 in mtr_commit (mtr=0x7fffa8abe370) at /data/src/10.1/storage/xtradb/mtr/mtr0mtr.cc:322
      #6  0x000055da27faed4b in dict_boot () at /data/src/10.1/storage/xtradb/dict/dict0boot.cc:454
      #7  0x000055da27f2c4b6 in innobase_start_or_create_for_mysql () at /data/src/10.1/storage/xtradb/srv/srv0start.cc:2649
      #8  0x000055da2768cb85 in innodb_init () at /data/src/10.1/extra/mariabackup/xtrabackup.cc:1798
      #9  0x000055da27695ce5 in xtrabackup_prepare_func (argc=3, argv=0x7f08ec820648) at /data/src/10.1/extra/mariabackup/xtrabackup.cc:5979
      #10 0x000055da27697ffa in main (argc=5, argv=0x7fffa8ac2cd8) at /data/src/10.1/extra/mariabackup/xtrabackup.cc:6824

      To reproduce, upload and unpack the backup from here:
      and run

      bin/mariabackup --prepare --apply-log-only --innodb-file-io-threads=1 --target-dir=`pwd`/backup_before_prepare_0

      It was meant to be the initial part of an incremental backup, which is why prepare is run with apply-log-only as documented; I'm not including further incremental backups because they are unimportant for reproducing.

      Backup log is attached as mbackup_backup_0.log.
      As far as I know, there is no DDL in the test flow at the time when the backup is taken; it does, however, include fairly big values for blobs (text fields), which seems to be essential for the problem. The general log is attached as mysql.log.gz.

      The failure happens a lot in my tests on 10.1 and is reproducible easily with random tests, but converting it into a deterministic MTR test case seems not trivial, apparently it depends on timing and possibly requires some debug synchronization or injection.

      I couldn't reproduce it so far on 10.2+.

      Notes on the origin of the report

      Reproducible easily enough with this:

      github.com/MariaDB/randgen --branch elenst-jira-refs a51b46b6

      perl ./runall-new.pl --basedir=/data/src/10.1-bug --vardir=/home/travis/logs/vardir --duration=300 --threads=1 --seed=1549825243 --reporters=Backtrace,ErrorLog,Deadlock --skip-gendata --gendata-advanced   --grammar=conf/mariadb/bulk_insert.yy --mysqld=--log_output=FILE --mysqld=--max-statement-time=3 --mysqld=--lock-wait-timeout=2 --mysqld=--loose-innodb-lock-wait-timeout=1   --engine=InnoDB --scenario=MariaBackupIncremental




            vlad.lesin Vladislav Lesin
            elenst Elena Stepanova
            0 Vote for this issue
            1 Start watching this issue