[MDEV-12863] No table can be created after second encryption plugin attempted to load - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.1.23
Fix Version/s: 10.1.26, 10.2.8
Component/s: Encryption
Labels:
None

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

Attachments

Issue Links

relates to

MDEV-9948 Failing assertion: new_state->key_version != ENCRYPTION_KEY_VERSION_INVALID in fil0crypt.cc

Closed

Activity

Ascending order - Click to sort in descending order

Andrii Nikitin (Inactive) added a comment - 2017-05-22 10:13 - edited

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)

Andrii Nikitin (Inactive) added a comment - 2017-05-22 10:13 - edited 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)

Andrii Nikitin (Inactive) added a comment - 2017-05-22 10:36

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.

Andrii Nikitin (Inactive) added a comment - 2017-05-22 10:36 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.

Elena Stepanova added a comment - 2017-05-22 11:29

Possibly related to ~~MDEV-9948~~

Elena Stepanova added a comment - 2017-05-22 11:29 Possibly related to MDEV-9948

Jan Lindström (Inactive) added a comment - 2017-07-26 04:07

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

Jan Lindström (Inactive) added a comment - 2017-07-26 04:07 install plugin for encryption plugins should be disabled and allow setting it only on startup. Fixing this inside a InnoDB is out of reach.

MariaDB Server

No table can be created after second encryption plugin attempted to load

Details

Description

Attachments

Issue Links

Activity

People

Dates

Git Integration