[MDEV-8156] Assertion failure in file log0crypt.cc line 220 on server restart Created: 2015-05-13  Updated: 2015-08-06  Resolved: 2015-06-18

Status: Closed
Project: MariaDB Server
Component/s: Encryption, Storage Engine - InnoDB, Storage Engine - XtraDB
Affects Version/s: 10.1.4
Fix Version/s: 10.1.6

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 0
Labels: None

Sprint: 10.1.6-1

 Description   

If the server was previously started with InnoDB log encryption, restarting the server without the encryption plugin causes the assertion failure as below. On a release build, there is no assertion failure, but a crash with SIGABRT.

I realize it cannot really work without the plugin on encrypted logs, and expect it to abort, but it would be good to have clear diagnostics for this rather than the scary crash.

Also, I thought it might work with innodb_fast_shutdown turned off, but it doesn't make a difference. 

150513  3:32:01 [ERROR] InnoDB: Redo log crypto: getting mysqld crypto key from key version failed.
 
2015-05-13 03:32:01 7f4331ff6760  InnoDB: Assertion failure in thread 139926578358112 in file log0crypt.cc line 220
 
InnoDB: We intentionally generate a memory trap.

Stack trace from 10.1 commit c8ad5b2f

 
#5  0x00007f432fbd33e0 in *__GI_abort () at abort.c:92
 
#6  0x00007f4332962742 in init_crypt_key (info=0x7ffce3e6e010) at 10.1/storage/xtradb/log/log0crypt.cc:220
 
#7  0x00007f4332962884 in add_crypt_info (info=0x7ffce3e6e010) at 10.1/storage/xtradb/log/log0crypt.cc:254
 
#8  0x00007f4332962fa3 in log_crypt_read_checkpoint_buf (buf=0x7f432f015b36 "") at 10.1/storage/xtradb/log/log0crypt.cc:474
 
#9  0x00007f433295bcfb in recv_find_max_checkpoint (max_group=0x7ffce3e6eb58, max_field=0x7ffce3e6eb60) at 10.1/storage/xtradb/log/log0recv.cc:813
 
#10 0x00007f433295fbac in recv_recovery_from_checkpoint_start_func (type=78656949, limit_lsn=18446744073709551615, min_flushed_lsn=1616911, max_flushed_lsn=1616911) at 10.1/storage/xtradb/log/log0recv.cc:3162
 
#11 0x00007f4332a411dc in innobase_start_or_create_for_mysql () at 10.1/storage/xtradb/srv/srv0start.cc:2528
 
#12 0x00007f43328d87fa in innobase_init (p=0x7f432f02e270) at 10.1/storage/xtradb/handler/ha_innodb.cc:4083
 
#13 0x00007f433272c2f0 in ha_initialize_handlerton (plugin=0x7f432f1446e8) at 10.1/sql/handler.cc:512
 
#14 0x00007f4332513fa8 in plugin_initialize (tmp_root=0x7ffce3e728e0, plugin=0x7f432f1446e8, argc=0x7f43337f59d0, argv=0x7f432f01e6c0, options_only=false) at 10.1/sql/sql_plugin.cc:1403
 
#15 0x00007f4332514b7a in plugin_init (argc=0x7f43337f59d0, argv=0x7f432f01e6c0, flags=2) at 10.1/sql/sql_plugin.cc:1676
 
#16 0x00007f43324363e7 in init_server_components () at 10.1/sql/mysqld.cc:5041
 
#17 0x00007f4332437528 in mysqld_main (argc=12, argv=0x7f432f01e6c0) at 10.1/sql/mysqld.cc:5631
 
#18 0x00007f433242d100 in main (argc=11, argv=0x7ffce3e73628) at 10.1/sql/main.cc:25

To reproduce:

  • start server with 

    [mysqld]
    		 
    plugin-load-add=file_key_management.so
    		 
    loose-file_key_management_filename=/home/elenst/git/10.1/mysql-test/std_data/keys.txt
    		 
    innodb-encrypt-log=on

  • shut down the server
  • start the server without the options above.

 Comments   
