[MDEV-30400] Assertion `height == btr_page_get_level(page_cur_get_page(page_cursor))' failed in btr_cur_search_to_nth_level on INSERT Created: 2023-01-13  Updated: 2023-07-28  Resolved: 2023-01-24

Status: Closed
Project: MariaDB Server
Component/s: GIS, Storage Engine - InnoDB
Affects Version/s: 10.6, 10.7, 10.8, 10.9, 10.10, 10.11, 11.0
Fix Version/s: 10.11.2, 11.0.1, 10.6.12, 10.7.8, 10.8.7, 10.9.5, 10.10.3

Type: Bug Priority: Blocker
Reporter: Roel Van de Paar Assignee: Marko Mäkelä
Resolution: Fixed Votes: 1
Labels: regression-10.6

Issue Links:
Problem/Incident
causes MDEV-30648 btr_estimate_n_rows_in_range() access... Closed
causes MDEV-31767 InnoDB tables are being flagged as co... Closed
Relates
relates to MDEV-23165 Assertion `level <= 50' failed in btr... Confirmed
relates to MDEV-29835 Partial server freeze Closed
relates to MDEV-29967 innodb_read_ahead_threshold (linear r... Closed
relates to MDEV-30289 mtr_t::m_memo is causing frequent mem... Closed
relates to MDEV-30637 Mariadb server hangs Closed

 Description   

While similar in testcase to MDEV-23165, this bug only exists in 10.6+ and the assert is different. Not sporadic.

CREATE TABLE t (c POINT NOT NULL,SPATIAL (c)) ENGINE=InnoDB;
 
SET GLOBAL innodb_limit_optimistic_insert_debug=2;
 
INSERT INTO t SELECT POINTFROMTEXT ('POINT(0 0)') FROM seq_1_to_366;

Leads to:

11.0.1 b075191ba8598af6aff5549e6e19f6255aef258a (Debug)

 
mysqld: /test/11.0_dbg/storage/innobase/btr/btr0cur.cc:1901: dberr_t btr_cur_search_to_nth_level(ulint, const dtuple_t*, page_cur_mode_t, btr_latch_mode, btr_cur_t*, mtr_t*, ib_uint64_t): Assertion `height == btr_page_get_level(page_cur_get_page(page_cursor))' failed.

11.0.1 b075191ba8598af6aff5549e6e19f6255aef258a (Debug)

 
Core was generated by `/test/MD090123-mariadb-11.0.1-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=23033843611200)
 
    at ./nptl/pthread_kill.c:44
 
[Current thread is 1 (Thread 0x14f2fc10f640 (LWP 588465))]
 
(gdb) bt
 
#0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=23033843611200) at ./nptl/pthread_kill.c:44
 
#1  __pthread_kill_internal (signo=6, threadid=23033843611200) at ./nptl/pthread_kill.c:78
 
#2  __GI___pthread_kill (threadid=23033843611200, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
 
#3  0x000014f314d80476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
 
#4  0x000014f314d667f3 in __GI_abort () at ./stdlib/abort.c:79
 
#5  0x000014f314d6671b in __assert_fail_base (fmt=0x14f314f1b150 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55adf0deec48 "height == btr_page_get_level(page_cur_get_page(page_cursor))", file=0x55adf0debeb0 "/test/11.0_dbg/storage/innobase/btr/btr0cur.cc", line=1901, function=<optimized out>) at ./assert/assert.c:92
 
#6  0x000014f314d77e96 in __GI___assert_fail (assertion=0x55adf0deec48 "height == btr_page_get_level(page_cur_get_page(page_cursor))", file=0x55adf0debeb0 "/test/11.0_dbg/storage/innobase/btr/btr0cur.cc", line=1901, function=0x55adf0dee5c8 "dberr_t btr_cur_search_to_nth_level(ulint, const dtuple_t*, page_cur_mode_t, btr_latch_mode, btr_cur_t*, mtr_t*, ib_uint64_t)") at ./assert/assert.c:101
 
#7  0x000055adf0922ea9 in btr_cur_search_to_nth_level (level=level@entry=0, tuple=tuple@entry=0x14f2bc01d7b8, mode=mode@entry=PAGE_CUR_RTREE_INSERT, latch_mode=<optimized out>, latch_mode@entry=BTR_INSERT_TREE, cursor=cursor@entry=0x14f2fc10c300, mtr=mtr@entry=0x14f2fc10c850, autoinc=<optimized out>) at /test/11.0_dbg/storage/innobase/btr/btr0cur.cc:1901
 
#8  0x000055adf0817e65 in row_ins_sec_index_entry_low (flags=flags@entry=0, mode=mode@entry=BTR_INSERT_TREE, index=index@entry=0x14f2bc020ff0, offsets_heap=<optimized out>, offsets_heap@entry=0x14f2bc075080, heap=heap@entry=0x14f2bc074590, entry=entry@entry=0x14f2bc01d7b8, trx_id=0, thr=0x14f2bc025750) at /test/11.0_dbg/storage/innobase/row/row0ins.cc:2909
 
