[MDEV-28800] SIGABRT due to running out of memory for InnoDB locks Created: 2022-06-11  Updated: 2024-01-05

Status: Stalled
Project: MariaDB Server
Component/s: Locking, Storage Engine - InnoDB
Affects Version/s: 10.6, 10.7, 10.8, 10.9, 10.10
Fix Version/s: 10.6

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Debarun Banerjee
Resolution: Unresolved Votes: 0
Labels: not-10.3, not-10.4, not-10.5, slow_query

Issue Links:
Relates
relates to MDEV-10962 Deadlock with 3 concurrent DELETEs by... Closed
relates to MDEV-24813 Locking full table scan fails to use ... Confirmed
relates to MDEV-28803 ERROR 1206 (HY000): The total number ... Open
relates to MDEV-28804 Increased lock objects in 10.6+ leadi... Stalled
relates to MDEV-28805 SET GLOBAL innodb_buffer_pool_size=12... Confirmed

 Description    

# mysqld options required for replay: --innodb-buffer-pool-size=300M 
# Repeat entire testcase (inc server startup) if necessary to reproduce crash (usually a single attempt is sufficient)
 
SET GLOBAL innodb_buffer_pool_size=12*1024*1024;
 
CREATE TABLE t1 (d DOUBLE) ENGINE=InnoDB;
 
INSERT INTO t1 VALUES (0x0061),(0x0041),(0x00E0),(0x00C0),(0x1EA3),(0x1EA2),(0x00E3),(0x00C3),(0x00E1),(0x00C1),(0x1EA1),(0x1EA0);
 
INSERT INTO t1 SELECT t1.* FROM t1,t1 t2,t1 t3,t1 t4,t1 t5,t1 t6;

Leads to:

