[MDEV-8011] Table encryption issues Created: 2015-04-17  Updated: 2015-05-09  Resolved: 2015-05-09

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

Type: Bug Priority: Major
Reporter: Rhys Campbell Assignee: Sergei Golubchik
Resolution: Fixed Votes: 0
Labels: verified
Environment:

CentOS 7 64 Bit

Attachments: PNG File 1.png     PNG File 2.png     PNG File 3.png    
Issue Links:
Relates
relates to MDEV-8021 "InnoDB: Tablespace id 4 encrypted bu... Closed

 Description   

Hi All,

Been playing with encryption in 10.1.4 today and there’s a few issues…

Firstly the manual gives the following example…

“Example my.cnf to enable XtraDB encryption:

[mysqld]
 
file-key-management
 
file-key-management-filename = /mount/usb1/keys.txt
 
innodb-encrypt-tables
 
innodb-encrypt-logs
 
innodb-encryption-threads=4”

But doesn’t make mention of the fact you need to add..

plugin-load-add=file_key_management.so

for this to work.

Secondly…

With this config..

plugin-load-add=file_key_management.so
 
file_key_management
 
file_key_management_filename = /home/rcampbel/key.enc
 
file_key_management_filekey = FILE:/home/rcampbel/keyfile.txt
 
file_key_management_encryption_algorithm = AES_CBC
 
innodb-encrypt-tables
 
innodb-encrypt-logs
 
innodb-encryption-threads = 4

I receive the following error…

ERROR Innodb: Tablespace id 0 encrypted but encryption service not available. Can’t continue opening tablespace.”

Then if I comment out inndob-encrypt-tables we get a step further but it complains..

“unknown option –innodb-encrypt-logs” <- documentation for 10.1.4 says different

If I change this to…

innodb-encrypt-log

The server then starts up successfully. Here’s a snip of some relevant variables…

After this I do seem to be able to dynamically set innodb_encrypt_tables and create an encrypted table…

Then adding both, or either one of…

aria-encrypt-tables=1
 
encrypt-tmp-disk-tables=1

Results in a crash on startup…

 Comments   
Comment by Elena Stepanova [ 2015-04-17 ]

Thanks for the report.

Regarding documentation issues, I updated the KB page
a) changed innodb-encrypt-logs to innodb-encrypt-log (as serg confirmed it will stay as is);
b) added add-plugin-load to the config example; apparently the example assumed the plugin was a static library, but it's not the most normal case.

Regarding the assertion failure, I'm not getting this kind of crash on a fresh datadir. Did you upgrade from a previous version, or did you create any tables/data/InnoDB logs before starting the server with these options? Knowing it might help me to reproduce the problem.

Comment by Rhys Campbell [ 2015-04-17 ]

Hi Elena,

No this was a fresh installation\datadir with no tables/data additions.

I'm using this to spin up instances for testing..

https://github.com/mathnode/mim

It does change to the correct instances dir and does an mysql_install_db.

Rhys

Comment by Elena Stepanova [ 2015-04-18 ]

Thanks.

The assertion failure does not appear to be related to the added options (aria-encrypt-tables=1 or encrypt-tmp-disk-tables=1), but to the scenario itself:

  • start the server without innodb-encrypt-tables;
  • set innodb-encrypt-tables;
  • create InnoDB table;
  • restart the server (so it again starts without innodb-encrypt-tables);
    => the failure occurs.

Test case

 
--source include/have_file_key_management_plugin.inc
 
--source include/have_innodb.inc
 
 
 
set global innodb_encrypt_tables = 1;
 
 
 
create table t1 (i int) engine=InnoDB;
 
 
 
--enable_reconnect
 
--exec echo "wait" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
 
--shutdown_server
 
--source include/wait_until_disconnected.inc
 
 
 
--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
 
--source include/wait_until_connected_again.inc
 
 
 
select * from t1;

Stack trace from 10.1 commit 22a7b4dee0

 
150418  3:33:10 [ERROR] InnoDB: Key id 0 version 1 can not be found. Reason=4294967295
 
