[MDEV-17232] error codes when decryption fails depend on innodb-stats-persistent Created: 2018-09-18  Updated: 2021-10-25  Resolved: 2021-10-25

Status: Closed
Project: MariaDB Server
Component/s: Encryption, Storage Engine - InnoDB, Tests
Affects Version/s: 10.2
Fix Version/s: 10.2.24

Type: Bug Priority: Major
Reporter: Robert Golebiowski Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: None


 Description   

There different error codes generated when table cannot be encrypted and innodb-stats-persistent is ON/OFF:

CURRENT_TEST: encryption.innodb-bad-key-change
mysqltest: At line 45: query 'SELECT * FROM t1' failed with wrong errno 1296: 'Got error 192 'Table encrypted but decryption failed. This could be because correct encryption management plugin is not loaded, used encryption key is not available or encryption method does not match.' from InnoDB', instead of 1932...

To see the error change innodb-stats-persistent to ON in innodb-bad-key-change.test

 Comments   
Comment by Elena Stepanova [ 2018-09-18 ]

It appears to be fixed in 10.3, but 10.2 does indeed produces the error above, and morever, the debug build fails on an assertion:

perl ./mtr encryption.innodb-bad-key-change --mysqld=--innodb-stats-persistent=on

10.2 bd7c31621f

 
mysqld: /data/src/10.2/storage/innobase/include/ut0byte.ic:109: void* ut_align_down(const void*, ulint): Assertion `ptr' failed.
 
180918 21:19:11 [ERROR] mysqld got signal 6 ;
 
 
 
#7  0x00007f559406cee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
 
#8  0x000055acf2ddc3e3 in ut_align_down (ptr=0x0, align_no=16384) at /data/src/10.2/storage/innobase/include/ut0byte.ic:109
 
#9  0x000055acf2e0a6c3 in page_align (ptr=0x0) at /data/src/10.2/storage/innobase/include/page0page.h:180
 
#10 0x000055acf2e4a1a9 in page_rec_check (rec=0x0) at /data/src/10.2/storage/innobase/include/page0page.ic:564
 
#11 0x000055acf2e57977 in page_rec_is_infimum (rec=0x0) at /data/src/10.2/storage/innobase/include/page0page.ic:334
 
#12 0x000055acf302c5c9 in btr_estimate_n_rows_in_range_low (index=0x7f5534135838, tuple1=0x7f5534135208, mode1=PAGE_CUR_GE, tuple2=0x7f5534135280, mode2=PAGE_CUR_G, nth_attempt=1) at /data/src/10.2/storage/innobase/btr/btr0cur.cc:5696
 
#13 0x000055acf302d073 in btr_estimate_n_rows_in_range (index=0x7f5534135838, tuple1=0x7f5534135208, mode1=PAGE_CUR_GE, tuple2=0x7f5534135280, mode2=PAGE_CUR_G) at /data/src/10.2/storage/innobase/btr/btr0cur.cc:6020
 
#14 0x000055acf2df9266 in ha_innobase::records_in_range (this=0x7f5534134308, keynr=1, min_key=0x7f558c2cb8f0, max_key=0x7f558c2cb910) at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:13655
 
#15 0x000055acf29f6dfe in handler::multi_range_read_info_const (this=0x7f5534134308, keyno=1, seq=0x7f558c2cba90, seq_init_param=0x7f558c2cbac0, n_ranges_arg=0, bufsz=0x7f558c2cb994, flags=0x7f558c2cb990, cost=0x7f558c2cc0c0) at /data/src/10.2/sql/multi_range_read.cc:107
 
#16 0x000055acf29fa0ec in DsMrr_impl::dsmrr_info_const (this=0x7f5534134738, keyno=1, seq=0x7f558c2cba90, seq_init_param=0x7f558c2cbac0, n_ranges=0, bufsz=0x7f558c2cc050, flags=0x7f558c2cc04c, cost=0x7f558c2cc0c0) at /data/src/10.2/sql/multi_range_read.cc:1470
 
#17 0x000055acf2e05b14 in ha_innobase::multi_range_read_info_const (this=0x7f5534134308, keyno=1, seq=0x7f558c2cba90, seq_init_param=0x7f558c2cbac0, n_ranges=0, bufsz=0x7f558c2cc050, flags=0x7f558c2cc04c, cost=0x7f558c2cc0c0) at /data/src/10.2/storage/innobase/handler/ha_innodb.cc:21292
 
#18 0x000055acf2c341d2 in check_quick_select (param=0x7f558c2cc270, idx=0, index_only=false, tree=0x7f553402afc8, update_tbl_stats=true, mrr_flags=0x7f558c2cc04c, bufsize=0x7f558c2cc050, cost=0x7f558c2cc0c0) at /data/src/10.2/sql/opt_range.cc:10361
 
#19 0x000055acf2c2bb85 in get_key_scans_params (param=0x7f558c2cc270, tree=0x7f553402af40, index_read_must_be_used=false, update_tbl_stats=true, read_time=3.3000000000000003) at /data/src/10.2/sql/opt_range.cc:6797
 
#20 0x000055acf2c222eb in SQL_SELECT::test_quick_select (this=0x7f5534014f58, thd=0x7f5534000b00, keys_to_use=..., prev_tables=0, limit=18446744073709551615, force_quick_range=false, ordered_output=false, remove_false_parts_of_where=true) at /data/src/10.2/sql/opt_range.cc:2585
 
#21 0x000055acf28a9249 in get_quick_record_count (thd=0x7f5534000b00, select=0x7f5534014f58, table=0x7f5534133700, keys=0x7f5534013fc0, limit=18446744073709551615) at /data/src/10.2/sql/sql_select.cc:3841
 
#22 0x000055acf28ab6cb in make_join_statistics (join=0x7f5534013118, tables_list=..., keyuse_array=0x7f5534013408) at /data/src/10.2/sql/sql_select.cc:4463
 
#23 0x000055acf28a1645 in JOIN::optimize_inner (this=0x7f5534013118) at /data/src/10.2/sql/sql_select.cc:1580
 
#24 0x000055acf289fb29 in JOIN::optimize (this=0x7f5534013118) at /data/src/10.2/sql/sql_select.cc:1115
 
#25 0x000055acf28a8f92 in mysql_select (thd=0x7f5534000b00, tables=0x7f5534012718, wild_num=1, fields=..., conds=0x7f5534012ed8, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7f55340130f8, unit=0x7f55340046e0, select_lex=0x7f5534004e18) at /data/src/10.2/sql/sql_select.cc:3790
 
#26 0x000055acf289d2dd in handle_select (thd=0x7f5534000b00, lex=0x7f5534004618, result=0x7f55340130f8, setup_tables_done_option=0) at /data/src/10.2/sql/sql_select.cc:376
 
#27 0x000055acf2868945 in execute_sqlcom_select (thd=0x7f5534000b00, all_tables=0x7f5534012718) at /data/src/10.2/sql/sql_parse.cc:6477
 
#28 0x000055acf285e8d6 in mysql_execute_command (thd=0x7f5534000b00) at /data/src/10.2/sql/sql_parse.cc:3484
 
#29 0x000055acf286c81f in mysql_parse (thd=0x7f5534000b00, rawbuf=0x7f5534012528 "SELECT * FROM t2 where b = 1", length=28, parser_state=0x7f558c2ce200, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:8011
 
#30 0x000055acf285a17a in dispatch_command (command=COM_QUERY, thd=0x7f5534000b00, packet=0x7f55340088e1 "SELECT * FROM t2 where b = 1", packet_length=28, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1824
 
#31 0x000055acf2858add in do_command (thd=0x7f5534000b00) at /data/src/10.2/sql/sql_parse.cc:1378
 
#32 0x000055acf29aab50 in do_handle_one_connection (connect=0x55acf5412200) at /data/src/10.2/sql/sql_connect.cc:1335
 
#33 0x000055acf29aa8dd in handle_one_connection (arg=0x55acf5412200) at /data/src/10.2/sql/sql_connect.cc:1241
 
#34 0x000055acf2dcea68 in pfs_spawn_thread (arg=0x55acf541cff0) at /data/src/10.2/storage/perfschema/pfs.cc:1862
 
#35 0x00007f5595d43494 in start_thread (arg=0x7f558c2cf700) at pthread_create.c:333
 
#36 0x00007f559412993f in clone () from /lib/x86_64-linux-gnu/libc.so.6

Comment by Marko Mäkelä [ 2021-10-25 ]

I cannot repeat the crash with anything recent. I do not see a fix in btr_estimate_n_rows_in_range_low() that could have fixed this. We are not checking whether the cursor is positioned on a record, after btr_cur_search_to_nth_level() returned. We are just asserting that it is, and that the pointed-to record is not the infimum pseudo-record.

I was able to build bd7c31621ff8f490866a5a5dfb1d99de35d062a4 using cmake -DWITH_MARIABACKUP:BOOL=OFF and the following tweaks:

(cd libmariadb;git checkout origin/3.1)
 
git add libmariadb
 
patch -p1<<EOF
 
diff --git a/cmake/plugin.cmake b/cmake/plugin.cmake
 
index 70b252c16b5..359882c4cef 100644
 
--- a/cmake/plugin.cmake
 
+++ b/cmake/plugin.cmake
 
@@ -13,6 +13,8 @@
 
 # along with this program; if not, write to the Free Software
 
 # Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA 
 
+CMAKE_POLICY(SET CMP0079 NEW)
 
+CMAKE_POLICY(SET CMP0002 OLD)
 
 
 INCLUDE(CMakeParseArguments)
 
 
EOF

With that revision, I can reproduce the problem:

10.2 bd7c31621ff8f490866a5a5dfb1d99de35d062a4

 
CURRENT_TEST: encryption.innodb-bad-key-change
 
mysqltest: At line 79: query 'SELECT * FROM t2 where b = 1' failed with wrong errno 2013: 'Lost connection to MySQL server during query', instead of 1296...
 
…
 
#2  0x000055d801080b14 in handle_fatal_signal (sig=11) at /mariadb/10.2o/sql/signal_handler.cc:305
 
#3  <signal handler called>
 
#4  0x000055d8014e0459 in page_cur_get_rec (cur=0x7f5d88f235d8) at /mariadb/10.2o/storage/innobase/include/page0cur.ic:93
 
#5  0x000055d8014f8cdf in btr_cur_get_rec (cursor=0x7f5d88f235d0) at /mariadb/10.2o/storage/innobase/include/btr0cur.ic:48
 
#6  btr_estimate_n_rows_in_range_low (index=index@entry=0x7f5d34133668, tuple1=tuple1@entry=0x7f5d3402b468, mode1=mode1@entry=PAGE_CUR_GE, tuple2=tuple2@entry=0x7f5d3402b4e0, mode2=PAGE_CUR_G, nth_attempt=nth_attempt@entry=1) at /mariadb/10.2o/storage/innobase/btr/btr0cur.cc:5696
 
#7  0x000055d8014f9519 in btr_estimate_n_rows_in_range (index=index@entry=0x7f5d34133668, tuple1=tuple1@entry=0x7f5d3402b468, mode1=mode1@entry=PAGE_CUR_GE, tuple2=tuple2@entry=0x7f5d3402b4e0, mode2=<optimized out>) at /mariadb/10.2o/storage/innobase/btr/btr0cur.cc:6019
 
#8  0x000055d8012b33c1 in ha_innobase::records_in_range (this=0x7f5d3413cfd0, keynr=<optimized out>, min_key=<optimized out>, max_key=0x7f5d88f27cc0) at /mariadb/10.2o/storage/innobase/handler/ha_innodb.cc:13654
 
#9  0x000055d800fcb84c in handler::multi_range_read_info_const (this=0x7f5d3413cfd0, keyno=keyno@entry=1, seq=0x7f5d88f27df0, seq_init_param=<optimized out>, n_ranges_arg=<optimized out>, bufsz=bufsz@entry=0x7f5d88f27d4c, flags=0x7f5d88f27d48, cost=0x7f5d88f28400) at /mariadb/10.2o/sql/multi_range_read.cc:107

I was not able to repeat this with mariadb-10.2.24 or mariadb-10.2.25, but it does repeat with mariadb-10.2.22 and mariadb-10.2.23.

I tried to narrowed this further down. The parent commit of the fix of MDEV-14398 does not crash. There were many other changes to the handling of encrypted pages in that release. For the record, the oldest commit after mariadb-10.2.24 that I tested (and which did not crash) was 71f9552fd83ad155d541b2c2aa7c835f93cc47d3.

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