10.10.0 081a284712bb661349e2e3802077b12211cede3e (Optimized)

 
Core was generated by `/test/MD310522-mariadb-10.10.0-linux-x86_64-opt/bin/mysqld --no-defaults --core'.
 
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 0x14bae07b4700 (LWP 3389561))]
 
(gdb) bt
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x000014bb12242859 in __GI_abort () at abort.c:79
 
#2  0x00005601e3746893 in ib::fatal::~fatal (this=<optimized out>, __in_chrg=<optimized out>) at /test/10.10_opt/storage/innobase/ut/ut0ut.cc:530
 
#3  0x00005601e374f45a in buf_LRU_check_size_of_non_data_objects () at /test/10.10_opt/storage/innobase/include/ut0ut.h:337
 
#4  buf_LRU_get_free_block (have_mutex=have_mutex@entry=false) at /test/10.10_opt/storage/innobase/buf/buf0lru.cc:404
 
#5  0x00005601e37a6ff7 in buf_page_init_for_read (mode=132, page_id={m_id = 21474838481}, zip_size=0, unzip=<optimized out>) at /test/10.10_opt/storage/innobase/buf/buf0rea.cc:119
 
#6  0x00005601e3eb3c12 in buf_read_page_low (unzip=false, zip_size=0, page_id={m_id = 21474838481}, mode=132, sync=false, space=0x14ba68019740, err=<synthetic pointer>) at /test/10.10_opt/storage/innobase/buf/buf0rea.cc:299
 
#7  buf_read_page_background (space=space@entry=0x14ba68019740, page_id={m_id = 0}, zip_size=0) at /test/10.10_opt/storage/innobase/buf/buf0rea.cc:487
 
#8  0x00005601e3e8ce09 in btr_cur_prefetch_siblings (block=0x14bb0957bd60, index=<optimized out>) at /test/10.10_opt/storage/innobase/include/buf0types.h:95
 
#9  0x00005601e3e988ae in btr_cur_optimistic_insert (flags=<optimized out>, cursor=0x14bae07b1360, offsets=offsets@entry=0x14bae07b1348, heap=heap@entry=0x14bae07b1340, entry=entry@entry=0x14ba6801aa98, rec=rec@entry=0x14bae07b1358, big_rec=0x14bae07b1338, n_ext=<optimized out>, thr=0x14ba6801c788, mtr=0x14bae07b1ab0) at /test/10.10_opt/storage/innobase/btr/btr0cur.cc:3453
 
#10 0x00005601e3e0cf4d in row_ins_clust_index_entry_low (flags=<optimized out>, mode=<optimized out>, index=0x14ba6801adf8, n_uniq=<optimized out>, entry=0x14ba6801aa98, n_ext=<optimized out>, thr=<optimized out>) at /test/10.10_opt/storage/innobase/row/row0ins.cc:2754
 
#11 0x00005601e3e0e6e2 in row_ins_clust_index_entry (index=0x14ba6801adf8, entry=0x14ba6801aa98, thr=0x14ba6801c788, n_ext=0) at /test/10.10_opt/storage/innobase/row/row0ins.cc:3156
 
#12 0x00005601e3e0ee31 in row_ins_index_entry (thr=0x14ba6801c788, entry=<optimized out>, index=<optimized out>) at /test/10.10_opt/storage/innobase/row/row0ins.cc:3293
 
#13 row_ins_index_entry_step (thr=0x14ba6801c788, node=<optimized out>) at /test/10.10_opt/storage/innobase/row/row0ins.cc:3461
 
#14 row_ins (thr=0x14ba6801c788, node=<optimized out>) at /test/10.10_opt/storage/innobase/row/row0ins.cc:3608
 
#15 row_ins_step (thr=thr@entry=0x14ba6801c788) at /test/10.10_opt/storage/innobase/row/row0ins.cc:3754
 
#16 0x00005601e3e1ec15 in row_insert_for_mysql (mysql_rec=mysql_rec@entry=0x14ba6801b458 <incomplete sequence \375>, prebuilt=0x14ba6801c098, ins_mode=ROW_INS_NORMAL) at /test/10.10_opt/storage/innobase/row/row0mysql.cc:1318
 
#17 0x00005601e3d73a1a in ha_innobase::write_row (this=0x14ba6801b870, record=0x14ba6801b458 <incomplete sequence \375>) at /test/10.10_opt/storage/innobase/handler/ha_innodb.cc:7842
 
#18 0x00005601e3afda50 in handler::ha_write_row (this=0x14ba6801b870, buf=0x14ba6801b458 <incomplete sequence \375>) at /test/10.10_opt/sql/handler.cc:7551
 
#19 0x00005601e3872c3d in write_record (thd=0x14ba68000c58, table=0x14ba68017ca8, info=info@entry=0x14ba680141f0, sink=0x0) at /test/10.10_opt/sql/sql_insert.cc:2162
 
#20 0x00005601e3873833 in select_insert::send_data (this=0x14ba680141a0, values=<optimized out>) at /test/10.10_opt/sql/sql_insert.cc:4126
 
#21 0x00005601e391046c in select_result_sink::send_data_with_check (u=<optimized out>, sent=<optimized out>, items=@0x14ba68045e78: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x14ba68049238, last = 0x14ba68049238, elements = 1}, <No data fields>}, this=<optimized out>) at /test/10.10_opt/sql/sql_class.h:5689
 
#22 select_result_sink::send_data_with_check (sent=<optimized out>, u=<optimized out>, items=@0x14ba68045e78: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x14ba68049238, last = 0x14ba68049238, elements = 1}, <No data fields>}, this=<optimized out>) at /test/10.10_opt/sql/sql_class.h:5679
 
#23 end_send (join=0x14ba68045ab0, join_tab=0x14ba68055e60, end_of_records=<optimized out>) at /test/10.10_opt/sql/sql_select.cc:22427
 
#24 0x00005601e38e7173 in evaluate_join_record (join=join@entry=0x14ba68045ab0, join_tab=0x14ba68055ab0, error=error@entry=0) at /test/10.10_opt/sql/sql_select.cc:21421
 
#25 0x00005601e391cee7 in AGGR_OP::end_send (this=0x14ba68049228) at /test/10.10_opt/sql/sql_select.cc:29660
 
#26 0x00005601e391d120 in sub_select_postjoin_aggr (join=0x14ba68045ab0, join_tab=0x14ba68055ab0, end_of_records=<optimized out>) at /test/10.10_opt/sql/sql_select.cc:20901
 
#27 0x00005601e39264df in do_select (procedure=<optimized out>, join=0x14ba68045ab0) at /test/10.10_opt/sql/sql_select.cc:20738
 
#28 JOIN::exec_inner (this=0x14ba68045ab0) at /test/10.10_opt/sql/sql_select.cc:4786
 
#29 0x00005601e3926a48 in JOIN::exec (this=this@entry=0x14ba68045ab0) at /test/10.10_opt/sql/sql_select.cc:4564
 
#30 0x00005601e3924c51 in mysql_select (thd=0x14ba68000c58, tables=0x14ba68011508, fields=@0x14ba680111c8: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x14ba680114c0, last = 0x14ba680114c0, elements = 1}, <No data fields>}, conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=<optimized out>, result=0x14ba680141a0, unit=0x14ba68004cb8, select_lex=0x14ba68010f28) at /test/10.10_opt/sql/sql_select.cc:5044
 
#31 0x00005601e3925397 in handle_select (thd=thd@entry=0x14ba68000c58, lex=lex@entry=0x14ba68004be0, result=result@entry=0x14ba680141a0, setup_tables_done_option=setup_tables_done_option@entry=1073741824) at /test/10.10_opt/sql/sql_select.cc:578
 
#32 0x00005601e38b74dc in mysql_execute_command (thd=0x14ba68000c58, is_called_from_prepared_stmt=<optimized out>) at /test/10.10_opt/sql/sql_parse.cc:4708
 
#33 0x00005601e38a3bb5 in mysql_parse (rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, thd=0x14ba68000c58) at /test/10.10_opt/sql/sql_parse.cc:8036
 
#34 mysql_parse (thd=0x14ba68000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/10.10_opt/sql/sql_parse.cc:7958
 
#35 0x00005601e38af6ca in dispatch_command (command=COM_QUERY, thd=0x14ba68000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.10_opt/sql/sql_class.h:1364
 
#36 0x00005601e38b15f2 in do_command (thd=0x14ba68000c58, blocking=blocking@entry=true) at /test/10.10_opt/sql/sql_parse.cc:1407
 
#37 0x00005601e39c78af in do_handle_one_connection (connect=<optimized out>, connect@entry=0x5601e6906368, put_in_cache=put_in_cache@entry=true) at /test/10.10_opt/sql/sql_connect.cc:1418
 
#38 0x00005601e39c7b8d in handle_one_connection (arg=0x5601e6906368) at /test/10.10_opt/sql/sql_connect.cc:1312
 
#39 0x000014bb12753609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#40 0x000014bb1233f133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

10.10.0 081a284712bb661349e2e3802077b12211cede3e (Debug)

 
Core was generated by `/test/MD310522-mariadb-10.10.0-linux-x86_64-dbg/bin/mysqld --no-defaults --core'.
 
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 0x1455640cc700 (LWP 3589026))]
 
