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

Crash while loading mysqldump backup when InnoDB encryption is enabled

Details

    • 10.1.20

    Description

      A user saw the following crash when loading a mysqldump backup with encryption enabled in MariaDB 10.1.8:

      160919 17:28:30 [ERROR] mysqld got signal 11 ;
      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 http://kb.askmonty.org/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.1.8-MariaDB-log
      key_buffer_size=1048576
      read_buffer_size=262144
      max_used_connections=281
      max_threads=502
      thread_count=65
      It is possible that mysqld could use up to
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 171895 K bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x0x0
      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 0x3c000
      mysys/stacktrace.c:247(my_print_stacktrace)[0x7f5d9e47f6cb]
      sql/signal_handler.cc:160(handle_fatal_signal)[0x7f5d9dfe10d5]
      /lib64/libpthread.so.0(+0x355f20f710)[0x7f5d9d5fa710]
      fil/fil0fil.cc:1002(fil_mutex_enter_and_prepare_for_io)[0x7f5d9e2e8299]
      fil/fil0fil.cc:1465(fil_space_get_space)[0x7f5d9e2ecdd2]
      fil/fil0fil.cc:1584(fil_space_get_flags)[0x7f5d9e2ed149]
      btr/btr0scrub.cc:835(btr_scrub_start_space(unsigned long, btr_scrub_t*))[0x7f5d9e276044]
      fil/fil0crypt.cc:1329(fil_crypt_space_needs_rotation)[0x7f5d9e2f50a5]
      fil/fil0crypt.cc:2238(fil_crypt_thread)[0x7f5d9e2f5a28]
      /lib64/libpthread.so.0(+0x355f2079d1)[0x7f5d9d5f29d1]
      /lib64/libc.so.6(clone+0x6d)[0x7f5d9bad88fd]
      

      After upgrading to 10.1.17, it is still crashing, but the stack trace is not as useful:

      161005 15:39:21 [ERROR] mysqld got signal 11 ;
      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.1.17-MariaDB
      key_buffer_size=1048576
      read_buffer_size=262144
      max_used_connections=5
      max_threads=502
      thread_count=3
      It is possible that mysqld could use up to
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 171954 K bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x0x0
      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 0x3c000
      /usr/sbin/mysqld(my_print_stacktrace+0x2b)[0x7fb41721e16b]
      /usr/sbin/mysqld(handle_fatal_signal+0x475)[0x7fb416d7a375]
      /lib64/libpthread.so.0(+0x355f20f710)[0x7fb41637f710]
      /usr/sbin/mysqld(+0x8d7331)[0x7fb417086331]
      /usr/sbin/mysqld(+0x8dc092)[0x7fb41708b092]
      /usr/sbin/mysqld(+0x8dc439)[0x7fb41708b439]
      /usr/sbin/mysqld(+0x8638b4)[0x7fb4170128b4]
      /usr/sbin/mysqld(+0x8e4405)[0x7fb417093405]
      /usr/sbin/mysqld(+0x8e4d7a)[0x7fb417093d7a]
      /lib64/libpthread.so.0(+0x355f2079d1)[0x7fb4163779d1]
      /lib64/libc.so.6(clone+0x6d)[0x7fb41485d8fd]
      

      Attachments

        Activity

          GeoffMontee Geoff Montee (Inactive) created issue -
          jplindst Jan Lindström (Inactive) made changes -
          Field Original Value New Value
          Assignee Jan Lindström [ jplindst ]

          Based on error log and configuration encryption related.

          jplindst Jan Lindström (Inactive) added a comment - Based on error log and configuration encryption related.

          When the user switched to a debug build, he started seeing this crash instead:

          2016-10-13 01:02:56 7ffff7fe87e0  InnoDB: Assertion failure in thread 140737354041312 in file fil0fil.cc line 7393
          InnoDB: Failing assertion: space->page_0_crypt_read
          InnoDB: We intentionally generate a memory trap.
          InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
          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.6/en/forcing-innodb-recovery.html
          InnoDB: about forcing recovery.
          161013  1:02:56 [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.1.18-MariaDB-debug
          key_buffer_size=1048576
          read_buffer_size=262144
          max_used_connections=0
          max_threads=153
          thread_count=0
          It is possible that mysqld could use up to 
          key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 53191 K  bytes of memory
          Hope that's ok; if not, decrease some variables in the equation.
           
          Thread pointer: 0x0x0
          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 0x3c000
          /usr/sbin/mysqld(my_print_stacktrace+0x35)[0xf13810]
          /usr/sbin/mysqld(handle_fatal_signal+0x3ac)[0x8ce118]
          /lib64/libpthread.so.0[0x36db80f710]
          /lib64/libc.so.6(gsignal+0x35)[0x36db432625]
          /lib64/libc.so.6(abort+0x175)[0x36db433e05]
          /usr/sbin/mysqld[0xceee02]
          /usr/sbin/mysqld[0xc79545]
          /usr/sbin/mysqld[0xc850a1]
          /usr/sbin/mysqld[0xc8562e]
          /usr/sbin/mysqld[0xc85c22]
          /usr/sbin/mysqld[0xc85f38]
          /usr/sbin/mysqld[0xc86a30]
          /usr/sbin/mysqld[0xc86db5]
          /usr/sbin/mysqld[0xc874b5]
          /usr/sbin/mysqld[0xaf0f24]
          /usr/sbin/mysqld[0xaf2021]
          /usr/sbin/mysqld[0xbe35e7]
          /usr/sbin/mysqld[0xa7997b]
          /usr/sbin/mysqld(_Z24ha_initialize_handlertonP13st_plugin_int+0xf3)[0x8d01a6]
          /usr/sbin/mysqld[0x6b1b4e]
          /usr/sbin/mysqld(_Z11plugin_initPiPPci+0x839)[0x6b266c]
          /usr/sbin/mysqld[0x5d4cab]
          /usr/sbin/mysqld(_Z11mysqld_mainiPPc+0x617)[0x5d5cab]
          /usr/sbin/mysqld(main+0x20)[0x5cb004]
          /lib64/libc.so.6(__libc_start_main+0xfd)[0x36db41ed5d]
          /usr/sbin/mysqld[0x5caf29]
          

          GeoffMontee Geoff Montee (Inactive) added a comment - When the user switched to a debug build, he started seeing this crash instead: 2016-10-13 01:02:56 7ffff7fe87e0 InnoDB: Assertion failure in thread 140737354041312 in file fil0fil.cc line 7393 InnoDB: Failing assertion: space->page_0_crypt_read InnoDB: We intentionally generate a memory trap. InnoDB: Submit a detailed bug report to http://bugs.mysql.com. 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.6/en/forcing-innodb-recovery.html InnoDB: about forcing recovery. 161013 1:02:56 [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.1.18-MariaDB-debug key_buffer_size=1048576 read_buffer_size=262144 max_used_connections=0 max_threads=153 thread_count=0 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 53191 K bytes of memory Hope that's ok; if not, decrease some variables in the equation.   Thread pointer: 0x0x0 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 0x3c000 /usr/sbin/mysqld(my_print_stacktrace+0x35)[0xf13810] /usr/sbin/mysqld(handle_fatal_signal+0x3ac)[0x8ce118] /lib64/libpthread.so.0[0x36db80f710] /lib64/libc.so.6(gsignal+0x35)[0x36db432625] /lib64/libc.so.6(abort+0x175)[0x36db433e05] /usr/sbin/mysqld[0xceee02] /usr/sbin/mysqld[0xc79545] /usr/sbin/mysqld[0xc850a1] /usr/sbin/mysqld[0xc8562e] /usr/sbin/mysqld[0xc85c22] /usr/sbin/mysqld[0xc85f38] /usr/sbin/mysqld[0xc86a30] /usr/sbin/mysqld[0xc86db5] /usr/sbin/mysqld[0xc874b5] /usr/sbin/mysqld[0xaf0f24] /usr/sbin/mysqld[0xaf2021] /usr/sbin/mysqld[0xbe35e7] /usr/sbin/mysqld[0xa7997b] /usr/sbin/mysqld(_Z24ha_initialize_handlertonP13st_plugin_int+0xf3)[0x8d01a6] /usr/sbin/mysqld[0x6b1b4e] /usr/sbin/mysqld(_Z11plugin_initPiPPci+0x839)[0x6b266c] /usr/sbin/mysqld[0x5d4cab] /usr/sbin/mysqld(_Z11mysqld_mainiPPc+0x617)[0x5d5cab] /usr/sbin/mysqld(main+0x20)[0x5cb004] /lib64/libc.so.6(__libc_start_main+0xfd)[0x36db41ed5d] /usr/sbin/mysqld[0x5caf29]
          jplindst Jan Lindström (Inactive) made changes -
          Status Open [ 1 ] In Progress [ 3 ]

          Using empty datadir and mariadb-10.1-17 I could not repeat the issue. I imported the provided data several times both in product and debug build and did not see any assertions. However, I did following change to get more information if encryption information is already stored for tablespace but page 0 is not read.

          commit 1bfa37a79c78998e11c79227089864358d05bb4c
          Author: Jan Lindström <jan.lindstrom@mariadb.com>
          Date:   Mon Oct 24 16:55:36 2016 +0300
           
              Add more information if encryption information is already stored for
              tablespace but page0 is not yet read.
          

          jplindst Jan Lindström (Inactive) added a comment - Using empty datadir and mariadb-10.1-17 I could not repeat the issue. I imported the provided data several times both in product and debug build and did not see any assertions. However, I did following change to get more information if encryption information is already stored for tablespace but page 0 is not read. commit 1bfa37a79c78998e11c79227089864358d05bb4c Author: Jan Lindström <jan.lindstrom@mariadb.com> Date: Mon Oct 24 16:55:36 2016 +0300   Add more information if encryption information is already stored for tablespace but page0 is not yet read.

          commit 4edd4ad69807c11a2016ac1477805739270a8ee6
          Author: Jan Lindström <jan.lindstrom@mariadb.com>
          Date: Mon Oct 24 22:25:54 2016 +0300

          MDEV-10970: Crash while loading mysqldump backup when InnoDB encryption is enabled

          Follow-up: Make sure we do not reference NULL-pointer when space is being
          dropped and does not contain any nodes.

          jplindst Jan Lindström (Inactive) added a comment - commit 4edd4ad69807c11a2016ac1477805739270a8ee6 Author: Jan Lindström <jan.lindstrom@mariadb.com> Date: Mon Oct 24 22:25:54 2016 +0300 MDEV-10970 : Crash while loading mysqldump backup when InnoDB encryption is enabled Follow-up: Make sure we do not reference NULL-pointer when space is being dropped and does not contain any nodes.

          encryption.innodb_encryption_tables failed with the same assertion failure once:
          http://buildbot.askmonty.org/buildbot/builders/work-amd64-valgrind/builds/9382/steps/test/logs/stdio

          elenst Elena Stepanova added a comment - encryption.innodb_encryption_tables failed with the same assertion failure once: http://buildbot.askmonty.org/buildbot/builders/work-amd64-valgrind/builds/9382/steps/test/logs/stdio
          ratzpo Rasmus Johansson (Inactive) made changes -
          Sprint 10.1.20 [ 119 ]
          ratzpo Rasmus Johansson (Inactive) made changes -
          Rank Ranked higher
          jplindst Jan Lindström (Inactive) made changes -
          Component/s Storage Engine - XtraDB [ 10135 ]
          Fix Version/s 10.1.20 [ 22112 ]
          Fix Version/s 10.1 [ 16100 ]
          Resolution Fixed [ 1 ]
          Status In Progress [ 3 ] Closed [ 6 ]

          Should this bug have "Fix Versions" set to 10.1.19 if commit "4edd4ad69807c11a2016ac1477805739270a8ee6" was the fix? That commit seems to be included in the "mariadb-10.1.19" tag according to GitHub.

          https://github.com/MariaDB/server/commit/4edd4ad69807c11a2016ac1477805739270a8ee6

          Or did some other commit also contribute to the fix?

          GeoffMontee Geoff Montee (Inactive) added a comment - Should this bug have "Fix Versions" set to 10.1.19 if commit "4edd4ad69807c11a2016ac1477805739270a8ee6" was the fix? That commit seems to be included in the "mariadb-10.1.19" tag according to GitHub. https://github.com/MariaDB/server/commit/4edd4ad69807c11a2016ac1477805739270a8ee6 Or did some other commit also contribute to the fix?
          jplindst Jan Lindström (Inactive) made changes -
          Fix Version/s 10.1.19 [ 22111 ]
          Fix Version/s 10.1.20 [ 22112 ]

          It should be 10.1.19, sorry about error.

          jplindst Jan Lindström (Inactive) added a comment - It should be 10.1.19, sorry about error.
          serg Sergei Golubchik made changes -
          Workflow MariaDB v3 [ 77690 ] MariaDB v4 [ 151018 ]

          People

            jplindst Jan Lindström (Inactive)
            GeoffMontee Geoff Montee (Inactive)
            Votes:
            1 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Git Integration

                Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.