[MDEV-31861] Empty INSERT crashes with innodb_force_recovery=6 or innodb_read_only=ON - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.6, 10.9(EOL), 10.10(EOL), 10.11, 11.0(EOL), 11.1(EOL), 11.2(EOL)
Fix Version/s: 10.6.17, 10.11.7, 11.0.5, 11.1.4, 11.2.3, 11.3.2
Component/s: Storage Engine - InnoDB
Labels:
- not-10.4
- not-10.5

Description

# mysqld options required for replay:  --innodb-force-recovery=6

INSERT INTO mysql.innodb_index_stats SELECT * FROM mysql.innodb_index_stats WHERE table_name='';

Leads to

11.2.0 e81fa345020ec6a067583db6a7019d6404b26f93 (Optimized)
Core was generated by `/test/MD270723-mariadb-11.2.0-linux-x86_64-opt/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 0x152396f28700 (LWP 2916494))]
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00001523b64cf859 in __GI_abort () at abort.c:79
#2 0x0000561a58325b61 in ib::fatal::~fatal (this=<optimized out>, __in_chrg=<optimized out>) at /test/11.2_opt/storage/innobase/ut/ut0ut.cc:527
#3 0x0000561a5830da89 in os_file_sync_posix (file=<optimized out>) at /test/11.2_opt/storage/innobase/include/ut0ut.h:337
#4 os_file_flush_func (file=<optimized out>) at /test/11.2_opt/storage/innobase/os/os0file.cc:933
#5 0x0000561a589c4c2d in log_file_t::flush (this=0x561a59eafc20 <log_sys+288>) at /test/11.2_opt/storage/innobase/include/log0log.h:140
#6 log_t::flush (lsn=12288, this=0x561a59eafb00 <log_sys>) at /test/11.2_opt/storage/innobase/log/log0log.cc:886
#7 log_flush (lsn=12288) at /test/11.2_opt/storage/innobase/log/log0log.cc:904
#8 log_write_up_to (lsn=<optimized out>, durable=true, callback=<optimized out>) at /test/11.2_opt/storage/innobase/log/log0log.cc:954
#9 0x0000561a5898f802 in ha_innobase::extra (this=0x152380017bd0, operation=HA_EXTRA_END_ALTER_COPY) at /test/11.2_opt/storage/innobase/handler/ha_innodb.cc:15683
#10 0x0000561a584568c7 in select_insert::prepare_eof (this=0x152380012be8) at /test/11.2_opt/sql/sql_class.h:4669
#11 0x0000561a58456ba6 in select_insert::send_eof (this=0x152380012be8) at /test/11.2_opt/sql/sql_insert.cc:4365
#12 0x0000561a5850d12f in do_select (procedure=<optimized out>, join=0x152380012ca8) at /test/11.2_opt/sql/sql_select.cc:23010
#13 JOIN::exec_inner (this=0x152380012ca8) at /test/11.2_opt/sql/sql_select.cc:4935
#14 0x0000561a5850d5fe in JOIN::exec (this=this@entry=0x152380012ca8) at /test/11.2_opt/sql/sql_select.cc:4712
#15 0x0000561a5850b71c in mysql_select (thd=0x152380000c58, tables=0x1523800117b0, fields=<optimized out>, conds=0x152380012080, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=<optimized out>, result=0x152380012be8, unit=0x152380004da8, select_lex=0x152380011140) at /test/11.2_opt/sql/sql_select.cc:5243
#16 0x0000561a5850be87 in handle_select (thd=thd@entry=0x152380000c58, lex=lex@entry=0x152380004cc8, result=result@entry=0x152380012be8, setup_tables_done_option=setup_tables_done_option@entry=35184372088832) at /test/11.2_opt/sql/sql_select.cc:628
#17 0x0000561a584979be in mysql_execute_command (thd=0x152380000c58, is_called_from_prepared_stmt=<optimized out>) at /test/11.2_opt/sql/sql_parse.cc:4598
#18 0x0000561a584841e5 in mysql_parse (rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, thd=0x152380000c58) at /test/11.2_opt/sql/sql_parse.cc:7800
#19 mysql_parse (thd=0x152380000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/11.2_opt/sql/sql_parse.cc:7722
#20 0x0000561a58490092 in dispatch_command (command=COM_QUERY, thd=0x152380000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/11.2_opt/sql/sql_class.h:1374
#21 0x0000561a58491f7e in do_command (thd=0x152380000c58, blocking=blocking@entry=true) at /test/11.2_opt/sql/sql_parse.cc:1405
#22 0x0000561a585b16cf in do_handle_one_connection (connect=<optimized out>, connect@entry=0x561a5b7b2e28, put_in_cache=put_in_cache@entry=true) at /test/11.2_opt/sql/sql_connect.cc:1445
#23 0x0000561a585b19bd in handle_one_connection (arg=0x561a5b7b2e28) at /test/11.2_opt/sql/sql_connect.cc:1347
#24 0x00001523b69e0609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#25 0x00001523b65cc133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

11.2.0 e81fa345020ec6a067583db6a7019d6404b26f93 (Debug)
mariadbd: /test/11.2_dbg/storage/innobase/log/log0log.cc:970: void log_buffer_flush_to_disk(bool): Assertion `!srv_read_only_mode' failed.

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 0x1530b0421700 (LWP 642807))]
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00001530cf99e859 in __GI_abort () at abort.c:79
#2 0x00001530cf99e729 in __assert_fail_base (fmt=0x1530cfb34588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x5581593360ee "!srv_read_only_mode", file=0x558159356c28 "/test/11.2_dbg/storage/innobase/log/log0log.cc", line=970, function=<optimized out>) at assert.c:92
#3 0x00001530cf9affd6 in __GI___assert_fail (assertion=assertion@entry=0x5581593360ee "!srv_read_only_mode", file=file@entry=0x558159356c28 "/test/11.2_dbg/storage/innobase/log/log0log.cc", line=line@entry=970, function=function@entry=0x558159357208 "void log_buffer_flush_to_disk(bool)") at assert.c:101
#4 0x0000558158be13b1 in log_buffer_flush_to_disk (durable=durable@entry=true) at /test/11.2_dbg/storage/innobase/log/log0log.cc:970
#5 0x0000558158b61241 in ha_innobase::extra (this=0x15309c01e650, operation=HA_EXTRA_END_ALTER_COPY) at /test/11.2_dbg/storage/innobase/handler/ha_innodb.cc:15683
#6 0x000055815850c573 in select_insert::prepare_eof (this=this@entry=0x15309c0155e8) at /test/11.2_dbg/sql/sql_insert.cc:4263
#7 0x000055815850cbcf in select_insert::send_eof (this=0x15309c0155e8) at /test/11.2_dbg/sql/sql_insert.cc:4365
#8 0x00005581585e18ec in do_select (procedure=<optimized out>, join=0x15309c0156a8) at /test/11.2_dbg/sql/sql_select.cc:23010
#9 JOIN::exec_inner (this=this@entry=0x15309c0156a8) at /test/11.2_dbg/sql/sql_select.cc:4935
#10 0x00005581585e1cb2 in JOIN::exec (this=this@entry=0x15309c0156a8) at /test/11.2_dbg/sql/sql_select.cc:4712
#11 0x00005581585dfb30 in mysql_select (thd=thd@entry=0x15309c000d48, tables=0x15309c0141b0, fields=@0x15309c013df8: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x15309c014118, last = 0x15309c016958, elements = 8}, <No data fields>}, conds=0x15309c014a80, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=37385559870208, result=0x15309c0155e8, unit=0x15309c005058, select_lex=0x15309c013b40) at /test/11.2_dbg/sql/sql_select.cc:5243
#12 0x00005581585e02ce in handle_select (thd=thd@entry=0x15309c000d48, lex=lex@entry=0x15309c004f78, result=result@entry=0x15309c0155e8, setup_tables_done_option=setup_tables_done_option@entry=35184372088832) at /test/11.2_dbg/sql/sql_select.cc:628
#13 0x000055815855310d in mysql_execute_command (thd=thd@entry=0x15309c000d48, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/11.2_dbg/sql/sql_parse.cc:4598
#14 0x000055815853f73b in mysql_parse (thd=thd@entry=0x15309c000d48, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1530b04202c0) at /test/11.2_dbg/sql/sql_parse.cc:7800
#15 0x000055815854cc00 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x15309c000d48, packet=packet@entry=0x15309c00af49 "INSERT INTO mysql.innodb_index_stats SELECT * FROM mysql.innodb_index_stats WHERE table_name=''", packet_length=packet_length@entry=95, blocking=blocking@entry=true) at /test/11.2_dbg/sql/sql_class.h:1374
#16 0x000055815854f0b8 in do_command (thd=0x15309c000d48, blocking=blocking@entry=true) at /test/11.2_dbg/sql/sql_parse.cc:1405
#17 0x00005581586b4717 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55815c567bd8, put_in_cache=put_in_cache@entry=true) at /test/11.2_dbg/sql/sql_connect.cc:1445
#18 0x00005581586b4be6 in handle_one_connection (arg=0x55815c567bd8) at /test/11.2_dbg/sql/sql_connect.cc:1347
#19 0x00001530cfeaf609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#20 0x00001530cfa9b133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

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

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.4.31 (dbg), 10.4.31 (opt), 10.5.21 (dbg), 10.5.22 (dbg), 10.5.22 (opt)