(gdb) bt
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x00001455874f5859 in __GI_abort () at abort.c:79
 
#2  0x000055f12541eaad in ib::fatal::~fatal (this=<optimized out>, __in_chrg=<optimized out>) at /test/10.10_dbg/storage/innobase/ut/ut0ut.cc:530
 
#3  0x000055f1254bf9a5 in buf_LRU_check_size_of_non_data_objects () at /test/10.10_dbg/storage/innobase/include/ut0ut.h:337
 
#4  buf_LRU_get_free_block (have_mutex=have_mutex@entry=false) at /test/10.10_dbg/storage/innobase/buf/buf0lru.cc:404
 
#5  0x000055f1254c06dd in buf_page_init_for_read (mode=mode@entry=132, page_id=<optimized out>, zip_size=zip_size@entry=0, unzip=unzip@entry=false) at /test/10.10_dbg/storage/innobase/buf/buf0rea.cc:119
 
#6  0x000055f1254c2ef0 in buf_read_page_low (err=err@entry=0x1455640c8ae4, space=space@entry=0x1454ac0218f0, sync=sync@entry=false, mode=mode@entry=132, page_id={m_id = 21474838467}, zip_size=0, unzip=false) at /test/10.10_dbg/storage/innobase/buf/buf0rea.cc:299
 
#7  0x000055f1254c535a in buf_read_page_background (space=space@entry=0x1454ac0218f0, page_id={m_id = 21474838467}, zip_size=<optimized out>) at /test/10.10_dbg/storage/innobase/buf/buf0rea.cc:487
 
#8  0x000055f12544c0bf in btr_cur_prefetch_siblings (block=block@entry=0x14557e833800, index=index@entry=0x1454ac0205c0) at /test/10.10_dbg/storage/innobase/include/buf0types.h:95
 
#9  0x000055f125452fac in btr_cur_optimistic_insert (flags=flags@entry=0, cursor=cursor@entry=0x1455640c9160, offsets=offsets@entry=0x1455640c9148, heap=heap@entry=0x1455640c9140, entry=entry@entry=0x1454ac01eff0, rec=rec@entry=0x1455640c9158, big_rec=0x1455640c9138, n_ext=<optimized out>, thr=0x1454ac026f00, mtr=0x1455640c9710) at /test/10.10_dbg/storage/innobase/btr/btr0cur.cc:3453
 
#10 0x000055f12533c37b in row_ins_clust_index_entry_low (flags=flags@entry=0, mode=<optimized out>, mode@entry=2, index=index@entry=0x1454ac0205c0, n_uniq=n_uniq@entry=0, entry=entry@entry=0x1454ac01eff0, n_ext=n_ext@entry=0, thr=<optimized out>) at /test/10.10_dbg/storage/innobase/row/row0ins.cc:2754
 
#11 0x000055f12533e562 in row_ins_clust_index_entry (index=index@entry=0x1454ac0205c0, entry=entry@entry=0x1454ac01eff0, thr=thr@entry=0x1454ac026f00, n_ext=n_ext@entry=0) at /test/10.10_dbg/storage/innobase/row/row0ins.cc:3156
 
#12 0x000055f1253402e8 in row_ins_index_entry (thr=0x1454ac026f00, entry=0x1454ac01eff0, index=0x1454ac0205c0) at /test/10.10_dbg/storage/innobase/row/row0ins.cc:3293
 
