[MDEV-29319] Assertion failure size_in_header >= space.free_limit in fsp_get_available_space_in_free_extents() Created: 2022-08-17  Updated: 2022-08-24  Resolved: 2022-08-24

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.6
Fix Version/s: 10.3.37, 10.4.27, 10.5.18, 10.6.10, 10.7.6, 10.8.5, 10.9.3, 10.10.2

Type: Bug Priority: Major
Reporter: Thirunarayanan Balathandayuthapani Assignee: Thirunarayanan Balathandayuthapani
Resolution: Fixed Votes: 0
Labels: rr-profile-analyzed


 Description   

There is a race condition between info_low() and fsp_try_extend_data_file().
Following stack trace shows the problem

(rr) t 56
 
[Switching to thread 56 (Thread 2318080.2326679)]
 
#0  fsp_try_extend_data_file (space=0x6120000376c0, header=0x7f4d572d7c30, mtr=0x7f4d373a4980)
 
    at /data/Server/bb-10.6-MDEV-29250/storage/innobase/fsp/fsp0fsp.cc:747
 
747		mtr->write<4,mtr_t::FORCED>(*header, FSP_HEADER_OFFSET + FSP_SIZE
 
(rr) where
 
#0  fsp_try_extend_data_file (space=0x6120000376c0, header=0x7f4d572d7c30, mtr=0x7f4d373a4980)
 
    at /data/Server/bb-10.6-MDEV-29250/storage/innobase/fsp/fsp0fsp.cc:747
 
#1  0x0000561a8f4aba43 in fsp_fill_free_list (init_space=false, space=0x6120000376c0, header=0x7f4d572d7c30, mtr=0x7f4d373a4980)
 
    at /data/Server/bb-10.6-MDEV-29250/storage/innobase/fsp/fsp0fsp.cc:814
 
#2  0x0000561a8f4ac68e in fsp_alloc_free_extent (space=0x6120000376c0, hint=0, xdes=0x7f4d373a4490, mtr=0x7f4d373a4980, err=0x7f4d373a4820)
 
    at /data/Server/bb-10.6-MDEV-29250/storage/innobase/fsp/fsp0fsp.cc:948
 
#3  0x0000561a8f4b251f in fseg_alloc_free_extent (inode=0x7f4d578400f2 "", iblock=0x7f4d572db510, xdes=0x7f4d373a4490, space=0x6120000376c0, 
    mtr=0x7f4d373a4980, err=0x7f4d373a4820) at /data/Server/bb-10.6-MDEV-29250/storage/innobase/fsp/fsp0fsp.cc:1905
 
#4  0x0000561a8f4b3c89 in fseg_alloc_free_page_low (space=0x6120000376c0, seg_inode=0x7f4d578400f2 "", iblock=0x7f4d572db510, hint=4, 
    direction=113 'q', has_done_reservation=true, mtr=0x7f4d373a4980, init_mtr=0x7f4d373a4980, err=0x7f4d373a4820)
 
    at /data/Server/bb-10.6-MDEV-29250/storage/innobase/fsp/fsp0fsp.cc:2149
 
#5  0x0000561a8f4b48d2 in fseg_alloc_free_page_general (seg_header=0x7f4d5786004a "", hint=4, direction=113 'q', has_done_reservation=true, 
    mtr=0x7f4d373a4980, init_mtr=0x7f4d373a4980, err=0x7f4d373a4820) at /data/Server/bb-10.6-MDEV-29250/storage/innobase/fsp/fsp0fsp.cc:2266
 
#6  0x0000561a8f2b9b6a in btr_page_alloc_low (index=0x6160032d1c08, hint_page_no=4, file_direction=113 'q', level=0, mtr=0x7f4d373a4980, 
    init_mtr=0x7f4d373a4980, err=0x7f4d373a4820) at /data/Server/bb-10.6-MDEV-29250/storage/innobase/btr/btr0btr.cc:521
 
#7  0x0000561a8f2b9c59 in btr_page_alloc (index=0x6160032d1c08, hint_page_no=4, file_direction=113 'q', level=0, mtr=0x7f4d373a4980, 
    init_mtr=0x7f4d373a4980, err=0x7f4d373a4820) at /data/Server/bb-10.6-MDEV-29250/storage/innobase/btr/btr0btr.cc:548
 
#8  0x0000561a8f329a73 in btr_store_big_rec_extern_fields (pcur=0x7f4d373a4f90, offsets=0x7f4d373a58d0, big_rec_vec=0x62d000de8488, 
    btr_mtr=0x7f4d373a50c0, op=BTR_STORE_INSERT) at /data/Server/bb-10.6-MDEV-29250/storage/innobase/btr/btr0cur.cc:7044
 
