[MDEV-31819] innodb-force-recovery=6 crashes server when setting variables innodb_encryption_rotate_key_age and innodb_encryption_rotation_iops Created: 2023-08-01  Updated: 2023-11-28

Status: Open
Project: MariaDB Server
Component/s: None
Affects Version/s: 10.4, 10.5, 10.6, 10.9, 10.10, 10.11, 11.0, 11.1, 11.2
Fix Version/s: 10.4, 10.5, 10.6, 10.11, 11.0, 11.1

Type: Bug Priority: Major
Reporter: Ramesh Sivaraman Assignee: Marko Mäkelä
Resolution: Unresolved Votes: 0
Labels: None


 Description   

Test case 1
# # mysqld options required for replay:  --innodb-force-recovery=6
SET GLOBAL innodb_encryption_rotation_iops=1;
 
Test case 2
# mysqld options required for replay:  --innodb-force-recovery=6
SET GLOBAL innodb_encryption_rotate_key_age=1;

Leads to

10.[45] release build also crashes when running the above test cases

10.4.31 922db0642b6321ece41adb3232c1616812143573 (Optimized)

Core was generated by `/test/MD040723-mariadb-10.4.31-linux-x86_64-opt/bin/mariadbd --no-defaults --in'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  __GI___pthread_mutex_lock (mutex=mutex@entry=0x10)
    at ../nptl/pthread_mutex_lock.c:67
[Current thread is 1 (Thread 0x152780a5b700 (LWP 3415209))]
(gdb) bt
#0  __GI___pthread_mutex_lock (mutex=mutex@entry=0x10) at ../nptl/pthread_mutex_lock.c:67
#1  0x0000562470ce52ba in OSMutex::enter (this=0x10) at /test/10.4_opt/storage/innobase/include/sync0types.h:440
#2  os_event::set (this=0x0) at /test/10.4_opt/storage/innobase/os/os0event.cc:62
#3  os_event_set (event=0x0) at /test/10.4_opt/storage/innobase/os/os0event.cc:451
#4  0x0000562470e2f396 in fil_crypt_set_rotation_iops (val=<optimized out>) at /test/10.4_opt/storage/innobase/fil/fil0crypt.cc:2645
#5  0x0000562470c5bfc4 in innodb_encryption_rotation_iops_update (save=0x152760010090) at /test/10.4_opt/storage/innobase/handler/ha_innodb.cc:18616
#6  0x00005624707ef52f in sys_var_pluginvar::global_update (this=0x562472b13da0, thd=0x152760000c48, var=0x152760010070) at /test/10.4_opt/sql/sql_plugin.cc:3593
#7  0x000056247072dc31 in sys_var::update (this=0x562472b13da0, thd=0x152760000c48, var=0x152760010070) at /test/10.4_opt/sql/set_var.cc:208
#8  0x000056247072e11b in set_var::update (this=<optimized out>, thd=<optimized out>) at /test/10.4_opt/sql/set_var.cc:837
#9  0x000056247072f159 in sql_set_variables (thd=thd@entry=0x152760000c48, var_list=var_list@entry=0x1527600057c0, free=free@entry=true) at /test/10.4_opt/sql/set_var.cc:740
#10 0x00005624707e0a0a in mysql_execute_command (thd=0x152760000c48) at /test/10.4_opt/sql/sql_parse.cc:5045
#11 0x00005624707e55a2 in mysql_parse (thd=0x152760000c48, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_parse.cc:8008
#12 0x00005624707e8055 in dispatch_command (command=COM_QUERY, thd=0x152760000c48, packet=<optimized out>, packet_length=<optimized out>, is_com_multi=<optimized out>, is_next_command=<optimized out>) at /test/10.4_opt/sql/sql_class.h:1231
#13 0x00005624707e98af in do_command (thd=0x152760000c48) at /test/10.4_opt/sql/sql_parse.cc:1378
#14 0x00005624708d6dae in do_handle_one_connection (connect=<optimized out>) at /test/10.4_opt/sql/sql_connect.cc:1420
#15 0x00005624708d6e3d in handle_one_connection (arg=<optimized out>) at /test/10.4_opt/sql/sql_connect.cc:1324
#16 0x0000152799a4e609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#17 0x000015279963a133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

11.2.0 e81fa345020ec6a067583db6a7019d6404b26f93 (Debug)

Core was generated by `/test/MD270723-mariadb-11.2.0-linux-x86_64-dbg/bin/mariadbd --no-defaults --inn'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
[Current thread is 1 (Thread 0x145f49f14700 (LWP 3462722))]
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x0000145f694a0859 in __GI_abort () at abort.c:79
#2  0x000055c737446af6 in safe_mutex_lock (mp=mp@entry=0x55c738877ee0 <fil_crypt_threads_mutex>, my_flags=my_flags@entry=0, file=file@entry=0x55c737891f88 "/test/11.2_dbg/storage/innobase/fil/fil0crypt.cc", line=line@entry=2183) at /test/11.2_dbg/mysys/thr_mutex.c:245
#3  0x000055c73735ebaa in inline_mysql_mutex_lock (src_line=2183, src_file=0x55c737891f88 "/test/11.2_dbg/storage/innobase/fil/fil0crypt.cc", that=0x55c738877ee0 <fil_crypt_threads_mutex>) at /test/11.2_dbg/include/mysql/psi/mysql_thread.h:750
#4  fil_crypt_set_rotate_key_age (val=1) at /test/11.2_dbg/storage/innobase/fil/fil0crypt.cc:2183
#5  0x000055c73701d601 in innodb_encryption_rotate_key_age_update (save=0x145f34013458) at /test/11.2_dbg/storage/innobase/handler/ha_innodb.cc:18493
#6  0x000055c736a5490d in sys_var_pluginvar::global_update (this=0x55c7397f3cb0, thd=0x145f34000d48, var=0x145f34013438) at /test/11.2_dbg/sql/sql_plugin.cc:3635
#7  0x000055c736955ae0 in sys_var::update (this=0x55c7397f3cb0, thd=0x145f34000d48, var=0x145f34013438) at /test/11.2_dbg/sql/set_var.cc:207
#8  0x000055c736956023 in set_var::update (this=<optimized out>, thd=<optimized out>) at /test/11.2_dbg/sql/set_var.cc:864
#9  0x000055c73695724a in sql_set_variables (thd=thd@entry=0x145f34000d48, var_list=var_list@entry=0x145f34005fe8, free=free@entry=true) at /test/11.2_dbg/sql/set_var.cc:746
#10 0x000055c736a3977a in mysql_execute_command (thd=thd@entry=0x145f34000d48, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/11.2_dbg/sql/sql_parse.cc:4803
#11 0x000055c736a2573b in mysql_parse (thd=thd@entry=0x145f34000d48, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x145f49f132c0) at /test/11.2_dbg/sql/sql_parse.cc:7800
#12 0x000055c736a32c00 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x145f34000d48, packet=packet@entry=0x145f3400af49 "SET GLOBAL innodb_encryption_rotate_key_age=1", packet_length=packet_length@entry=45, blocking=blocking@entry=true) at /test/11.2_dbg/sql/sql_class.h:1374
#13 0x000055c736a350b8 in do_command (thd=0x145f34000d48, blocking=blocking@entry=true) at /test/11.2_dbg/sql/sql_parse.cc:1405
#14 0x000055c736b9a717 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55c739a2dcc8, put_in_cache=put_in_cache@entry=true) at /test/11.2_dbg/sql/sql_connect.cc:1445
#15 0x000055c736b9abe6 in handle_one_connection (arg=0x55c739a2dcc8) at /test/11.2_dbg/sql/sql_connect.cc:1347
#16 0x0000145f699b1609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#17 0x0000145f6959d133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.4.31 (dbg), 10.4.31 (opt), 10.5.22 (opt), 10.5.22 (dbg), 10.6.15 (dbg), 10.9.8 (dbg), 10.10.6 (dbg), 10.11.4 (dbg), 11.0.2 (dbg), 11.1.2 (dbg), 11.2.0 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.6.15 (opt), 10.9.8 (opt), 10.10.6 (opt), 10.11.4 (opt), 10.11.5 (dbg), 10.11.5 (opt), 11.0.2 (opt), 11.1.2 (opt), 11.2.0 (opt)



 Comments   
Comment by Ramesh Sivaraman [ 2023-08-01 ]

Unique IDs

SIGABRT|safe_mutex_lock|inline_mysql_mutex_lock|fil_crypt_set_rotate_key_age|innodb_encryption_rotate_key_age_update
SIGABRT|safe_mutex_lock|inline_mysql_mutex_lock|fil_crypt_set_rotation_iops|innodb_encryption_rotation_iops_update
SIGSEGV|OSMutex::enter|os_event::set|os_event_set|fil_crypt_set_rotate_key_age
SIGSEGV|OSMutex::enter|os_event::set|os_event_set|fil_crypt_set_rotation_iops
SIGSEGV|__GI___pthread_mutex_lock|OSMutex::enter|os_event::set|os_event_set

Comment by Marko Mäkelä [ 2023-08-01 ]

I believe that in these code paths, we are missing a check for high_level_read_only.

The sole purpose of innodb_force_recovery=6 is to allow any data to be resurrected from a seriously corrupted database. Also if innodb_read_only=ON we must not modify any persistent InnoDB data pages.

Generated at Thu Feb 08 10:26:42 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.