2015-04-18 03:33:10 7f847d31a700  InnoDB: Assertion failure in thread 140207012816640 in file ha_innodb.cc line 19898
 
 
 
#5  0x00007f847af483e0 in *__GI_abort () at abort.c:92
 
#6  0x00007f84743218c0 in ib_logf (level=IB_LOG_LEVEL_FATAL, format=0x7f84744ceff8 "Key id %u version %u can not be found. Reason=%u") at 10.1/storage/innobase/handler/ha_innodb.cc:19898
 
#7  0x00007f84742bb08f in fil_crypt_get_key (dst=0x7f847d316520 "Pe1}\204\177", key_length=0x7f847d3164c0, crypt_data=0x7f84763d6300, version=1) at 10.1/storage/innobase/fil/fil0crypt.cc:184
 
#8  0x00007f84742bc582 in fil_space_decrypt (crypt_data=0x7f84763d6300, src_frame=0x7f8465d24000 "t\030\006\252", page_size=16384, dst_frame=0x7f8471a90000 "t\030\006\252") at 10.1/storage/innobase/fil/fil0crypt.cc:811
 
#9  0x00007f84742bc7f1 in fil_space_decrypt (space=4, src_frame=0x7f8465d24000 "t\030\006\252", page_size=16384, dst_frame=0x7f8471a90000 "t\030\006\252") at 10.1/storage/innobase/fil/fil0crypt.cc:880
 
#10 0x00007f847424726d in buf_page_decrypt_after_read (bpage=0x7f84717bc080) at 10.1/storage/innobase/buf/buf0buf.cc:5844
 
#11 0x00007f8474243720 in buf_page_io_complete (bpage=0x7f84717bc080, evict=false) at 10.1/storage/innobase/buf/buf0buf.cc:4245
 
#12 0x00007f847425fdf1 in buf_read_page_low (err=0x7f847d31670c, sync=true, mode=132, space=4, zip_size=0, unzip=0, tablespace_version=5, offset=3) at 10.1/storage/innobase/buf/buf0rea.cc:216
 
#13 0x00007f8474260329 in buf_read_page (space=4, zip_size=0, offset=3) at 10.1/storage/innobase/buf/buf0rea.cc:414
 
#14 0x00007f847423fddd in buf_page_get_gen (space=4, zip_size=0, offset=3, rw_latch=2, guess=0x0, mode=10, file=0x7f84744a8bf0 "10.1/storage/innobase/btr/btr0btr.cc", line=736, mtr=0x7f847d3169c0) at 10.1/storage/innobase/buf/buf0buf.cc:2764
 
#15 0x00007f84741fe784 in btr_block_get_func (space=4, zip_size=0, page_no=3, mode=2, file=0x7f84744a8bf0 "10.1/storage/innobase/btr/btr0btr.cc", line=736, index=0x7f8465d29978, mtr=0x7f847d3169c0) at 10.1/storage/innobase/include/btr0btr.ic:60
 
#16 0x00007f84741ff52e in btr_root_block_get (index=0x7f8465d29978, mode=2, mtr=0x7f847d3169c0) at 10.1/storage/innobase/btr/btr0btr.cc:736
 
#17 0x00007f84741ff668 in btr_root_get (index=0x7f8465d29978, mtr=0x7f847d3169c0) at 10.1/storage/innobase/btr/btr0btr.cc:763
 
#18 0x00007f8474200455 in btr_get_size_and_reserved (index=0x7f8465d29978, flag=2, used=0x7f847d316988, mtr=0x7f847d3169c0) at 10.1/storage/innobase/btr/btr0btr.cc:1256
 
#19 0x00007f8474200352 in btr_get_size (index=0x7f8465d29978, flag=2, mtr=0x7f847d3169c0) at 10.1/storage/innobase/btr/btr0btr.cc:1220
 
#20 0x00007f8474298282 in dict_stats_update_transient_for_index (index=0x7f8465d29978) at 10.1/storage/innobase/dict/dict0stats.cc:889
 
#21 0x00007f84742984b7 in dict_stats_update_transient (table=0x7f8465d29378) at 10.1/storage/innobase/dict/dict0stats.cc:965
 