#13 row_ins_index_entry_step (thr=0x1454ac026f00, node=<optimized out>) at /test/10.10_dbg/storage/innobase/row/row0ins.cc:3461
 
#14 row_ins (thr=0x1454ac026f00, node=<optimized out>) at /test/10.10_dbg/storage/innobase/row/row0ins.cc:3608
 
#15 row_ins_step (thr=thr@entry=0x1454ac026f00) at /test/10.10_dbg/storage/innobase/row/row0ins.cc:3754
 
#16 0x000055f12536293d in row_insert_for_mysql (mysql_rec=mysql_rec@entry=0x1454ac025b18 <incomplete sequence \375>, prebuilt=0x1454ac0267f0, ins_mode=ROW_INS_NORMAL) at /test/10.10_dbg/storage/innobase/row/row0mysql.cc:1318
 
#17 0x000055f1251eca63 in ha_innobase::write_row (this=0x1454ac025fa0, record=0x1454ac025b18 <incomplete sequence \375>) at /test/10.10_dbg/storage/innobase/handler/ha_innodb.cc:7842
 
#18 0x000055f124ed76c9 in handler::ha_write_row (this=0x1454ac025fa0, buf=0x1454ac025b18 <incomplete sequence \375>) at /test/10.10_dbg/sql/handler.cc:7551
 
#19 0x000055f124b9afd2 in write_record (thd=0x1454ac000db8, table=0x1454ac0256a8, info=info@entry=0x1454ac017710, sink=0x0) at /test/10.10_dbg/sql/sql_insert.cc:2162
 
#20 0x000055f124b9b460 in select_insert::send_data (this=0x1454ac0176c0, values=<optimized out>) at /test/10.10_dbg/sql/sql_insert.cc:4126
 
#21 0x000055f124c54fc9 in select_result_sink::send_data_with_check (sent=<optimized out>, u=<optimized out>, items=@0x1454ac06e3a8: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x1454ac071758, last = 0x1454ac071758, elements = 1}, <No data fields>}, this=<optimized out>) at /test/10.10_dbg/sql/sql_class.h:5689
 
#22 end_send (join=0x1454ac06dfe0, join_tab=0x1454ac07ed60, end_of_records=<optimized out>) at /test/10.10_dbg/sql/sql_select.cc:22427
 
#23 0x000055f124c2702e in evaluate_join_record (join=join@entry=0x1454ac06dfe0, join_tab=0x1454ac07e9b0, error=error@entry=0) at /test/10.10_dbg/sql/sql_select.cc:21421
 
#24 0x000055f124c63943 in AGGR_OP::end_send (this=this@entry=0x1454ac071748) at /test/10.10_dbg/sql/sql_select.cc:29660
 
#25 0x000055f124c63c4b in sub_select_postjoin_aggr (join=0x1454ac06dfe0, join_tab=0x1454ac07e9b0, end_of_records=<optimized out>) at /test/10.10_dbg/sql/sql_select.cc:20901
 
#26 0x000055f124c3c9d1 in sub_select (join=join@entry=0x1454ac06dfe0, join_tab=join_tab@entry=0x1454ac07e600, end_of_records=end_of_records@entry=true) at /test/10.10_dbg/sql/sql_select.cc:21135
 
#27 0x000055f124c3ce4a in sub_select_cache (join=0x1454ac06dfe0, join_tab=0x1454ac07e600, end_of_records=<optimized out>) at /test/10.10_dbg/sql/sql_select.cc:20968
 
#28 0x000055f124c3c9d1 in sub_select (join=join@entry=0x1454ac06dfe0, join_tab=join_tab@entry=0x1454ac07e250, end_of_records=end_of_records@entry=true) at /test/10.10_dbg/sql/sql_select.cc:21135
 
#29 0x000055f124c3ce4a in sub_select_cache (join=0x1454ac06dfe0, join_tab=0x1454ac07e250, end_of_records=<optimized out>) at /test/10.10_dbg/sql/sql_select.cc:20968
 
#30 0x000055f124c3c9d1 in sub_select (join=join@entry=0x1454ac06dfe0, join_tab=join_tab@entry=0x1454ac07dea0, end_of_records=end_of_records@entry=true) at /test/10.10_dbg/sql/sql_select.cc:21135
 
#31 0x000055f124c3ce4a in sub_select_cache (join=0x1454ac06dfe0, join_tab=0x1454ac07dea0, end_of_records=<optimized out>) at /test/10.10_dbg/sql/sql_select.cc:20968
 
#32 0x000055f124c3c9d1 in sub_select (join=join@entry=0x1454ac06dfe0, join_tab=join_tab@entry=0x1454ac07daf0, end_of_records=end_of_records@entry=true) at /test/10.10_dbg/sql/sql_select.cc:21135
 
#33 0x000055f124c3ce4a in sub_select_cache (join=0x1454ac06dfe0, join_tab=0x1454ac07daf0, end_of_records=<optimized out>) at /test/10.10_dbg/sql/sql_select.cc:20968
 
