[MDEV-12863] No table can be created after second encryption plugin attempted to load Created: 2017-05-22  Updated: 2017-08-14  Resolved: 2017-08-14

Status: Closed
Project: MariaDB Server
Component/s: Encryption
Affects Version/s: 10.1.23
Fix Version/s: 10.1.26, 10.2.8

Type: Bug Priority: Major
Reporter: Andrii Nikitin (Inactive) Assignee: Sergei Golubchik
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-9948 Failing assertion: new_state->key_ver... Closed

 Description   

The error below happens after attempt to load second encryption plugin (in any order tried aws_key_management, file_key_management and debug_key_management)

MariaDB [test]> select * from information_schema.plugins where plugin_type='encryption';
 
+---------------------+----------------+---------------+-------------+---------------------+------------------------+------------------------+------------------------+----------------------------------+----------------+-------------+-----------------+---------------------+
 
| PLUGIN_NAME         | PLUGIN_VERSION | PLUGIN_STATUS | PLUGIN_TYPE | PLUGIN_TYPE_VERSION | PLUGIN_LIBRARY         | PLUGIN_LIBRARY_VERSION | PLUGIN_AUTHOR          | PLUGIN_DESCRIPTION               | PLUGIN_LICENSE | LOAD_OPTION | PLUGIN_MATURITY | PLUGIN_AUTH_VERSION |
 
+---------------------+----------------+---------------+-------------+---------------------+------------------------+------------------------+------------------------+----------------------------------+----------------+-------------+-----------------+---------------------+
 
| file_key_management | 1.0            | ACTIVE        | ENCRYPTION  | 3.0                 | file_key_management.so | 1.13                   | Denis Endro eperi GmbH | File-based key management plugin | GPL            | ON          | Stable          | 1.0                 |
 
+---------------------+----------------+---------------+-------------+---------------------+------------------------+------------------------+------------------------+----------------------------------+----------------+-------------+-----------------+---------------------+
 
 
 
MariaDB [test]> create table a(i int)  engine=innodb;
 
Query OK, 0 rows affected (0.22 sec)
 
 
 
MariaDB [test]> drop table a;
 
Query OK, 0 rows affected (0.10 sec)
 
 
 
MariaDB [test]> install plugin debug_key_management soname 'debug_key_management.so';
 
ERROR 1123 (HY000): Can't initialize function 'debug_key_management'; Plugin initialization function failed.
 
MariaDB [test]> create table a(i int)  engine=innodb;
 
ERROR 1005 (HY000): Can't create table `test`.`a` (errno: 140 "Wrong create options")

Error log has only this message startup:

Version: '10.1.24-MariaDB'  socket: '/home/a/test1/dt/my.sock'  port: 3311  Source distribution
 
2017-05-22 11:34:52 140430689876736 [ERROR] Plugin 'debug_key_management' registration as a ENCRYPTION failed.

Similar problem happens when attempting to install database with incorrect option

 /usr/local/mysql/scripts/mysql_install_db --no-defaults --basedir=/usr/local/mysql --plugin-load-add=file_key_management --file-key-management-filename=$(pwd)/mysql-test/std_data/keys.txt --innodb-encrypt-tables --innodb-encrypt-log --plugin_load_add=debug_key_management 
 
 
2017-05-22 11:20:30 140644433411008 [ERROR] Plugin 'file_key_management' registration as a ENCRYPTION failed.
 
2017-05-22 11:20:30 140644433411008 [Note] InnoDB: Using mutexes to ref count buffer pool pages
 
2017-05-22 11:20:30 140644433411008 [Note] InnoDB: The InnoDB memory heap is disabled
 
2017-05-22 11:20:30 140644433411008 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2017-05-22 11:20:30 140644433411008 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
 
2017-05-22 11:20:30 140644433411008 [Note] InnoDB: Compressed tables use zlib 1.2.8
 
2017-05-22 11:20:30 140644433411008 [Note] InnoDB: Using Linux native AIO
 
2017-05-22 11:20:30 140644433411008 [Note] InnoDB: Using SSE crc32 instructions
 
2017-05-22 11:20:30 140644433411008 [Note] InnoDB: Initializing buffer pool, size = 128.0M
 
2017-05-22 11:20:30 140644433411008 [Note] InnoDB: Completed initialization of buffer pool
 
2017-05-22 11:20:30 140644433411008 [Note] InnoDB: The first specified data file ./ibdata1 did not exist: a new database to be created!
 
2017-05-22 11:20:30 140644433411008 [Note] InnoDB: Setting file ./ibdata1 size to 12 MB
 
2017-05-22 11:20:30 140644433411008 [Note] InnoDB: Setting log file ./ib_logfile101 size to 48 MB
 
2017-05-22 11:20:31 140644433411008 [Note] InnoDB: Setting log file ./ib_logfile1 size to 48 MB
 
2017-05-22 11:20:32 140644433411008 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
 
2017-05-22 11:20:32 140644433411008 [Warning] InnoDB: New log files created, LSN=45883
 
