[MDEV-33101] Server crashes when starting the server with innodb-force-recovery=6 and enabling the innodb_truncate_temporary_tablespace_now variable. Created: 2023-12-21  Updated: 2024-01-05  Resolved: 2024-01-05

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 11.3, 11.4
Fix Version/s: 11.3.2, 11.4.1

Type: Bug Priority: Critical
Reporter: Ramesh Sivaraman Assignee: Debarun Banerjee
Resolution: Fixed Votes: 0
Labels: crash, regression

Issue Links:
Problem/Incident
is caused by MDEV-28699 Shrink temporary tablespaces without ... Closed

 Description   

Test case

# mysqld options required for replay:  --innodb-force-recovery=6
SET GLOBAL innodb_truncate_temporary_tablespace_now=1;

Leads to

11.3.2 bc6b6cf6a70b3ac99ead8971c25b2fd9702b0b49 (Optimized)

Core was generated by `/test/MD011223-mariadb-11.3.2-linux-x86_64-opt/bin/mariadbd --no-defaults --inn'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  srw_lock_impl<false>::wr_lock (line=988, 
    file=0x55c1ba5f79e8 "/test/11.3_opt/storage/innobase/include/fil0fil.h", 
    this=0xa0) at /test/11.3_opt/storage/innobase/include/srw_lock.h:521
[Current thread is 1 (Thread 0x151ab410a700 (LWP 3887626))]
(gdb) bt
#0  srw_lock_impl<false>::wr_lock (line=988, file=0x55c1ba5f79e8 "/test/11.3_opt/storage/innobase/include/fil0fil.h", this=0xa0) at /test/11.3_opt/storage/innobase/include/srw_lock.h:521
#1  fil_space_t::x_lock (this=0x0) at /test/11.3_opt/storage/innobase/include/fil0fil.h:988
#2  mtr_t::x_lock_space (space=0x0, this=0x151ab4108810) at /test/11.3_opt/storage/innobase/mtr/mtr0mtr.cc:807
#3  mtr_t::x_lock_space (this=this@entry=0x151ab4108810, space=space@entry=0x0) at /test/11.3_opt/storage/innobase/mtr/mtr0mtr.cc:799
#4  0x000055c1ba198255 in fsp_shrink_temp_space () at /test/11.3_opt/storage/innobase/fsp/fsp0fsp.cc:3765
#5  0x000055c1b9ffbcf8 in innodb_trunc_temp_space_update (save=<optimized out>) at /test/11.3_opt/storage/innobase/handler/ha_innodb.cc:18507
#6  innodb_trunc_temp_space_update (save=<optimized out>) at /test/11.3_opt/storage/innobase/handler/ha_innodb.cc:18502
#7  0x000055c1b9a910af in sys_var_pluginvar::global_update (this=0x55c1bcc1fe68, thd=0x151a88000c58, var=0x151a88010cd0) at /test/11.3_opt/sql/sql_plugin.cc:3699
#8  0x000055c1b99a7ffc in sys_var::update (this=0x55c1bcc1fe68, thd=0x151a88000c58, var=0x151a88010cd0) at /test/11.3_opt/sql/set_var.cc:207
#9  0x000055c1b99a84db in set_var::update (this=<optimized out>, thd=<optimized out>) at /test/11.3_opt/sql/set_var.cc:851
#10 0x000055c1b99a9619 in sql_set_variables (thd=thd@entry=0x151a88000c58, var_list=var_list@entry=0x151a88005eb0, free=free@entry=true) at /test/11.3_opt/sql/set_var.cc:733
#11 0x000055c1b9a7a6cb in mysql_execute_command (thd=0x151a88000c58, is_called_from_prepared_stmt=<optimized out>) at /test/11.3_opt/sql/sql_parse.cc:4786
#12 0x000055c1b9a67e96 in mysql_parse (thd=0x151a88000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/11.3_opt/sql/sql_parse.cc:7749
#13 0x000055c1b9a74415 in dispatch_command (command=COM_QUERY, thd=0x151a88000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/11.3_opt/sql/sql_class.h:1549
#14 0x000055c1b9a7665e in do_command (thd=0x151a88000c58, blocking=blocking@entry=true) at /test/11.3_opt/sql/sql_parse.cc:1406
#15 0x000055c1b9ba5f97 in do_handle_one_connection (connect=<optimized out>, put_in_cache=true) at /test/11.3_opt/sql/sql_connect.cc:1418
#16 0x000055c1b9ba62dd in handle_one_connection (arg=arg@entry=0x55c1bceeb048) at /test/11.3_opt/sql/sql_connect.cc:1320
#17 0x000055c1b9f4da3c in pfs_spawn_thread (arg=0x55c1bd004938) at /test/11.3_opt/storage/perfschema/pfs.cc:2201
#18 0x0000151ab5e57609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#19 0x0000151ab5a43133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

11.4.0 aed9c656a919b94c9451f8618a332f4ba421c21c (Debug)

Core was generated by `/test/MD191223-mariadb-11.4.0-linux-x86_64-dbg/bin/mariadbd --no-defaults --inn'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  mtr_t::x_lock_space (this=this@entry=0x14b76811d720, space=space@entry=0x0)
    at /test/11.4_dbg/storage/innobase/mtr/mtr0mtr.cc:821
