Details
-
Type:
Bug
-
Status: Closed
-
Priority:
Major
-
Resolution: Fixed
-
Affects Version/s: 10.1.4
-
Fix Version/s: 10.1.5
-
Component/s: Encryption, Storage Engine - InnoDB
-
Labels:
-
Environment:CentOS 7 64 Bit
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…
Gliffy Diagrams
Attachments
Issue Links
- relates to
-
-
- Closed
-
Activity
- All
- Comments
- Work Log
- History
- Activity
- Transitions
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
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
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
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.
Thanks for the report.
Regarding documentation issues, I updated the KB page
a) changed innodb-encrypt-logs to innodb-encrypt-log (as Sergei Golubchik 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.