[MDEV-10970] Crash while loading mysqldump backup when InnoDB encryption is enabled Created: 2016-10-06  Updated: 2016-12-05  Resolved: 2016-12-02

Status: Closed
Project: MariaDB Server
Component/s: Encryption, Storage Engine - InnoDB, Storage Engine - XtraDB
Affects Version/s: 10.1.8, 10.1.17
Fix Version/s: 10.1.19

Type: Bug Priority: Critical
Reporter: Geoff Montee (Inactive) Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 1
Labels: encryption, innodb

Sprint: 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]



 Comments   
Comment by Jan Lindström (Inactive) [ 2016-10-07 ]

Based on error log and configuration encryption related.

Comment by Geoff Montee (Inactive) [ 2016-10-13 ]

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]

Comment by Jan Lindström (Inactive) [ 2016-10-24 ]

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.

Comment by Jan Lindström (Inactive) [ 2016-10-24 ]

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.

Comment by Elena Stepanova [ 2016-11-02 ]

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

Comment by Geoff Montee (Inactive) [ 2016-12-02 ]

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?

Comment by Jan Lindström (Inactive) [ 2016-12-05 ]

It should be 10.1.19, sorry about error.

Generated at Thu Feb 08 07:46:18 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.