#22 0x00007f847429cda5 in dict_stats_update (table=0x7f8465d29378, stats_upd_option=DICT_STATS_RECALC_TRANSIENT) at 10.1/storage/innobase/dict/dict0stats.cc:3387
 
#23 0x00007f847430112e in dict_stats_init (table=0x7f8465d29378) at 10.1/storage/innobase/include/dict0stats.ic:174
 
#24 0x00007f8474307872 in ha_innodb::open (this=0x7f8465c7d088, name=0x7f8465c6bf60 "./test/t1", mode=2, test_if_locked=18) at 10.1/storage/innobase/handler/ha_innodb.cc:5576
 
#25 0x00007f847da9d962 in handler::ha_open (this=0x7f8465c7d088, table_arg=0x7f8465c9ea70, name=0x7f8465c6bf60 "./test/t1", mode=2, test_if_locked=18) at 10.1/sql/handler.cc:2510
 
#26 0x00007f847d9558b5 in open_table_from_share (thd=0x7f846e0fb070, share=0x7f8465c6ba88, alias=0x7f8465ce0260 "t1", db_stat=39, prgflag=44, ha_open_flags=18, outparam=0x7f8465c9ea70, is_create_table=false) at 10.1/sql/table.cc:2917
 
#27 0x00007f847d803d05 in open_table (thd=0x7f846e0fb070, table_list=0x7f8465ce0268, ot_ctx=0x7f847d317f90) at 10.1/sql/sql_base.cc:2547
 
#28 0x00007f847d80653a in open_and_process_table (thd=0x7f846e0fb070, lex=0x7f846e0fed28, tables=0x7f8465ce0268, counter=0x7f847d318034, flags=0, prelocking_strategy=0x7f847d3180a0, has_prelocking_list=false, ot_ctx=0x7f847d317f90) at 10.1/sql/sql_base.cc:4013
 
#29 0x00007f847d80771c in open_tables (thd=0x7f846e0fb070, options=..., start=0x7f847d318018, counter=0x7f847d318034, flags=0, prelocking_strategy=0x7f847d3180a0) at 10.1/sql/sql_base.cc:4538
 
#30 0x00007f847d808904 in open_and_lock_tables (thd=0x7f846e0fb070, options=..., tables=0x7f8465ce0268, derived=true, flags=0, prelocking_strategy=0x7f847d3180a0) at 10.1/sql/sql_base.cc:5196
 
#31 0x00007f847d7fc333 in open_and_lock_tables (thd=0x7f846e0fb070, tables=0x7f8465ce0268, derived=true, flags=0) at 10.1/sql/sql_base.h:530
 
#32 0x00007f847d87459b in execute_sqlcom_select (thd=0x7f846e0fb070, all_tables=0x7f8465ce0268) at 10.1/sql/sql_parse.cc:5703
 
#33 0x00007f847d86adb9 in mysql_execute_command (thd=0x7f846e0fb070) at 10.1/sql/sql_parse.cc:2926
 
#34 0x00007f847d87802e in mysql_parse (thd=0x7f846e0fb070, rawbuf=0x7f8465ce0088 "select * from t1", length=16, parser_state=0x7f847d3191b0) at 10.1/sql/sql_parse.cc:7165
 
#35 0x00007f847d86703e in dispatch_command (command=COM_QUERY, thd=0x7f846e0fb070, packet=0x7f84737d8071 "select * from t1", packet_length=16) at 10.1/sql/sql_parse.cc:1462
 
#36 0x00007f847d865e0e in do_command (thd=0x7f846e0fb070) at 10.1/sql/sql_parse.cc:1090
 
#37 0x00007f847d9970a7 in do_handle_one_connection (thd_arg=0x7f846e0fb070) at 10.1/sql/sql_connect.cc:1347
 
#38 0x00007f847d996dec in handle_one_connection (arg=0x7f846e0fb070) at 10.1/sql/sql_connect.cc:1258
 
#39 0x00007f847df4bf46 in pfs_spawn_thread (arg=0x7f847a4244f0) at 10.1/storage/perfschema/pfs.cc:1860
 