#9  0x000055adf081a1da in row_ins_sec_index_entry (index=index@entry=0x14f2bc020ff0, entry=entry@entry=0x14f2bc01d7b8, thr=thr@entry=0x14f2bc025750, check_foreign=check_foreign@entry=true) at /test/11.0_dbg/storage/innobase/row/row0ins.cc:3266
 
#10 0x000055adf081eeb6 in row_ins_index_entry (thr=0x14f2bc025750, entry=0x14f2bc01d7b8, index=0x14f2bc020ff0) at /test/11.0_dbg/storage/innobase/row/row0ins.cc:3311
 
#11 row_ins_index_entry_step (thr=0x14f2bc025750, node=0x14f2bc025530) at /test/11.0_dbg/storage/innobase/row/row0ins.cc:3477
 
#12 row_ins (thr=0x14f2bc025750, node=0x14f2bc025530) at /test/11.0_dbg/storage/innobase/row/row0ins.cc:3623
 
#13 row_ins_step (thr=thr@entry=0x14f2bc025750) at /test/11.0_dbg/storage/innobase/row/row0ins.cc:3763
 
#14 0x000055adf084057f in row_insert_for_mysql (mysql_rec=mysql_rec@entry=0x14f2bc01d218 "\031", prebuilt=0x14f2bc025060, ins_mode=ins_mode@entry=ROW_INS_NORMAL) at /test/11.0_dbg/storage/innobase/row/row0mysql.cc:1308
 
#15 0x000055adf06e8c16 in ha_innobase::write_row (this=0x14f2bc024820, record=0x14f2bc01d218 "\031") at /test/11.0_dbg/storage/innobase/handler/ha_innodb.cc:7833
 
#16 0x000055adf04063bb in handler::ha_write_row (this=0x14f2bc024820, buf=0x14f2bc01d218 "\031") at /test/11.0_dbg/sql/handler.cc:7584
 
#17 0x000055adf00f2a34 in write_record (thd=0x14f2bc000d58, table=0x14f2bc01ab78, info=info@entry=0x14f2bc0161f8, sink=0x0) at /test/11.0_dbg/sql/sql_insert.cc:2203
 
#18 0x000055adf00f2f37 in select_insert::send_data (this=0x14f2bc0161a8, values=<optimized out>) at /test/11.0_dbg/sql/sql_insert.cc:4181
 
#19 0x000055adf01a3ffc in select_result_sink::send_data_with_check (sent=<optimized out>, u=<optimized out>, items=@0x14f2bc013c20: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x14f2bc013fa8, last = 0x14f2bc013fa8, elements = 1}, <No data fields>}, this=<optimized out>) at /test/11.0_dbg/sql/sql_class.h:5721
 
#20 end_send (join=0x14f2bc016268, join_tab=0x14f2bc06e5a8, end_of_records=<optimized out>) at /test/11.0_dbg/sql/sql_select.cc:23079
 
#21 0x000055adf017757f in evaluate_join_record (join=join@entry=0x14f2bc016268, join_tab=join_tab@entry=0x14f2bc06e1f0, error=error@entry=0) at /test/11.0_dbg/sql/sql_select.cc:22073
 
#22 0x000055adf018b88c in sub_select (join=0x14f2bc016268, join_tab=0x14f2bc06e1f0, end_of_records=false) at /test/11.0_dbg/sql/sql_select.cc:21882
 
#23 0x000055adf01becd9 in do_select (procedure=<optimized out>, join=0x14f2bc016268) at /test/11.0_dbg/sql/sql_select.cc:21386
 
#24 JOIN::exec_inner (this=this@entry=0x14f2bc016268) at /test/11.0_dbg/sql/sql_select.cc:4822
 
#25 0x000055adf01bf23e in JOIN::exec (this=this@entry=0x14f2bc016268) at /test/11.0_dbg/sql/sql_select.cc:4600
 
#26 0x000055adf01bd1a7 in mysql_select (thd=thd@entry=0x14f2bc000d58, tables=0x14f2bc014058, fields=@0x14f2bc013c20: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x14f2bc013fa8, last = 0x14f2bc013fa8, elements = 1}, <No data fields>}, conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=37385559870208, result=0x14f2bc0161a8, unit=0x14f2bc004f98, select_lex=0x14f2bc013980) at /test/11.0_dbg/sql/sql_select.cc:5080
 
#27 0x000055adf01bd91a in handle_select (thd=thd@entry=0x14f2bc000d58, lex=lex@entry=0x14f2bc004ec0, result=result@entry=0x14f2bc0161a8, setup_tables_done_option=setup_tables_done_option@entry=35184372088832) at /test/11.0_dbg/sql/sql_select.cc:581
 
#28 0x000055adf0136703 in mysql_execute_command (thd=thd@entry=0x14f2bc000d58, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/11.0_dbg/sql/sql_parse.cc:4713
 