#34 0x000055f124c3c9d1 in sub_select (join=join@entry=0x1454ac06dfe0, join_tab=join_tab@entry=0x1454ac07d740, end_of_records=end_of_records@entry=true) at /test/10.10_dbg/sql/sql_select.cc:21135
 
#35 0x000055f124c3ce4a in sub_select_cache (join=0x1454ac06dfe0, join_tab=0x1454ac07d740, end_of_records=<optimized out>) at /test/10.10_dbg/sql/sql_select.cc:20968
 
#36 0x000055f124c3c9d1 in sub_select (join=0x1454ac06dfe0, join_tab=0x1454ac07d390, end_of_records=true) at /test/10.10_dbg/sql/sql_select.cc:21135
 
#37 0x000055f124c702b1 in do_select (procedure=<optimized out>, join=0x1454ac06dfe0) at /test/10.10_dbg/sql/sql_select.cc:20738
 
#38 JOIN::exec_inner (this=this@entry=0x1454ac06dfe0) at /test/10.10_dbg/sql/sql_select.cc:4786
 
#39 0x000055f124c70814 in JOIN::exec (this=this@entry=0x1454ac06dfe0) at /test/10.10_dbg/sql/sql_select.cc:4564
 
#40 0x000055f124c6e598 in mysql_select (thd=thd@entry=0x1454ac000db8, tables=0x1454ac014a28, fields=@0x1454ac0146e8: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x1454ac0149e0, last = 0x1454ac0149e0, elements = 1}, <No data fields>}, conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2202244745984, result=0x1454ac0176c0, unit=0x1454ac004fd8, select_lex=0x1454ac014448) at /test/10.10_dbg/sql/sql_select.cc:5044
 
#41 0x000055f124c6ed8e in handle_select (thd=thd@entry=0x1454ac000db8, lex=lex@entry=0x1454ac004f00, result=result@entry=0x1454ac0176c0, setup_tables_done_option=setup_tables_done_option@entry=1073741824) at /test/10.10_dbg/sql/sql_select.cc:578
 
#42 0x000055f124be8f9d in mysql_execute_command (thd=thd@entry=0x1454ac000db8, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /test/10.10_dbg/sql/sql_parse.cc:4708
 
#43 0x000055f124bd4e3a in mysql_parse (thd=thd@entry=0x1454ac000db8, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x1455640cb470) at /test/10.10_dbg/sql/sql_parse.cc:8036
 
#44 0x000055f124be2422 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x1454ac000db8, packet=packet@entry=0x1454ac00b6d9 "INSERT INTO t1 SELECT t1.* FROM t1,t1 t2,t1 t3,t1 t4,t1 t5,t1 t6", packet_length=packet_length@entry=64, blocking=blocking@entry=true) at /test/10.10_dbg/sql/sql_class.h:1364
 
#45 0x000055f124be4b2c in do_command (thd=0x1454ac000db8, blocking=blocking@entry=true) at /test/10.10_dbg/sql/sql_parse.cc:1407
 
#46 0x000055f124d443c0 in do_handle_one_connection (connect=<optimized out>, connect@entry=0x55f127e141d8, put_in_cache=put_in_cache@entry=true) at /test/10.10_dbg/sql/sql_connect.cc:1418
 
#47 0x000055f124d448c9 in handle_one_connection (arg=0x55f127e141d8) at /test/10.10_dbg/sql/sql_connect.cc:1312
 
#48 0x0000145587a06609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#49 0x00001455875f2133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Though earlier versions will not crash, the query will take a very long time in all MariaDB versions, as well as all MySQL server versions. See MDEV-28804.
As an interesting side note, MS 5.7 runs just under two minutes slower/behind MD 10.7.5 on the first query, started at approximately the same time, on the same machine.

 Comments   
Comment by Roel Van de Paar [ 2022-06-11 ]

Additional slightly different stack seen (same testcase) (fsp_page_create instead of buf_page_init_for_read after buf_LRU_get_free_block):