#40 0x00007f847cf59b50 in start_thread (arg=<optimized out>) at pthread_create.c:304
 
#41 0x00007f847afee95d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112

Comment by Elena Stepanova [ 2015-04-18 ]

I missed another failure reported in the description:

150418 21:22:24 [ERROR] InnoDB: Tablespace id 0 encrypted but encryption service not available. Can't continue opening tablespace.
 
 
 
2015-04-18 21:22:24 7f2fe642e760  InnoDB: Assertion failure in thread 139843703334752 in file ha_innodb.cc line 21064
 
 
 
#5  0x00007f2fe400b3e0 in *__GI_abort () at abort.c:92
 
#6  0x00007f2fe6d26754 in ib_logf (level=IB_LOG_LEVEL_FATAL, format=0x7f2fe7430398 "Tablespace id %ld encrypted but encryption service not available. Can't continue opening tablespace.\n") at 10.1/storage/xtradb/handler/ha_innodb.cc:21064
 
#7  0x00007f2fe6f6d360 in fil_read_first_page (data_file=7, one_read_already=0, flags=0x7ffece033e08, space_id=0x7ffece033e10, min_flushed_lsn=0x7ffece036638, max_flushed_lsn=0x7ffece036640, orig_space_id=18446744073709551615, crypt_data=0x7ffece033e18) at 10.1/storage/xtradb/fil/fil0fil.cc:2041
 
#8  0x00007f2fe6e6c395 in open_or_create_data_files (create_new_db=0x7ffece036630, min_arch_log_no=0x7ffece036648, max_arch_log_no=0x7ffece036650, min_flushed_lsn=0x7ffece036638, max_flushed_lsn=0x7ffece036640, sum_of_new_sizes=0x7ffece036658) at 10.1/storage/xtradb/srv/srv0start.cc:1062
 
#9  0x00007f2fe6e6e151 in innobase_start_or_create_for_mysql () at 10.1/storage/xtradb/srv/srv0start.cc:2180
 
#10 0x00007f2fe6d09772 in innobase_init (p=0x7f2fe354f070) at 10.1/storage/xtradb/handler/ha_innodb.cc:4083
 
#11 0x00007f2fe6b5c8b4 in ha_initialize_handlerton (plugin=0x7f2fe353c6e8) at 10.1/sql/handler.cc:512
 
#12 0x00007f2fe6944bd8 in plugin_initialize (tmp_root=0x7ffece03a2e0, plugin=0x7f2fe353c6e8, argc=0x7f2fe7c18950, argv=0x7f2fe341e8c0, options_only=false) at 10.1/sql/sql_plugin.cc:1403
 
#13 0x00007f2fe69457aa in plugin_init (argc=0x7f2fe7c18950, argv=0x7f2fe341e8c0, flags=2) at 10.1/sql/sql_plugin.cc:1676
 
#14 0x00007f2fe6867627 in init_server_components () at 10.1/sql/mysqld.cc:5041
 
#15 0x00007f2fe6868768 in mysqld_main (argc=16, argv=0x7f2fe341e8c0) at 10.1/sql/mysqld.cc:5631
 
#16 0x00007f2fe685e340 in main (argc=11, argv=0x7ffece03b028) at 10.1/sql/main.cc:25

It happens e.g. in this case (close to the initially described scenario):

  • start server on a new clean datadir with 

    plugin-load-add=file_key_management.so
    		 
    file_key_management_filename=<file>
    		 
    innodb-encrypt-tables
    		 
    innodb-encryption-threads = 4

  • shutdown the server
  • start the server on the same datadir with the same config plus some unknown variable, e.g. --innodb-unknown
    => instead of going down nicely with the "unknown variable" error, it aborts with the assertion failure above.

See also MDEV-8021

Comment by Sergei Golubchik [ 2015-05-09 ]

This seems a mix of documentation issues (already fixed) and various effect of MDEV-8021 (also fixed). Thus I'm closing it. Please reopen or comment if I'm wrong and this MDEV includes more issues that need to be fixed.

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