821	  ut_ad(space->purpose == FIL_TYPE_TEMPORARY ||
[Current thread is 1 (Thread 0x14b76811f700 (LWP 3217785))]
(gdb) bt
#0  mtr_t::x_lock_space (this=this@entry=0x14b76811d720, space=space@entry=0x0) at /test/11.4_dbg/storage/innobase/mtr/mtr0mtr.cc:821
#1  0x0000556ad83bdbc4 in fsp_shrink_temp_space () at /test/11.4_dbg/storage/innobase/fsp/fsp0fsp.cc:3725
#2  0x0000556ad8057322 in innodb_trunc_temp_space_update (save=<optimized out>) at /test/11.4_dbg/storage/innobase/handler/ha_innodb.cc:18507
#3  0x0000556ad79ef337 in sys_var_pluginvar::global_update (this=0x556ada90c9a0, thd=0x14b740000d48, var=0x14b7400136d0) at /test/11.4_dbg/sql/sql_plugin.cc:3699
#4  0x0000556ad78e5000 in sys_var::update (this=0x556ada90c9a0, thd=0x14b740000d48, var=0x14b7400136d0) at /test/11.4_dbg/sql/set_var.cc:207
#5  0x0000556ad78e5543 in set_var::update (this=<optimized out>, thd=<optimized out>) at /test/11.4_dbg/sql/set_var.cc:851
#6  0x0000556ad78e6753 in sql_set_variables (thd=thd@entry=0x14b740000d48, var_list=var_list@entry=0x14b740006150, free=free@entry=true) at /test/11.4_dbg/sql/set_var.cc:733
#7  0x0000556ad79d26ab in mysql_execute_command (thd=thd@entry=0x14b740000d48, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/11.4_dbg/sql/sql_parse.cc:4786
#8  0x0000556ad79bd7d1 in mysql_parse (thd=thd@entry=0x14b740000d48, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14b76811e2b0) at /test/11.4_dbg/sql/sql_parse.cc:7748
#9  0x0000556ad79cb63b in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14b740000d48, packet=packet@entry=0x14b74000b1b9 "SET GLOBAL innodb_truncate_temporary_TABLESPACE_now=1", packet_length=packet_length@entry=53, blocking=blocking@entry=true) at /test/11.4_dbg/sql/sql_class.h:1551
#10 0x0000556ad79cdd50 in do_command (thd=0x14b740000d48, blocking=blocking@entry=true) at /test/11.4_dbg/sql/sql_parse.cc:1406
#11 0x0000556ad7b472fd in do_handle_one_connection (connect=<optimized out>, connect@entry=0x556adad52268, put_in_cache=put_in_cache@entry=true) at /test/11.4_dbg/sql/sql_connect.cc:1418
#12 0x0000556ad7b478b2 in handle_one_connection (arg=arg@entry=0x556adad52268) at /test/11.4_dbg/sql/sql_connect.cc:1320
#13 0x0000556ad7fb33f4 in pfs_spawn_thread (arg=0x556adad1bf68) at /test/11.4_dbg/storage/perfschema/pfs.cc:2201
#14 0x000014b76bffa609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#15 0x000014b76bbe6133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95



 Comments   
Comment by Debarun Banerjee [ 2024-01-04 ]

Problem: The issue is introduced by "MDEV-28699: Shrink temporary
tablespaces without restart". SRV_FORCE_NO_LOG_REDO forces
server to read only mode and we don't initialize temporary
tablespace in read only mode.
innodb_truncate_temporary_tablespace_now gets into the problem
while trying to access temporary tablespace.

Solution: innodb_truncate_temporary_tablespace_now should be no-op in
read only mode.

diff --git a/storage/innobase/handler/ha_innodb.cc b/storage/innobase/handler/ha_innodb.cc
index 4164ce336b3..b6f54c97c17 100644
— a/storage/innobase/handler/ha_innodb.cc
+++ b/storage/innobase/handler/ha_innodb.cc
@@ -18482,7 +18482,8 @@ static
void
innodb_trunc_temp_space_update(THD*, st_mysql_sys_var*, void*, const void* save)
{

  • if (!static_cast<const my_bool>(save))
    + /* Temp tablespace is not initialized in read only mode. */
    + if (!static_cast<const my_bool>(save) || srv_read_only_mode)
    return;
    mysql_mutex_unlock(&LOCK_global_system_variables);
    fsp_shrink_temp_space();
Comment by Debarun Banerjee [ 2024-01-04 ]

https://github.com/MariaDB/server/pull/2979
The patch is created against 11.4. The same should work for 11.3 as well.

Comment by Debarun Banerjee [ 2024-01-05 ]

New patch created against the oldest affected version 11.3.
https://github.com/MariaDB/server/pull/2981

Comment by Debarun Banerjee [ 2024-01-05 ]

Patch Pushed to 11.3.

commit 5a58935cb9939c1ca389e7112d1b288ea1b038d5 (HEAD -> 11.3, origin/11.3)
Author: mariadb-DebarunBanerjee <debarun.banerjee@mariadb.com>
Date: Fri Jan 5 12:20:37 2024 +0530

The issue is introduced by "MDEV-28699: Shrink temporary tablespaces
without restart". SRV_FORCE_NO_LOG_REDO forces server to read only mode
and we don't initialize temporary tablespace in read only mode.

solution: innodb_truncate_temporary_tablespace_now should be no-op in
read only mode.

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