10.8.4 0e0a3580efdae313fab340bbb308d371fa36c021 (Optimized)

 
Core was generated by `/test/MD310522-mariadb-10.8.4-linux-x86_64-opt/bin/mysqld --no-defaults --core-'.
 
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 0x148dcc124700 (LWP 3997020))]
 
(gdb) bt
 
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
 
#1  0x0000148df0d1a859 in __GI_abort () at abort.c:79
 
#2  0x0000556a6f349333 in ib::fatal::~fatal (this=<optimized out>, __in_chrg=<optimized out>) at /test/10.8_opt/storage/innobase/ut/ut0ut.cc:530
 
#3  0x0000556a6f351efa in buf_LRU_check_size_of_non_data_objects () at /test/10.8_opt/storage/innobase/include/ut0ut.h:337
 
#4  buf_LRU_get_free_block (have_mutex=have_mutex@entry=false) at /test/10.8_opt/storage/innobase/buf/buf0lru.cc:404
 
#5  0x0000556a6faf1d97 in fsp_page_create (space=0x556a71717840, offset=1232, mtr=0x148dcc11ff70) at /test/10.8_opt/storage/innobase/fsp/fsp0fsp.cc:1076
 
#6  0x0000556a6faf2f4e in fseg_alloc_free_page_low (space=0x556a71717840, seg_inode=0x148de84cb7b2 <error: Cannot access memory at address 0x148de84cb7b2>, iblock=0x148de805d040, hint=<optimized out>, direction=<optimized out>, mtr=0x148dcc11ff70, init_mtr=0x148dcc11ff70) at /test/10.8_opt/storage/innobase/fsp/fsp0fsp.cc:2250
 
#7  0x0000556a6faf4ca1 in fseg_alloc_free_page_general (seg_header=seg_header@entry=0x148de3b8803c <error: Cannot access memory at address 0x148de3b8803c>, hint=1232, direction=direction@entry=111 'o', has_done_reservation=has_done_reservation@entry=true, mtr=mtr@entry=0x148dcc11ff70, init_mtr=init_mtr@entry=0x148dcc11ff70) at /test/10.8_opt/storage/innobase/fsp/fsp0fsp.cc:2298
 
#8  0x0000556a6fa66fbb in trx_undo_add_page (undo=undo@entry=0x148d2001b890, mtr=mtr@entry=0x148dcc11ff70) at /test/10.8_opt/storage/innobase/trx/trx0undo.cc:679
 
#9  0x0000556a6fa51304 in trx_undo_report_row_operation (thr=thr@entry=0x148d2001c8d8, index=index@entry=0x148d2001ac98, clust_entry=clust_entry@entry=0x148d2001a7f8, update=update@entry=0x0, cmpl_info=cmpl_info@entry=0, rec=rec@entry=0x0, offsets=<optimized out>, roll_ptr=<optimized out>) at /test/10.8_opt/storage/innobase/trx/trx0rec.cc:2215
 
#10 0x0000556a6fa9334b in btr_cur_ins_lock_and_undo (inherit=0x148dcc121107, mtr=0x148dcc121b10, thr=0x148d2001c8d8, entry=0x148d2001a7f8, cursor=0x148dcc1213c0, flags=0) at /test/10.8_opt/storage/innobase/btr/btr0cur.cc:3285
 
#11 btr_cur_optimistic_insert (flags=0, cursor=0x148dcc1213c0, offsets=offsets@entry=0x148dcc1213a8, heap=heap@entry=0x148dcc1213a0, entry=entry@entry=0x148d2001a7f8, rec=rec@entry=0x148dcc1213b8, big_rec=0x148dcc121398, n_ext=<optimized out>, thr=0x148d2001c8d8, mtr=0x148dcc121b10) at /test/10.8_opt/storage/innobase/btr/btr0cur.cc:3513
 
#12 0x0000556a6fa076ad in row_ins_clust_index_entry_low (flags=<optimized out>, mode=<optimized out>, index=0x148d2001ac98, n_uniq=<optimized out>, entry=0x148d2001a7f8, n_ext=<optimized out>, thr=<optimized out>) at /test/10.8_opt/storage/innobase/row/row0ins.cc:2754
 
#13 0x0000556a6fa08e42 in row_ins_clust_index_entry (index=0x148d2001ac98, entry=0x148d2001a7f8, thr=0x148d2001c8d8, n_ext=0) at /test/10.8_opt/storage/innobase/row/row0ins.cc:3156
 
#14 0x0000556a6fa09591 in row_ins_index_entry (thr=0x148d2001c8d8, entry=<optimized out>, index=<optimized out>) at /test/10.8_opt/storage/innobase/row/row0ins.cc:3293
 
#15 row_ins_index_entry_step (thr=0x148d2001c8d8, node=<optimized out>) at /test/10.8_opt/storage/innobase/row/row0ins.cc:3461
 
#16 row_ins (thr=0x148d2001c8d8, node=<optimized out>) at /test/10.8_opt/storage/innobase/row/row0ins.cc:3608
 
#17 row_ins_step (thr=thr@entry=0x148d2001c8d8) at /test/10.8_opt/storage/innobase/row/row0ins.cc:3754
 
#18 0x0000556a6fa19375 in row_insert_for_mysql (mysql_rec=mysql_rec@entry=0x148d20017928 <incomplete sequence \375>, prebuilt=0x148d2001c1e8, ins_mode=ROW_INS_NORMAL) at /test/10.8_opt/storage/innobase/row/row0mysql.cc:1318
 
#19 0x0000556a6f96e9fa in ha_innobase::write_row (this=0x148d2001b9c0, record=0x148d20017928 <incomplete sequence \375>) at /test/10.8_opt/storage/innobase/handler/ha_innodb.cc:7842
 
#20 0x0000556a6f6f9680 in handler::ha_write_row (this=0x148d2001b9c0, buf=0x148d20017928 <incomplete sequence \375>) at /test/10.8_opt/sql/handler.cc:7549
 
#21 0x0000556a6f4740cd in write_record (thd=0x148d20000c58, table=0x148d20019a28, info=info@entry=0x148d20014168, sink=0x0) at /test/10.8_opt/sql/sql_insert.cc:2161
 
#22 0x0000556a6f474cc3 in select_insert::send_data (this=0x148d20014118, values=<optimized out>) at /test/10.8_opt/sql/sql_insert.cc:4125
 
#23 0x0000556a6f51119c in select_result_sink::send_data_with_check (u=<optimized out>, sent=<optimized out>, items=@0x148d20045f00: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x148d200492c0, last = 0x148d200492c0, elements = 1}, <No data fields>}, this=<optimized out>) at /test/10.8_opt/sql/sql_class.h:5660
 
#24 select_result_sink::send_data_with_check (sent=<optimized out>, u=<optimized out>, items=@0x148d20045f00: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x148d200492c0, last = 0x148d200492c0, elements = 1}, <No data fields>}, this=<optimized out>) at /test/10.8_opt/sql/sql_class.h:5650
 
#25 end_send (join=0x148d20045b38, join_tab=0x148d20055e60, end_of_records=<optimized out>) at /test/10.8_opt/sql/sql_select.cc:22399
 
#26 0x0000556a6f4e7eb3 in evaluate_join_record (join=join@entry=0x148d20045b38, join_tab=0x148d20055ab0, error=error@entry=0) at /test/10.8_opt/sql/sql_select.cc:21393
 
#27 0x0000556a6f51dc17 in AGGR_OP::end_send (this=0x148d200492b0) at /test/10.8_opt/sql/sql_select.cc:29624
 
#28 0x0000556a6f51de50 in sub_select_postjoin_aggr (join=0x148d20045b38, join_tab=0x148d20055ab0, end_of_records=<optimized out>) at /test/10.8_opt/sql/sql_select.cc:20873
 
#29 0x0000556a6f52720f in do_select (procedure=<optimized out>, join=0x148d20045b38) at /test/10.8_opt/sql/sql_select.cc:20710
 
#30 JOIN::exec_inner (this=0x148d20045b38) at /test/10.8_opt/sql/sql_select.cc:4759
 
#31 0x0000556a6f527778 in JOIN::exec (this=this@entry=0x148d20045b38) at /test/10.8_opt/sql/sql_select.cc:4537
 
#32 0x0000556a6f525981 in mysql_select (thd=0x148d20000c58, tables=0x148d200114b0, fields=@0x148d20011170: {<base_list> = {<Sql_alloc> = {<No data fields>}, first = 0x148d20011468, last = 0x148d20011468, elements = 1}, <No data fields>}, conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=<optimized out>, result=0x148d20014118, unit=0x148d20004ca8, select_lex=0x148d20010ed0) at /test/10.8_opt/sql/sql_select.cc:5017
 
#33 0x0000556a6f5260c7 in handle_select (thd=thd@entry=0x148d20000c58, lex=lex@entry=0x148d20004bd0, result=result@entry=0x148d20014118, setup_tables_done_option=setup_tables_done_option@entry=1073741824) at /test/10.8_opt/sql/sql_select.cc:551
 
#34 0x0000556a6f4b84cf in mysql_execute_command (thd=0x148d20000c58, is_called_from_prepared_stmt=<optimized out>) at /test/10.8_opt/sql/sql_parse.cc:4708
 
#35 0x0000556a6f4a4c75 in mysql_parse (rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>, thd=0x148d20000c58) at /test/10.8_opt/sql/sql_parse.cc:8027
 
#36 mysql_parse (thd=0x148d20000c58, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at /test/10.8_opt/sql/sql_parse.cc:7949
 
#37 0x0000556a6f4b086a in dispatch_command (command=COM_QUERY, thd=0x148d20000c58, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at /test/10.8_opt/sql/sql_class.h:1362
 
#38 0x0000556a6f4b2792 in do_command (thd=0x148d20000c58, blocking=blocking@entry=true) at /test/10.8_opt/sql/sql_parse.cc:1407
 
#39 0x0000556a6f5c777f in do_handle_one_connection (connect=<optimized out>, connect@entry=0x556a719923d8, put_in_cache=put_in_cache@entry=true) at /test/10.8_opt/sql/sql_connect.cc:1418
 
#40 0x0000556a6f5c7a5d in handle_one_connection (arg=0x556a719923d8) at /test/10.8_opt/sql/sql_connect.cc:1312
 
#41 0x0000148df122b609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#42 0x0000148df0e17133 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Comment by Roel Van de Paar [ 2022-06-11 ]

All UniqueID's

SIGABRT|ib::fatal::~fatal|buf_LRU_check_size_of_non_data_objects|buf_LRU_get_free_block|buf_page_init_for_read
 
SIGABRT|ib::fatal::~fatal|buf_LRU_check_size_of_non_data_objects|buf_LRU_get_free_block|fsp_page_create

Comment by Elena Stepanova [ 2022-06-11 ]

Additionally, the second query takes even (much) longer

Out of semi-professional curiosity, what are the characteristics of the machine where you've seen the 2nd query succeed, and what was the on-disk size of the data (ballpark) after that?

Comment by Marko Mäkelä [ 2022-06-13 ]

As I noted in MDEV-28803, the crash does occur in 10.7 as well. Please double-check the affected versions.

Comment by Marko Mäkelä [ 2022-06-13 ]

I think that in 10.6 and later, thanks to MDEV-13542, it should be feasible to let buf_LRU_get_free_block() return a failure status and let the caller handle that.

Comment by Marko Mäkelä [ 2022-06-13 ]

The test case of MDEV-28803 crashes 10.6 just fine for me:

10.6 51ca5d517ef67f97e3c38d57174f8cfa251a14d8

 
mysqltest: At line 8: query 'INSERT INTO t1 SELECT t1.* FROM t1,t1 t2,t1 t3,t1 t4,t1 t5,t1 t6' failed: <Unknown> (2013): Lost connection to server during query
 
…
 
2022-06-13 10:37:47 0 [Note] InnoDB: Completed to resize buffer pool from 8388608 to 16777216.
 
2022-06-13 10:37:47 0 [Note] InnoDB: Completed resizing buffer pool at 220613 10:37:47.
 
2022-06-13 10:37:51 4 [Warning] InnoDB: Over 67 percent of the buffer pool is occupied by lock heaps or the adaptive hash index! Check that your transactions do not set too many row locks. innodb_buffer_pool_size=15M. Starting the InnoDB Monitor to print diagnostics.
 
2022-06-13 10:37:52 4 [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. 231 OS file reads, 2710 OS file writes, 247 OS fsyncs.
 
2022-06-13 10:38:02 4 [ERROR] [FATAL] InnoDB: Over 95 percent of the buffer pool is occupied by lock heaps or the adaptive hash index! Check that your transactions do not set too many row locks, or review if innodb_buffer_pool_size=15M could be bigger.

Comment by Roel Van de Paar [ 2022-06-13 ]

Confirmed crash is present in 10.6 and 10.7 when using this MTR testcase, and not present in 10.3 nor 10.5. 10.4 Cannot be tested due to MDEV-28805.

10.4.26 ebbd5ef6e2902a51a46e47dbb8a8667593cb25e7 (Debug)

 
mysqltest: At line 2: query 'SET GLOBAL innodb_buffer_pool_size=12*1024*1024' failed: 1231: Variable 'innodb_buffer_pool_size' can't be set to the value of '12582912'

However, at the CLI, and when using the OP listed option --innodb-buffer-pool-size=300M, only 10.8 to 10.10 crashes.
10.6 and 10.7 will not crash in this case but rather complete (as mentoned in MDEV-28804) when this option is not used.

In summary; for the original T/C, the listed versions are correct. For the modified/additional testcase (without changing the original buffer pool size) 10.6 + 10.7 are affected also.

Comment by Marko Mäkelä [ 2022-06-13 ]

I do not think that this is any recent regression. In fact, I would expect any InnoDB version (starting from the very first release with MySQL 3.23) to crash like this. The logic around returning the error code DB_LOCK_TABLE_FULL (in order to avoid running out of memory) is inaccurate and prone to race conditions.

The code refactoring that was conducted in MDEV-13542 should allow the crashes to be fixed in 10.6 and later releases.

Comment by Marko Mäkelä [ 2022-06-22 ]

I created a rough prototype that needs some more work before it is ready for any testing. The reason why we sometimes crash and sometimes report DB_LOCK_TABLE_FULL is that the check buf_pool.running_out() (whether less than ¼ of the buffer pool is available for data pages) is inaccurate and misplaced. Between the time the check is executed and the lock objects are actually allocated, other threads could exhaust the buffer pool.

Comment by Marko Mäkelä [ 2022-08-26 ]

I produced a slightly better prototype that may be worth testing. I will still have to solve the problem where we would run out of lock memory while adjusting the locks during a page reorganize, split, or merge.

Comment by Marko Mäkelä [ 2023-07-05 ]

Once MDEV-10962 is fixed, there should be less memory wasted due to singleton lock record bitmaps.

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

MDEV-24813 may be more practical and feasible to fix first.

Comment by Marko Mäkelä [ 2024-01-05 ]

If I remember correctly, the prototype that I had produced performed very badly in stress tests.

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