#9  0x0000561a8f0fa67b in row_ins_index_entry_big_rec (entry=0x616003379f08, big_rec=0x62d000de8488, offsets=0x7f4d373a58d0, 
    heap=0x7f4d373a5740, index=0x6160032d1c08, thd=0x62b000380218) at /data/Server/bb-10.6-MDEV-29250/storage/innobase/row/row0ins.cc:2485
 
#10 0x0000561a8f0fc82f in row_ins_clust_index_entry_low (flags=0, mode=2, index=0x6160032d1c08, n_uniq=1, entry=0x616003379f08, n_ext=0, 
    thr=0x625000714e08) at /data/Server/bb-10.6-MDEV-29250/storage/innobase/row/row0ins.cc:2790
 
#11 0x0000561a8f0fe90f in row_ins_clust_index_entry (index=0x6160032d1c08, entry=0x616003379f08, thr=0x625000714e08, n_ext=0)
 
    at /data/Server/bb-10.6-MDEV-29250/storage/innobase/row/row0ins.cc:3150
 
#12 0x0000561a8f0ff20e in row_ins_index_entry (index=0x6160032d1c08, entry=0x616003379f08, thr=0x625000714e08)
 
    at /data/Server/bb-10.6-MDEV-29250/storage/innobase/row/row0ins.cc:3276
 
#13 0x0000561a8f10027e in row_ins_index_entry_step (node=0x6210004bc3f0, thr=0x625000714e08)
 
    at /data/Server/bb-10.6-MDEV-29250/storage/innobase/row/row0ins.cc:3444
 
#14 0x0000561a8f100ccc in row_ins (node=0x6210004bc3f0, thr=0x625000714e08)
 
    at /data/Server/bb-10.6-MDEV-29250/storage/innobase/row/row0ins.cc:3590
 
#15 0x0000561a8f101d16 in row_ins_step (thr=0x625000714e08) at /data/Server/bb-10.6-MDEV-29250/storage/innobase/row/row0ins.cc:3730
 
#16 0x0000561a8f1414ae in row_insert_for_mysql (mysql_rec=0x61a00041e8b8 "H\377\t", prebuilt=0x6210004bb588, ins_mode=ROW_INS_NORMAL)
 
    at /data/Server/bb-10.6-MDEV-29250/storage/innobase/row/row0mysql.cc:1313
 
#17 0x0000561a8edb4063 in ha_innobase::write_row (this=0x61d000c026b8, record=0x61a00041e8b8 "H\377\t")
 
    at /data/Server/bb-10.6-MDEV-29250/storage/innobase/handler/ha_innodb.cc:7935
 
--Type <RET> for more, q to quit, c to continue without paging--
 
#18 0x0000561a8e4d6ef8 in handler::ha_write_row (this=0x61d000c026b8, buf=0x61a00041e8b8 "H\377\t")
 
    at /data/Server/bb-10.6-MDEV-29250/sql/handler.cc:7575
 
#19 0x0000561a8dc1d554 in write_record (thd=0x62b000380218, table=0x6190006eeb98, info=0x7f4d373a6de0, sink=0x0)
 
    at /data/Server/bb-10.6-MDEV-29250/sql/sql_insert.cc:2156
 
#20 0x0000561a8dc15c29 in mysql_insert (thd=0x62b000380218, table_list=0x62b0003874b8, fields=..., values_list=..., update_fields=..., 
    update_values=..., duplic=DUP_ERROR, ignore=false, result=0x0) at /data/Server/bb-10.6-MDEV-29250/sql/sql_insert.cc:1128
 
#21 0x0000561a8dcd3f17 in mysql_execute_command (thd=0x62b000380218, is_called_from_prepared_stmt=false)
 
    at /data/Server/bb-10.6-MDEV-29250/sql/sql_parse.cc:4565
 
#22 0x0000561a8dceb176 in mysql_parse (thd=0x62b000380218, 
    rawbuf=0x62b000387238 "INSERT INTO t3 (col1,col2, col_int, col_string, col_text) VALUES ( 9, 9 - 1, 9, REPEAT(SUBSTR(CAST( 9 AS CHAR),1,1), 10), REPEAT(SUBSTR(CAST( 9 AS CHAR),1,1), @fill_amount) ) /* E_R Thread46 QNO 71 CO"..., length=210, parser_state=0x7f4d373a7a20)
 
    at /data/Server/bb-10.6-MDEV-29250/sql/sql_parse.cc:8030
 
#23 0x0000561a8dcc3584 in dispatch_command (command=COM_QUERY, thd=0x62b000380218, 
    packet=0x62900118f219 " INSERT INTO t3 (col1,col2, col_int, col_string, col_text) VALUES ( 9, 9 - 1, 9, REPEAT(SUBSTR(CAST( 9 AS CHAR),1,1), 10), REPEAT(SUBSTR(CAST( 9 AS CHAR),1,1), @fill_amount) ) /* E_R Thread46 QNO 71 C"..., packet_length=212, blocking=true)
 
    at /data/Server/bb-10.6-MDEV-29250/sql/sql_parse.cc:1896
 
