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

Assertion `block->page.flush_observer == __null || block->page.flush_observer == observer' failed in buf_flush_note_modification

    XMLWordPrintable

    Details

      Description

      The test case uses innodb_background_scrub_data_uncompressed, but I don't think it's absolutely necessary for the assertion failure to happen, apparently it just makes it reasonably reproducible. The identical failure was observed without any scrubbing-related options (but with encryption enabled) upon upgrade from MySQL 5.7.24 to 10.2.

      • The test case is non-deterministic and it uses a loop. Please don't put it into the regression suite, it's for reproducing purposes only.
      • Run with --repeat=N if it doesn't fail right away. It usually fails for me within 3 attempts. Increasing the number of loops doesn't seem to increase the probability. Make sure the server is restarted between attempts (in the test case below, the commented part of the cleanup makes sure of that).
      • Run with --mem or on SSD. I don't know if it's reproducible on a spinning disk, the test case takes too long.
      • Remember to run with encryption options.

      Run with

      --mysqld=--innodb-encrypt-tables  --mysqld=--innodb-encryption-threads=4    --mysqld=--file-key-management  --mysqld=--plugin-load-add=file_key_management --mysqld=--file-key-management-filename=`pwd`/std_data/keys.txt --mysqld=--plugin-load-add=file_key_management --repeat=5 --mem
      

      --source include/have_innodb.inc
       
      SET @scrub.save= @@innodb_background_scrub_data_uncompressed;
       
      --connect (con1,localhost,root,,)
      CREATE TABLE t1 (pk INT, a INT, PRIMARY KEY(pk)) ENGINE=InnoDB;
      INSERT INTO t1 VALUES (1,2),(2,3),(3,4),(4,5),(5,6),(6,7),(7,8),(8,9);
      SET GLOBAL innodb_background_scrub_data_uncompressed=ON;
      --disconnect con1
       
      --connection default
      --let $i= 1000
      while ($i)
      {
         --eval ALTER TABLE t1 FORCE /* $i */
         --dec $i
      }
       
      # Cleanup
      --delimiter ;
      DROP TABLE t1;
       
      # This is intentionally commented, so that when you run with --repeat,
      # the server is restarted every time between the runs
      # SET GLOBAL innodb_background_scrub_data_uncompressed = @scrub.save;
      

      10.4 18af13b8 debug

      mysqld: /data/src/10.4/storage/innobase/include/buf0flu.ic:65: void buf_flush_note_modification(buf_block_t*, lsn_t, lsn_t, FlushObserver*): Assertion `block->page.flush_observer == __null || block->page.flush_observer == observer' failed.
      190906 18:34:16 [ERROR] mysqld got signal 6 ;
       
      #7  0x00007fb27288ef12 in __GI___assert_fail (assertion=0x555abe139f18 "block->page.flush_observer == __null || block->page.flush_observer == observer", file=0x555abe139e18 "/data/src/10.4/storage/innobase/include/buf0flu.ic", line=65, function=0x555abe13bd80 <_ZZL27buf_flush_note_modificationP11buf_block_tmmP13FlushObserverE19__PRETTY_FUNCTION__> "void buf_flush_note_modification(buf_block_t*, lsn_t, lsn_t, FlushObserver*)") at assert.c:101
      #8  0x0000555abd8836da in buf_flush_note_modification (block=0x7fb26782a8f8, start_lsn=484825, end_lsn=484831, observer=0x0) at /data/src/10.4/storage/innobase/include/buf0flu.ic:65
      #9  0x0000555abd887420 in ReleaseBlocks::add_dirty_page_to_flush_list (this=0x7fb24d7f9780, slot=0x7fb24d7f98e8) at /data/src/10.4/storage/innobase/mtr/mtr0mtr.cc:379
      #10 0x0000555abd88746f in ReleaseBlocks::operator() (this=0x7fb24d7f9780, slot=0x7fb24d7f98e8) at /data/src/10.4/storage/innobase/mtr/mtr0mtr.cc:390
      #11 0x0000555abd88829e in CIterate<ReleaseBlocks const>::operator() (this=0x7fb24d7f9780, block=0x7fb24d7f98d8) at /data/src/10.4/storage/innobase/mtr/mtr0mtr.cc:60
      #12 0x0000555abd887c0c in mtr_buf_t::for_each_block_in_reverse<CIterate<ReleaseBlocks const> > (this=0x7fb24d7f98a0, functor=...) at /data/src/10.4/storage/innobase/include/dyn0buf.h:371
      #13 0x0000555abd886282 in mtr_t::Command::release_blocks (this=0x7fb24d7f97f0) at /data/src/10.4/storage/innobase/mtr/mtr0mtr.cc:885
      #14 0x0000555abd8863c5 in mtr_t::Command::execute (this=0x7fb24d7f97f0) at /data/src/10.4/storage/innobase/mtr/mtr0mtr.cc:910
      #15 0x0000555abd8845b5 in mtr_t::commit (this=0x7fb24d7f98a0) at /data/src/10.4/storage/innobase/mtr/mtr0mtr.cc:558
      #16 0x0000555abdb6efdb in fil_crypt_rotate_page (key_state=0x7fb24d7f9e34, state=0x7fb24d7f9e40) at /data/src/10.4/storage/innobase/fil/fil0crypt.cc:2052
      #17 0x0000555abdb6f6f4 in fil_crypt_rotate_pages (key_state=0x7fb24d7f9e34, state=0x7fb24d7f9e40) at /data/src/10.4/storage/innobase/fil/fil0crypt.cc:2179
      #18 0x0000555abdb701e1 in fil_crypt_thread () at /data/src/10.4/storage/innobase/fil/fil0crypt.cc:2403
      #19 0x00007fb2744034a4 in start_thread (arg=0x7fb24d7fa700) at pthread_create.c:456
      #20 0x00007fb27294bd0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
      

      Reproducible on 10.2+.
      Couldn't reproduce on 10.1.
      No immediate obvious effect on a release build.

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              marko Marko Mäkelä
              Reporter:
              elenst Elena Stepanova
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: