[MDEV-8724] Assertion `rc == 0' failed in ma_decrypt on reading an Aria table - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.1(EOL)
Fix Version/s: 10.1.11
Component/s: Encryption, Storage Engine - Aria
Labels:
None

Sprint:
10.1.11

Description

Comment

Test flow:

- start server with key file containing key 1;
- create an encrypted Aria table, insert some data;
- restart server without key 1;
- repair the table (it appears to be corrupted, repair deletes the data);
- insert some more data;
- restart again with key 1;
- try to read from the table
=> assertion failure

Test case
--exec echo "wait" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
--shutdown_server
--source include/wait_until_disconnected.inc

--write_file $MYSQLTEST_VARDIR/keys1.txt
1;770A8A65DA156D24EE2A093277530142
EOF

--exec echo "restart:--aria-encrypt-tables=1 --plugin-load-add=file_key_management.so --file-key-management --file-key-management-filename=$MYSQLTEST_VARDIR/keys1.txt" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
--enable_reconnect
--source include/wait_until_connected_again.inc

CREATE TABLE t1 (i INT, KEY(i)) ENGINE=Aria;
INSERT INTO t1 VALUES (1);

--exec echo "wait" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
--shutdown_server
--source include/wait_until_disconnected.inc

--write_file $MYSQLTEST_VARDIR/keys2.txt
2;770A8A65DA156D24EE2A093277530143
EOF

--exec echo "restart:--aria-encrypt-tables=1 --plugin-load-add=file_key_management.so --file-key-management --file-key-management-filename=$MYSQLTEST_VARDIR/keys2.txt" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
--enable_reconnect
--source include/wait_until_connected_again.inc

repair table t1;

INSERT INTO t1 VALUES (2);

--exec echo "wait" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
--shutdown_server
--source include/wait_until_disconnected.inc

--exec echo "restart:--aria-encrypt-tables=1 --plugin-load-add=file_key_management.so --file-key-management --file-key-management-filename=$MYSQLTEST_VARDIR/keys1.txt" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
--enable_reconnect
--source include/wait_until_connected_again.inc

select * from t1;

10.1/storage/maria/ma_crypt.c:493: ma_decrypt: Assertion `rc == 0' failed.

150901 19:49:25 [ERROR] mysqld got signal 6 ;

Stack trace from 10.1 8ea9b8c0b168b3e5aad08886477d8726531abcd5
#6 0x00007fdfce578311 in *__GI___assert_fail (assertion=0x7fdfd1a5268b "rc == 0", file=<optimized out>, line=493, function=0x7fdfd1a526d8 "ma_decrypt") at assert.c:81
#7 0x00007fdfd15fdcbc in ma_decrypt (crypt_data=0x7fdfc5631230, src=0x7fdfc5581080 "", dst=0x7fdfc7804080 "", size=8172, pageno=1, lsn=4294976334, key_version=0) at 10.1/storage/maria/ma_crypt.c:493
#8 0x00007fdfd15fd27c in ma_crypt_data_post_read_hook (res=0, args=0x7fdfd0957680) at 10.1/storage/maria/ma_crypt.c:230
#9 0x00007fdfd15eacd2 in read_block (pagecache=0x7fdfd2a4c560, block=0x7fdfc80601b0, primary=1 '\001') at 10.1/storage/maria/ma_pagecache.c:2720
#10 0x00007fdfd15ec2d3 in pagecache_read (pagecache=0x7fdfd2a4c560, file=0x7fdfc563d498, pageno=1, level=0, buff=0x7fdfc563a070 "\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245\245"..., type=PAGECACHE_LSN_PAGE, lock=PAGECACHE_LOCK_LEFT_UNLOCKED, page_link=0x7fdfd0957740) at 10.1/storage/maria/ma_pagecache.c:3396
#11 0x00007fdfd163562b in _ma_scan_block_record (info=0x7fdfc563d070, record=0x7fdfcdc16388 "\377\217\217\217\217\245\245\245\377\245\245\245\245\245\245\245\250c\301\315\337\177", record_pos=0, skip_deleted=1 '\001') at 10.1/storage/maria/ma_blockrec.c:5501
#12 0x00007fdfd161bf91 in maria_scan (info=0x7fdfc563d070, record=0x7fdfcdc16388 "\377\217\217\217\217\245\245\245\377\245\245\245\245\245\245\245\250c\301\315\337\177") at 10.1/storage/maria/ma_scan.c:54
#13 0x00007fdfd15c62e4 in ha_maria::rnd_next (this=0x7fdfc547d088, buf=0x7fdfcdc16388 "\377\217\217\217\217\245\245\245\377\245\245\245\245\245\245\245\250c\301\315\337\177") at 10.1/storage/maria/ha_maria.cc:2445
#14 0x00007fdfd10ee356 in handler::ha_rnd_next (this=0x7fdfc547d088, buf=0x7fdfcdc16388 "\377\217\217\217\217\245\245\245\377\245\245\245\245\245\245\245\250c\301\315\337\177") at 10.1/sql/handler.cc:2581
#15 0x00007fdfd10ef6d7 in handler::read_first_row (this=0x7fdfc547d088, buf=0x7fdfcdc16388 "\377\217\217\217\217\245\245\245\377\245\245\245\245\245\245\245\250c\301\315\337\177", primary_key=64) at 10.1/sql/handler.cc:2776
#16 0x00007fdfd0f32c3f in handler::ha_read_first_row (this=0x7fdfc547d088, buf=0x7fdfcdc16388 "\377\217\217\217\217\245\245\245\377\245\245\245\245\245\245\245\250c\301\315\337\177", primary_key=64) at 10.1/sql/sql_class.h:5378
#17 0x00007fdfd0f1d642 in join_read_system (tab=0x7fdfc54e5048) at 10.1/sql/sql_select.cc:18624
#18 0x00007fdfd0f1d249 in join_read_const_table (thd=0x7fdfc7472070, tab=0x7fdfc54e5048, pos=0x7fdfc54e5598) at 10.1/sql/sql_select.cc:18520
#19 0x00007fdfd0ef8a31 in make_join_statistics (join=0x7fdfc54e4948, tables_list=..., keyuse_array=0x7fdfc54e4c48) at 10.1/sql/sql_select.cc:3668
#20 0x00007fdfd0ef07a7 in JOIN::optimize_inner (this=0x7fdfc54e4948) at 10.1/sql/sql_select.cc:1358
#21 0x00007fdfd0eef65e in JOIN::optimize (this=0x7fdfc54e4948) at 10.1/sql/sql_select.cc:1021
#22 0x00007fdfd0ef7817 in mysql_select (thd=0x7fdfc7472070, rref_pointer_array=0x7fdfc74763d0, tables=0x7fdfc54e4268, wild_num=1, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7fdfc54e4928, unit=0x7fdfc7475a68, select_lex=0x7fdfc7476158) at 10.1/sql/sql_select.cc:3329
#23 0x00007fdfd0eed849 in handle_select (thd=0x7fdfc7472070, lex=0x7fdfc74759a0, result=0x7fdfc54e4928, setup_tables_done_option=0) at 10.1/sql/sql_select.cc:371
#24 0x00007fdfd0ebe02d in execute_sqlcom_select (thd=0x7fdfc7472070, all_tables=0x7fdfc54e4268) at 10.1/sql/sql_parse.cc:5832
#25 0x00007fdfd0eb41d4 in mysql_execute_command (thd=0x7fdfc7472070) at 10.1/sql/sql_parse.cc:2949
#26 0x00007fdfd0ec15ef in mysql_parse (thd=0x7fdfc7472070, rawbuf=0x7fdfc54e4088 "select * from t1", length=16, parser_state=0x7fdfd09591a0) at 10.1/sql/sql_parse.cc:7208
#27 0x00007fdfd0eb0373 in dispatch_command (command=COM_QUERY, thd=0x7fdfc7472070, packet=0x7fdfc9bc6071 "select * from t1", packet_length=16) at 10.1/sql/sql_parse.cc:1475
#28 0x00007fdfd0eaf099 in do_command (thd=0x7fdfc7472070) at 10.1/sql/sql_parse.cc:1097
#29 0x00007fdfd0fe31e9 in do_handle_one_connection (thd_arg=0x7fdfc7472070) at 10.1/sql/sql_connect.cc:1350
#30 0x00007fdfd0fe2f3a in handle_one_connection (arg=0x7fdfc7472070) at 10.1/sql/sql_connect.cc:1262
#31 0x00007fdfd15a774f in pfs_spawn_thread (arg=0x7fdfcdc235f0) at 10.1/storage/perfschema/pfs.cc:1860
#32 0x00007fdfd0593b50 in start_thread (arg=<optimized out>) at pthread_create.c:304
#33 0x00007fdfce62895d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112

Attachments

Activity

Ascending order - Click to sort in descending order

Michael Widenius added a comment - 2016-01-28 12:59

The assert happens because in debug mode we always crash if we found something that should not happen with encryption to make it easier to debug this.

I will fix this so that the assert only happens in debug builds if --debug-assert-on-error is set.

Michael Widenius added a comment - 2016-01-28 12:59 The assert happens because in debug mode we always crash if we found something that should not happen with encryption to make it easier to debug this. I will fix this so that the assert only happens in debug builds if --debug-assert-on-error is set.

Michael Widenius added a comment - 2016-01-28 14:07

Fix pushed to 10.1 tree.

Michael Widenius added a comment - 2016-01-28 14:07 Fix pushed to 10.1 tree.

Elena Stepanova added a comment - 2016-01-28 14:21

[1/28/16 14:08] <elenst> montywi: generally, "if we found something that should not happen" is kind of a definition of a bug
[1/28/16 14:09] <elenst> montywi: so, maybe if it really should not happen, better to keep the assert, and to make sure it does not happen when it should not?
[1/28/16 14:10] <elenst> i mean, seriously. If it can happen, there should be no assert, debug or not debug; and it it should not happen, the assert is valid, but the current behavior is not
[1/28/16 14:11] <elenst> hiding the assert conditionally only complicates the problem

Elena Stepanova added a comment - 2016-01-28 14:21 [1/28/16 14:08] <elenst> montywi: generally, "if we found something that should not happen" is kind of a definition of a bug [1/28/16 14:09] <elenst> montywi: so, maybe if it really should not happen, better to keep the assert, and to make sure it does not happen when it should not? [1/28/16 14:10] <elenst> i mean, seriously. If it can happen, there should be no assert, debug or not debug; and it it should not happen, the assert is valid, but the current behavior is not [1/28/16 14:11] <elenst> hiding the assert conditionally only complicates the problem

Michael Widenius added a comment - 2016-02-02 12:46

In this particular case the assert was for something that should never happen in normal operations, especially in our test environment (for which most of the asserts are done).

In normal operations, decryption an encryption shouldn't fail. It only failed in this case because of 'wrong usage' when someone wrongly changes a key to something else.

The --debug-assert-on-error flag is something that was proposed a couple a years ago to achieve a middle ground; Give an SQL error for things that could be caused by a user, even doing wrong things but an assert otherwise to make it easier to debug things.

The one thing we didn't do before was to have --debug-assert-on-error on as default for mysql-test-run. Maybe it's time to do that.

Michael Widenius added a comment - 2016-02-02 12:46 In this particular case the assert was for something that should never happen in normal operations, especially in our test environment (for which most of the asserts are done). In normal operations, decryption an encryption shouldn't fail. It only failed in this case because of 'wrong usage' when someone wrongly changes a key to something else. The --debug-assert-on-error flag is something that was proposed a couple a years ago to achieve a middle ground; Give an SQL error for things that could be caused by a user, even doing wrong things but an assert otherwise to make it easier to debug things. The one thing we didn't do before was to have --debug-assert-on-error on as default for mysql-test-run. Maybe it's time to do that.

MariaDB Server

Assertion `rc == 0' failed in ma_decrypt on reading an Aria table

Details

Description

Attachments

Activity

People

Dates

Git Integration