2017-05-22 11:20:32 140644433411008 [Note] InnoDB: Doublewrite buffer not found: creating new
 
2017-05-22 11:20:32 140644433411008 [Note] InnoDB: Doublewrite buffer created
 
2017-05-22 11:20:32 140644433411008 [Note] InnoDB: 128 rollback segment(s) are active.
 
2017-05-22 11:20:32 140644433411008 [Warning] InnoDB: Creating foreign key constraint system tables.
 
2017-05-22 11:20:32 140644433411008 [Note] InnoDB: Foreign key constraint system tables created
 
2017-05-22 11:20:32 140644433411008 [Note] InnoDB: Creating tablespace and datafile system tables.
 
2017-05-22 11:20:32 140644433411008 [Note] InnoDB: Tablespace and datafile system tables created.
 
2017-05-22 11:20:32 140644433411008 [Note] InnoDB: Waiting for purge to start
 
2017-05-22 11:20:32 140644433411008 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.35-80.0 started; log sequence number 0
 
2017-05-22 11:20:32 140643716298496 [Note] InnoDB: Dumping buffer pool(s) not yet started
 
ERROR: 1005  Can't create table `mysql`.`innodb_table_stats` (errno: 140 "Wrong create options")
 
2017-05-22 11:20:33 140644433411008 [ERROR] Aborting



 Comments   
Comment by Andrii Nikitin (Inactive) [ 2017-05-22 ] 

MariaDB [test]> create table a(i int)  engine=innodb;
 
ERROR 1005 (HY000): Can't create table `test`.`a` (errno: 140 "Wrong create options")
 
MariaDB [test]> show warnings\G
 
*************************** 1. row ***************************
 
  Level: Warning
 
   Code: 140
 
Message: InnoDB: ENCRYPTION_KEY_ID 1 not available
 
*************************** 2. row ***************************
 
  Level: Error
 
   Code: 1005
 
Message: Can't create table `test`.`a` (errno: 140 "Wrong create options")
 
*************************** 3. row ***************************
 
  Level: Warning
 
   Code: 1030
 
Message: Got error 140 "Wrong create options" from storage engine InnoDB
 
3 rows in set (0.00 sec)

Comment by Andrii Nikitin (Inactive) [ 2017-05-22 ]

Other strange side effects happen as well, I think they should be fixed as part of this bug, but let me know if dedicated report is required:

  • variable innodb_encrypt_tables becomes unmodifiable:

MariaDB [(none)]> set global innodb_encrypt_tables = 1;
 
Query OK, 0 rows affected (0.00 sec)
 
 
 
MariaDB [(none)]> set global innodb_encrypt_tables = 'ON';
 
Query OK, 0 rows affected (0.00 sec)
 
 
 
MariaDB [(none)]> install plugin debug_key_management soname 'debug_key_management.so';
 
ERROR 1123 (HY000): Can't initialize function 'debug_key_management'; Plugin initialization function failed.
 
MariaDB [(none)]> set global innodb_encrypt_tables = 'ON';
 
ERROR 1231 (42000): Variable 'innodb_encrypt_tables' can't be set to the value of 'ON'

  • server crashes at shutdown:

# mysqladmin shutdown
 
*** stack smashing detected ***: /home/a/test1/build/sql//mysqld terminated
 
# tail -n 40 dt/error.log
 
2017-05-22 12:28:18 139672664271616 [Note] Event Scheduler: Purging the queue. 0 events
 
2017-05-22 12:28:18 139671933781760 [Note] InnoDB: FTS optimize thread exiting.
 
2017-05-22 12:28:18 139672664271616 [Note] InnoDB: Starting shutdown...
 
170522 12:28:19 [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.24-MariaDB
 
key_buffer_size=134217728
 
read_buffer_size=131072
 
max_used_connections=1
 
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 = 467121 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x0
 
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 0x48400
 
/home/a/test1/build/sql//mysqld(my_print_stacktrace+0x29)[0x55f7eb04f9d9]
 
/home/a/test1/build/sql//mysqld(handle_fatal_signal+0x3ad)[0x55f7eac342ed]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x11630)[0x7f0812457630]
 
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x9f)[0x7f0811a237ef]
 
/lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7f0811a253ea]
 
/lib/x86_64-linux-gnu/libc.so.6(+0x790d0)[0x7f0811a670d0]
 
/lib/x86_64-linux-gnu/libc.so.6(__fortify_fail+0x54)[0x7f0811b082c4]
 
/lib/x86_64-linux-gnu/libc.so.6(__fortify_fail+0x0)[0x7f0811b08270]
 
mysys/stacktrace.c:268(my_print_stacktrace)[0x55f7eaeb6660]
 
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
 
information that should help you find out what is causing the crash.

Comment by Elena Stepanova [ 2017-05-22 ]

Possibly related to MDEV-9948

Comment by Jan Lindström (Inactive) [ 2017-07-26 ]

install plugin for encryption plugins should be disabled and allow setting it only on startup. Fixing this inside a InnoDB is out of reach.

Generated at Thu Feb 08 08:01:04 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.