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

Assertion `found' in buf_page_get_low with encryption and scrubbing

    XMLWordPrintable

    Details

      Description

      It seems to only affect 10.2 and 10.3. If it is indeed so, I don't expect it to be fixed, but I still need it be filed, so that we can ignore it in future.

      The test case is non-deterministic. It currently fails for me on average within ~50 attempts, but it can vary a lot.
      Run with

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

      --source include/have_innodb.inc
      --source include/have_sequence.inc
       
      SET @age= @@innodb_encryption_rotate_key_age,
          @scrub= @@innodb_background_scrub_data_uncompressed;
       
      SET GLOBAL innodb_encryption_rotate_key_age= 0,
                 innodb_background_scrub_data_uncompressed= 1;
       
      CREATE TABLE t (pk INT PRIMARY KEY) ENGINE=InnoDB;
      INSERT INTO t SELECT seq FROM seq_1_to_1000;
      DROP TABLE t;
       
      SET GLOBAL innodb_encryption_rotate_key_age= @age,
                 innodb_background_scrub_data_uncompressed= @scrub;
      

      10.3 4e503aec

      mysqld: /data/src/10.3/storage/innobase/buf/buf0buf.cc:4263: buf_block_t* buf_page_get_low(page_id_t, const page_size_t&, ulint, buf_block_t*, ulint, const char*, unsigned int, mtr_t*, dberr_t*): Assertion `found' failed.
      210123 23:22:34 [ERROR] mysqld got signal 6 ;
       
      Thread 29 (Thread 0x7fe81dffb700 (LWP 2907754)):
      #0  my_read (Filedes=72, Buffer=0x7fe81dff8c40 "Limit", ' ' <repeats 21 times>, "Soft Limit", ' ' <repeats 11 times>, "Hard Limit", ' ' <repeats 11 times>, "Units     \nMax cpu time", ' ' <repeats 14 times>, "unlimited", ' ' <repeats 12 times>, "unlimited", ' ' <repeats 12 times>, "seconds   \nMax file size", ' ' <repeats 13 times>, "unlimited       "..., Count=4096, MyFlags=0) at /data/src/10.3/mysys/my_read.c:63
      #1  0x000055d83d0e1aac in output_core_info () at /data/src/10.3/sql/signal_handler.cc:66
      #2  0x000055d83d0e22aa in handle_fatal_signal (sig=6) at /data/src/10.3/sql/signal_handler.cc:339
      #3  <signal handler called>
      #4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
      #5  0x00007fe84c2cf859 in __GI_abort () at abort.c:79
      #6  0x00007fe84c2cf729 in __assert_fail_base (fmt=0x7fe84c465588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55d83dcd1927 "found", file=0x55d83dccf2e8 "/data/src/10.3/storage/innobase/buf/buf0buf.cc", line=4263, function=<optimized out>) at assert.c:92
      #7  0x00007fe84c2e0f36 in __GI___assert_fail (assertion=0x55d83dcd1927 "found", file=0x55d83dccf2e8 "/data/src/10.3/storage/innobase/buf/buf0buf.cc", line=4263, function=0x55d83dcd1800 "buf_block_t* buf_page_get_low(page_id_t, const page_size_t&, ulint, buf_block_t*, ulint, const char*, unsigned int, mtr_t*, dberr_t*)") at assert.c:101
      #8  0x000055d83d63251d in buf_page_get_low (page_id=..., page_size=..., rw_latch=2, guess=0x0, mode=10, file=0x55d83dd036d8 "/data/src/10.3/storage/innobase/fil/fil0crypt.cc", line=2076, mtr=0x7fe81dffa8d0, err=0x7fe81dffa884) at /data/src/10.3/storage/innobase/buf/buf0buf.cc:4263
      #9  0x000055d83d63470e in buf_page_get_gen (page_id=..., page_size=..., rw_latch=2, guess=0x0, mode=10, file=0x55d83dd036d8 "/data/src/10.3/storage/innobase/fil/fil0crypt.cc", line=2076, mtr=0x7fe81dffa8d0, err=0x7fe81dffa884) at /data/src/10.3/storage/innobase/buf/buf0buf.cc:4901
      #10 0x000055d83d6e956a in fil_crypt_flush_space (state=0x7fe81dffae20) at /data/src/10.3/storage/innobase/fil/fil0crypt.cc:2073
      #11 0x000055d83d6e99a3 in fil_crypt_complete_rotate_space (state=0x7fe81dffae20) at /data/src/10.3/storage/innobase/fil/fil0crypt.cc:2154
      #12 0x000055d83d6e9d68 in fil_crypt_thread () at /data/src/10.3/storage/innobase/fil/fil0crypt.cc:2257
      #13 0x00007fe84c7f0609 in start_thread (arg=<optimized out>) at pthread_create.c:477
      #14 0x00007fe84c3cc293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      Another assertion failure happens on a much rarer occasion:

      mysqld: /data/src/10.3/storage/innobase/btr/btr0scrub.cc:882: void btr_scrub_complete_space(btr_scrub_t*): Assertion `scrub_data->scrubbing' failed.
      210123 23:31:33 [ERROR] mysqld got signal 6 ;
      

      No coredump is produced in this case.

      The data in the table is not required for the first failure, but might be necessary for the second one.
      rr profile for the 1st failure is available.

        Attachments

          Activity

            People

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

              Dates

              Created:
              Updated:
              Resolved:

                Git Integration