Comment by Jan Lindström (Inactive) [ 2015-06-18 ]

commit f5ddffd83e627cc0f6a24dfe4d8fc2e0c983bf78
Author: Jan Lindström <jan.lindstrom@mariadb.com>
Date: Thu Jun 18 19:58:57 2015 +0300

MDEV-8156: Assertion failure in file log0crypt.cc line 220 on server restart

Instead of asserting print informative error message to error log
and return failure from innodb_init causing the server to shutdown.

Comment by Aurélien LEQUOY [ 2015-08-06 ]

I just tried with lastest 10.1.6 (donwload and compiled 1 hour ago) and i got same problem !

[mariadb-10.1]
 
plugin-load-add=file_key_management.so
 
file-key-management
 
file-key-management
 
file-key-management-filename='key.enc'
 
file_key_management_filekey='secretPassword2'
 
innodb-encrypt-tables
 
innodb-encrypt-log
 
innodb-encryption-threads=2
 
encrypt-tmp-disk-tables=1

create a table with encrypt
insert one line

remove these options and restart server and i got :

150806 16:26:41 mysqld_safe Starting mysqld daemon with databases from /data/mysql/data
 
2015-08-06 16:26:42 139969101432640 [Note] /usr/local/mysql/bin/mysqld (mysqld 10.1.6-MariaDB-log) starting as process 30296 ...
 
2015-08-06 16:26:42 139969101432640 [Note] InnoDB: Using mutexes to ref count buffer pool pages
 
2015-08-06 16:26:42 139969101432640 [Note] InnoDB: The InnoDB memory heap is disabled
 
2015-08-06 16:26:42 139969101432640 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2015-08-06 16:26:42 139969101432640 [Note] InnoDB: Memory barrier is not used
 
2015-08-06 16:26:42 139969101432640 [Note] InnoDB: Compressed tables use zlib 1.2.3.4
 
2015-08-06 16:26:42 139969101432640 [Note] InnoDB: Not using CPU crc32 instructions
 
2015-08-06 16:26:42 139969101432640 [Note] InnoDB: Initializing buffer pool, size = 4.0G
 
2015-08-06 16:26:43 139969101432640 [Note] InnoDB: Completed initialization of buffer pool
 
2015-08-06 16:26:45 139969101432640 [Note] InnoDB: Highest supported file format is Barracuda.
 
2015-08-06 16:26:45 139969101432640 [ERROR] InnoDB: Redo log crypto: getting mysqld crypto key from key version failed. Reason could b
 
e that requested key_version 1 is not found or required encryption  key management is not found.
 
2015-08-06 16:26:45 139969101432640 [ERROR] Plugin 'InnoDB' init function returned error.
 
2015-08-06 16:26:45 139969101432640 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
 
2015-08-06 16:26:45 139969101432640 [Note] Plugin 'FEEDBACK' is disabled.
 
2015-08-06 16:26:45 139969101432640 [ERROR] Unknown/unsupported storage engine: InnoDB
 
2015-08-06 16:26:45 139969101432640 [ERROR] Aborting
 
 
 
2015-08-06 16:26:45 139969101432640 [Note] /usr/local/mysql/bin/mysqld: Shutdown complete

Comment by Jan Lindström (Inactive) [ 2015-08-06 ]

Hi,

To me this does not look the same. In original bug report there was a error message and crash. Now server refuses the start and prints error message (if full error log is provided). If requested key_version is not found there is no way to continue.

Comment by Aurélien LEQUOY [ 2015-08-06 ]

yes, but my point of view it's you miss key, so you lost encripted data => normal.

But in this case you lost all data even data not encripted. (i just cripted one table one this table).

More how to get back without encryption ?

Comment by Jan Lindström (Inactive) [ 2015-08-06 ]

Yes, can you explain step by step what you did, but original problem was that you had innodb-encrypt-log=on
, after this log file is encrypted and if you lost the key you can't restart the database from latest checkpoint (because it is encrypted).

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