#24 0x0000561a8dcc09cb in do_command (thd=0x62b000380218, blocking=true) at /data/Server/bb-10.6-MDEV-29250/sql/sql_parse.cc:1409
 
#25 0x0000561a8e0c5029 in do_handle_one_connection (connect=0x6080000c4538, put_in_cache=true)
 
    at /data/Server/bb-10.6-MDEV-29250/sql/sql_connect.cc:1418
 
#26 0x0000561a8e0c48b5 in handle_one_connection (arg=0x6080000c4538) at /data/Server/bb-10.6-MDEV-29250/sql/sql_connect.cc:1312
 
#27 0x00007f4d64e06609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#28 0x00007f4d649db293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
 
 
 
 
 
(rr) t 3
 
[Switching to thread 3 (Thread 2318080.2326332)]
 
#0  0x0000561a8edd8ce5 in fsp_get_available_space_in_free_extents (space=...)
 
    at /data/Server/bb-10.6-MDEV-29250/storage/innobase/handler/ha_innodb.cc:14678
 
14678		ut_ad(size_in_header >= space.free_limit);
 
(rr) where
 
#0  0x0000561a8edd8ce5 in fsp_get_available_space_in_free_extents (space=...)
 
    at /data/Server/bb-10.6-MDEV-29250/storage/innobase/handler/ha_innodb.cc:14678
 
#1  0x0000561a8edd9b7d in ha_innobase::info_low (this=0x61d000b43cb8, flag=18, is_analyze=false)
 
    at /data/Server/bb-10.6-MDEV-29250/storage/innobase/handler/ha_innodb.cc:14849
 
#2  0x0000561a8eddb08b in ha_innobase::info (this=0x61d000b43cb8, flag=18)
 
    at /data/Server/bb-10.6-MDEV-29250/storage/innobase/handler/ha_innodb.cc:15048
 
#3  0x0000561a8e91115b in mysql_delete (thd=0x62b00031e218, table_list=0x62b0003253b8, conds=0x62b000326088, order_list=0x62b000322e60, 
    limit=18446744073709551615, options=0, result=0x0) at /data/Server/bb-10.6-MDEV-29250/sql/sql_delete.cc:516
 
#4  0x0000561a8dcd63f4 in mysql_execute_command (thd=0x62b00031e218, is_called_from_prepared_stmt=false)
 
    at /data/Server/bb-10.6-MDEV-29250/sql/sql_parse.cc:4807
 
#5  0x0000561a8dceb176 in mysql_parse (thd=0x62b00031e218, 
    rawbuf=0x62b000325238 "DELETE FROM t3 WHERE col2 = 299 OR col2 IS NULL  /* E_R Thread38 QNO 93 CON_ID 56 */", length=84, 
    parser_state=0x7f4d39121a20) at /data/Server/bb-10.6-MDEV-29250/sql/sql_parse.cc:8030
 
#6  0x0000561a8dcc3584 in dispatch_command (command=COM_QUERY, thd=0x62b00031e218, 
    packet=0x6290010bd219 " DELETE FROM t3 WHERE col2 = 299 OR col2 IS NULL  /* E_R Thread38 QNO 93 CON_ID 56 */ ", packet_length=86, 
    blocking=true) at /data/Server/bb-10.6-MDEV-29250/sql/sql_parse.cc:1896
 
#7  0x0000561a8dcc09cb in do_command (thd=0x62b00031e218, blocking=true) at /data/Server/bb-10.6-MDEV-29250/sql/sql_parse.cc:1409
 
#8  0x0000561a8e0c5029 in do_handle_one_connection (connect=0x6080000c41b8, put_in_cache=true)
 
    at /data/Server/bb-10.6-MDEV-29250/sql/sql_connect.cc:1418
 
#9  0x0000561a8e0c48b5 in handle_one_connection (arg=0x6080000c41b8) at /data/Server/bb-10.6-MDEV-29250/sql/sql_connect.cc:1312
 
#10 0x00007f4d64e06609 in start_thread (arg=<optimized out>) at pthread_create.c:477
 
#11 0x00007f4d649db293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95



 Comments   
Comment by Thirunarayanan Balathandayuthapani [ 2022-08-22 ]

Patch is in bb-10.3-MDEV-29319

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

I see that there is only one caller of the function fsp_get_available_space_in_free_extents(), in ha_innobase::info_low(). We might as well acquire and release fil_space_t::latch around the call. I think that we have to acquire the latch in all builds and not only debug builds, because even if no debug assertion failed, the stats.delete_length could be calculated incorrectly.

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