Attachments

Issue Links

is caused by

MDEV-515 innodb bulk insert

Closed

Activity

Ascending order - Click to sort in descending order

Marko Mäkelä added a comment - 2023-11-14 15:03

The failing assertion duplicates one at the start of the next callee. The following fixes this:

diff --git a/storage/innobase/handler/ha_innodb.cc b/storage/innobase/handler/ha_innodb.cc

index 188f703f33c..d5cc2311a2b 100644

--- a/storage/innobase/handler/ha_innodb.cc

+++ b/storage/innobase/handler/ha_innodb.cc

@@ -15797,7 +15797,8 @@ ha_innobase::extra(

 		break;

 	case HA_EXTRA_END_ALTER_COPY:

 		m_prebuilt->table->skip_alter_undo = 0;

-		if (!m_prebuilt->table->is_temporary()) {

+		if (!m_prebuilt->table->is_temporary()

+		    && !high_level_read_only) {

 			log_buffer_flush_to_disk();

 		break;

diff --git a/storage/innobase/log/log0log.cc b/storage/innobase/log/log0log.cc

index e9ef36b4b84..3f8703beb3e 100644

--- a/storage/innobase/log/log0log.cc

+++ b/storage/innobase/log/log0log.cc

@@ -871,7 +871,6 @@ void log_write_up_to(lsn_t lsn, bool flush_to_disk, bool rotate_key,

 @param sync  whether to wait for a durable write to complete */

 void log_buffer_flush_to_disk(bool sync)

-  ut_ad(!srv_read_only_mode);

   log_write_up_to(log_sys.get_lsn(std::memory_order_acquire), sync);

Marko Mäkelä added a comment - 2023-11-14 15:03 The failing assertion duplicates one at the start of the next callee. The following fixes this: diff --git a/storage/innobase/handler/ha_innodb.cc b/storage/innobase/handler/ha_innodb.cc index 188f703f33c..d5cc2311a2b 100644 --- a/storage/innobase/handler/ha_innodb.cc +++ b/storage/innobase/handler/ha_innodb.cc @@ -15797,7 +15797,8 @@ ha_innobase::extra( break; case HA_EXTRA_END_ALTER_COPY: m_prebuilt->table->skip_alter_undo = 0; - if (!m_prebuilt->table->is_temporary()) { + if (!m_prebuilt->table->is_temporary() + && !high_level_read_only) { log_buffer_flush_to_disk(); } break; diff --git a/storage/innobase/log/log0log.cc b/storage/innobase/log/log0log.cc index e9ef36b4b84..3f8703beb3e 100644 --- a/storage/innobase/log/log0log.cc +++ b/storage/innobase/log/log0log.cc @@ -871,7 +871,6 @@ void log_write_up_to(lsn_t lsn, bool flush_to_disk, bool rotate_key, @param sync whether to wait for a durable write to complete */ void log_buffer_flush_to_disk(bool sync) { - ut_ad(!srv_read_only_mode); log_write_up_to(log_sys.get_lsn(std::memory_order_acquire), sync); }

Marko Mäkelä added a comment - 2023-11-16 14:56

Here is a simple test case that reproduces the reported failure:

diff --git a/mysql-test/suite/innodb/t/read_only_recovery.test b/mysql-test/suite/innodb/t/read_only_recovery.test

index 47146213090..d011b3aa5e3 100644

--- a/mysql-test/suite/innodb/t/read_only_recovery.test

+++ b/mysql-test/suite/innodb/t/read_only_recovery.test

@@ -39,6 +39,8 @@ SELECT * FROM t;

 SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED;

 SELECT * FROM t;

 SET GLOBAL innodb_max_purge_lag_wait=0;

+INSERT INTO mysql.innodb_index_stats

+SELECT * FROM mysql.innodb_index_stats LIMIT 0;

 --let $restart_parameters=

 --source include/restart_mysqld.inc

 SELECT * FROM t;

Marko Mäkelä added a comment - 2023-11-16 14:56 Here is a simple test case that reproduces the reported failure: diff --git a/mysql-test/suite/innodb/t/read_only_recovery.test b/mysql-test/suite/innodb/t/read_only_recovery.test index 47146213090..d011b3aa5e3 100644 --- a/mysql-test/suite/innodb/t/read_only_recovery.test +++ b/mysql-test/suite/innodb/t/read_only_recovery.test @@ -39,6 +39,8 @@ SELECT * FROM t; SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED; SELECT * FROM t; SET GLOBAL innodb_max_purge_lag_wait=0; +INSERT INTO mysql.innodb_index_stats +SELECT * FROM mysql.innodb_index_stats LIMIT 0; --let $restart_parameters= --source include/restart_mysqld.inc SELECT * FROM t;

MariaDB Server

Empty INSERT crashes with innodb_force_recovery=6 or innodb_read_only=ON

Details

Description

Attachments

Issue Links

Activity

People

Dates

Git Integration