innodb.table_encrypt_kill is causing server to crash on trunk

Description

For some reason after server is killed it cannot retrieve Innodb Master Encryption key from the keyring. It reports errors like:

21:04:17 2018-01-26T02:04:12.004903Z 0 [Warning] InnoDB: Ignoring tablespace `tde_db/t_encrypt_Y_6` because it could not be opened. 21:04:17 2018-01-26T02:04:12.005053Z 0 [ERROR] InnoDB: Encryption can't find master key, please check the keyring plugin is loaded. 21:04:17 2018-01-26T02:04:12.005063Z 0 [ERROR] InnoDB: Encryption information in datafile: ./tde_db/t_encrypt_Y_7.ibd can't be decrypted , please confirm the keyfile is match and

multiple times and in the end causes server to crash:

18:47:26 /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/debian-jessie-64bit/build/sql/mysqld-debug(my_print_stacktrace+0x35)[0x18ec2bb] 18:47:26 /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/debian-jessie-64bit/build/sql/mysqld-debug(handle_fatal_signal+0x425)[0xef362d] 18:47:26 /lib/x86_64-linux-gnu/libpthread.so.0(+0xf890)[0x7ff6ee720890] 18:47:26 /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/debian-jessie-64bit/build/sql/mysqld-debug(_Z28fil_space_is_being_truncatedm+0x4c)[0x1d8d5fc] 18:47:26 /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/debian-jessie-64bit/build/sql/mysqld-debug[0x1bded77] 18:47:26 /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/debian-jessie-64bit/build/sql/mysqld-debug[0x1bdf4ce] 18:47:26 /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/debian-jessie-64bit/build/sql/mysqld-debug(_Z14row_purge_stepP9que_thr_t+0x17f)[0x1bdf740] 18:47:26 /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/debian-jessie-64bit/build/sql/mysqld-debug[0x1b621a6] 18:47:26 /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/debian-jessie-64bit/build/sql/mysqld-debug[0x1b623a8] 18:47:26 /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/debian-jessie-64bit/build/sql/mysqld-debug(_Z15que_run_threadsP9que_thr_t+0x91)[0x1b6255d] 18:47:26 /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/debian-jessie-64bit/build/sql/mysqld-debug[0x1c322dc] 18:47:26 /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/debian-jessie-64bit/build/sql/mysqld-debug(srv_worker_thread+0x226)[0x1c3252b] 18:47:26 /lib/x86_64-linux-gnu/libpthread.so.0(+0x8064)[0x7ff6ee719064] 18:47:26 /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7ff6ec96462d]

 

Environment

None

Smart Checklist

Activity

Show:

Kathy Williamson August 17, 2020 at 12:09 PM

Completed under another ticket

Robert Golebiowski February 5, 2018 at 1:10 PM
Edited

Upstream bug. Seems like a design mistake. I have filed a mysql bug: https://bugs.mysql.com/bug.php?id=89534. Pasting here the bug report:

There is a crash due to possible mistake in InnoDB crash recovery design. The problem occurs when crash recovery is working with encrypted table, but possibly is not limited only to encrypted tables. This problem is visible in innodb.table_encrypt_kill testcase crash, however, this testcase crash rarely. The crash can be observed in the following scenario:

  • Start server with keyring plugin loaded in.

  • Create an encrypted table t1, run bunch of inserts, updates, deletes on it – like innodb.table_encrypt_kill testcase does.

  • Restart the server without keyring.

  • We should receive warnings that t1 cannot be loaded by innodb – due to lack of master key.

  • It can so happen that some of the records from t1 will be marked to delete in undo tablespace.

  • Purge threads will try to access table t1, however, t1 will not be loaded into fil_system→spaces. There will be crash on this statement :
    mark_for_truncate = fil_space_get_by_id(id)->is_being_truncated;
    (see the stack trace below)
     
    Skipping undo record that belongs to encrypted table that cannot be decrypted seems dangerous as undo tablespace should get truncated. I am not sure how deep the implication of skipping undo record could be.

Maybe recovery should stop if keyring for encrypted table is not available and only be done if some –force_recover option is used – discarding undo records for encrypted tables.

 
The stack trace: 

#0 0x00007f6f9c2f80c1 in __pthread_kill (threadid=<optimized out>, signo=11) at ../nptl/sysdeps/unix/sysv/linux/pthread_kill.c:61 #1 0x00000000018ce795 in my_write_core (sig=11) at /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/min-jessie-x64/mysys/stacktrace.c:249 #2 0x0000000000ef3285 in handle_fatal_signal (sig=11) at /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/min-jessie-x64/sql/signal_handler.cc:223 #3 <signal handler called> #4 0x0000000001ca968f in fil_space_is_being_truncated (id=24) at /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/min-jessie-x64/storage/innobase/fil/fil0fil.cc:1636 #5 0x0000000001b011c4 in row_purge_parse_undo_rec (node=0x3a74050, undo_rec=0x7f6f64010ac0 "\025\220\016", updated_extern=0x7f6f7affcdbe, thr=0x3a73f88) at /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/min-jessie-x64/storage/innobase/row/row0purge.cc:875 #6 0x0000000001b0191b in row_purge (node=0x3a74050, undo_rec=0x7f6f64010ac0 "\025\220\016", thr=0x3a73f88) at /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/min-jessie-x64/storage/innobase/row/row0purge.cc:1046 #7 0x0000000001b01b8d in row_purge_step (thr=0x3a73f88) at /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/min-jessie-x64/storage/innobase/row/row0purge.cc:1128 #8 0x0000000001a85ba0 in que_thr_step (thr=0x3a73f88) at /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/min-jessie-x64/storage/innobase/que/que0que.cc:1066 #9 0x0000000001a85da2 in que_run_threads_low (thr=0x3a73f88) at /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/min-jessie-x64/storage/innobase/que/que0que.cc:1128 #10 0x0000000001a85f57 in que_run_threads (thr=0x3a73f88) at /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/min-jessie-x64/storage/innobase/que/que0que.cc:1168 #11 0x0000000001b5317b in srv_task_execute () at /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/min-jessie-x64/storage/innobase/srv/srv0srv.cc:2842 #12 0x0000000001b533ca in srv_worker_thread (arg=0x0) at /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/min-jessie-x64/storage/innobase/srv/srv0srv.cc:2904 #13 0x00007f6f9c2f3064 in start_thread (arg=0x7f6f7affd700) at pthread_create.c:309 #14 0x00007f6f9a53e62d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111 Testcase innodb.table_encrypt_kill
Done

Details

Assignee

Reporter

Time tracking

28m logged

Affects versions

Priority

Smart Checklist

Created January 26, 2018 at 11:31 AM
Updated March 6, 2024 at 1:41 PM
Resolved August 17, 2020 at 12:09 PM