#29 0x000055adf013b934 in mysql_parse (thd=thd@entry=0x14f2bc000d58, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x14f2fc10e2c0) at /test/11.0_dbg/sql/sql_parse.cc:8000
 
#30 0x000055adf013dac8 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x14f2bc000d58, packet=packet@entry=0x14f2bc00ae09 "INSERT INTO t SELECT POINTFROMTEXT ('POINT(0 0)') FROM seq_1_to_366", packet_length=packet_length@entry=67, blocking=blocking@entry=true) at /test/11.0_dbg/sql/sql_class.h:243
 
#31 0x000055adf013f921 in do_command (thd=0x14f2bc000d58, blocking=blocking@entry=true) at /test/11.0_dbg/sql/sql_parse.cc:1407
 
#32 0x000055adf02899ea in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55adf402c788, put_in_cache=put_in_cache@entry=true) at /test/11.0_dbg/sql/sql_connect.cc:1416
 
#33 0x000055adf0289c4e in handle_one_connection (arg=0x55adf402c788) at /test/11.0_dbg/sql/sql_connect.cc:1318
 
#34 0x000014f314dd2b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
 
#35 0x000014f314e64a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Bug confirmed present in:
MariaDB: 10.6.12 (dbg), 10.7.8 (dbg), 10.8.7 (dbg), 10.9.5 (dbg), 10.10.3 (dbg), 10.11.2 (dbg), 11.0.1 (dbg)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.3.38 (dbg), 10.3.38 (opt), 10.4.28 (dbg), 10.4.28 (opt), 10.5.19 (dbg), 10.5.19 (opt), 10.6.12 (opt), 10.7.8 (opt), 10.8.7 (opt), 10.9.5 (opt), 10.10.3 (opt), 10.11.2 (opt), 11.0.1 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.40 (dbg), 5.7.40 (opt), 8.0.31 (dbg), 8.0.31 (opt)

 Comments   
Comment by Marko Mäkelä [ 2023-01-13 ]

Can you get bb-10.6-MDEV-29835 to crash with anything like this?

That branch is heavily refactoring btr_cur_search_to_nth_level(), including creating a separate version for SPATIAL INDEX operations. In fact, the goal is to remove the entire function. Currently that function only searches to non-leaf B-tree pages.

Comment by Roel Van de Paar [ 2023-01-13 ]

Confirmed that the current iteration of bb-10.6-MDEV-29835, revision b1ff085a6ce03651d13e318ecc0861f002067918, build as debug, does not crash.

10.6.12 b1ff085a6ce03651d13e318ecc0861f002067918 (Debug)

 
10.6.12-dbg>CREATE TABLE t (c POINT NOT NULL,SPATIAL (c)) ENGINE=InnoDB;
 
Query OK, 0 rows affected (0.012 sec)
 
 
 
10.6.12-dbg>SET GLOBAL innodb_limit_optimistic_insert_debug=2;
 
Query OK, 0 rows affected (0.000 sec)
 
 
 
10.6.12-dbg>INSERT INTO t SELECT POINTFROMTEXT ('POINT(0 0)') FROM seq_1_to_366;
 
Query OK, 366 rows affected (0.192 sec)
 
Records: 366  Duplicates: 0  Warnings: 0

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

This will be fixed by a subset of changes that are necessary for fixing MDEV-29835.

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

I only need 6 rows in the table instead of 366, for reproducing an assertion failure:

--source include/have_innodb.inc
 
--source include/have_debug.inc
 
--source include/have_sequence.inc
 
CREATE TABLE t1 (c POINT NOT NULL,SPATIAL (c)) ENGINE=InnoDB;
 
SET @save_limit=@@GLOBAL.innodb_limit_optimistic_insert_debug;
 
SET GLOBAL innodb_limit_optimistic_insert_debug=2;
 
BEGIN;
 
INSERT INTO t1 SELECT POINTFROMTEXT ('POINT(0 0)') FROM seq_1_to_6;
 
ROLLBACK;
 
SET GLOBAL innodb_limit_optimistic_insert_debug=@save_limit;
 
DROP TABLE t1;

10.6 a01abad6193a39a9cdaa2b36b2a40be1759be0ce

 
mariadbd: /mariadb/10.6m/storage/innobase/gis/gis0sea.cc:1036: void rtr_rebuild_path(rtr_info_t*, ulint): Assertion `new_path->size() == before_size - 1' failed.

With the original 366-line insert and the fix, we’d easily hit a consequence of MDEV-24813 during the ROLLBACK (which I added for additional testing). Maybe for SPATIAL INDEX, some additional locks are being allocated during ROLLBACK.

2023-01-23 12:31:36 3 [Warning] InnoDB: Difficult to find free blocks in the buffer pool (21 search iterations)! 21 failed attempts to flush a page! Consider increasing innodb_buffer_pool_size. Pending flushes (fsync) log: 0; buffer pool: 0. 4148 OS file reads, 1339 OS file writes, 243 OS fsyncs.

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

Merging this to the 11.0 branch will take some extra effort due to conflicts with MDEV-29694.

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