|
From one of our customer instances, we are observing MariaDB server hangs. Threads keep piling up. After analyzing the cores, this is what I found.
Lot of threads wait to acquire fil_space_t S latch. Another thread has taken fil_space_t X latch
thread 568 (purge doing delete and page merge) took (fil_space_t X latch), X-lock on page 12404981 and waiting for X-lock on page 1204976
|
|
thread 179 (doing btr_estimate_n_rows_in_range_on_level()) took S lock on page 1204976 and waiting for S-lock on page 1204981
|
|
t568
gdb) bt
|
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
|
#1 0x000055b967f42860 in ssux_lock_impl<true>::wait (lk=<optimized out>, this=0x7f69880c90f8) at ./storage/innobase/sync/srw_lock.cc:244
|
#2 ssux_lock_impl<true>::wr_wait (this=this@entry=0x7f69880c90f8, lk=<optimized out>) at ./storage/innobase/sync/srw_lock.cc:378
|
#3 0x000055b96783eb4f in ssux_lock_impl<true>::wr_lock (this=0x7f69880c90f8) at ./storage/innobase/include/srw_lock.h:265
|
#4 sux_lock<ssux_lock_impl<true> >::x_lock_upgraded (this=0x7f69880c90f8) at ./storage/innobase/include/sux_lock.h:428
|
#5 buf_page_get_low (page_id=..., zip_size=<optimized out>, rw_latch=<optimized out>, guess=<optimized out>, mode=<optimized out>, mtr=<optimized out>, err=<optimized out>, allow_ibuf_merge=<optimized out>) at ./storage/innobase/buf/buf0buf.cc:2842
|
#6 0x000055b967f6ed53 in btr_block_get (index=..., page=<optimized out>, mode=<optimized out>, merge=<optimized out>, mtr=<optimized out>, err=0x7f4e837fbb4c) at ./storage/innobase/btr/btr0btr.cc:228
|
#7 0x000055b967f6ee77 in btr_can_merge_with_page (cursor=cursor@entry=0x7f4e837fc380, page_no=page_no@entry=1204976, merge_block=merge_block@entry=0x7f4e837fbc58, mtr=mtr@entry=0x7f4e837fcc50) at ./storage/innobase/btr/btr0btr.cc:5336
|
#8 0x000055b967f7639a in btr_compress (cursor=cursor@entry=0x7f4e837fc380, adjust=adjust@entry=false, mtr=mtr@entry=0x7f4e837fcc50) at ./storage/innobase/btr/btr0btr.cc:3636
|
#9 0x000055b967f8bd72 in btr_cur_compress_if_useful (mtr=0x7f4e837fcc50, adjust=false, cursor=0x7f4e837fc380) at ./storage/innobase/btr/btr0cur.cc:5358
|
#10 btr_cur_compress_if_useful (cursor=0x7f4e837fc380, adjust=<optimized out>, mtr=0x7f4e837fcc50) at ./storage/innobase/btr/btr0cur.cc:5358
|
#11 0x000055b967f913d5 in btr_cur_pessimistic_delete (err=0x7f4e837fc2ac, has_reserved_extents=<optimized out>, cursor=<optimized out>, flags=<optimized out>, rollback=<optimized out>, mtr=0x7f4e837fcc50) at ./storage/innobase/btr/btr0cur.cc:5842
|
#12 0x000055b967f91a54 in btr_cur_node_ptr_delete (parent=parent@entry=0x7f4e837fc380, mtr=mtr@entry=0x7f4e837fcc50) at ./storage/innobase/btr/btr0cur.cc:5882
|
#13 0x000055b967f764f3 in btr_compress (cursor=cursor@entry=0x55b96aece980, adjust=adjust@entry=false, mtr=mtr@entry=0x7f4e837fcc50) at ./storage/innobase/btr/btr0btr.cc:3753
|
#14 0x000055b967f8bd72 in btr_cur_compress_if_useful (mtr=0x7f4e837fcc50, adjust=false, cursor=0x55b96aece980) at ./storage/innobase/btr/btr0cur.cc:5358
|
#15 btr_cur_compress_if_useful (cursor=0x55b96aece980, adjust=<optimized out>, mtr=0x7f4e837fcc50) at ./storage/innobase/btr/btr0cur.cc:5358
|
#16 0x000055b967f913d5 in btr_cur_pessimistic_delete (err=err@entry=0x7f4e837fc9e4, has_reserved_extents=has_reserved_extents@entry=0, cursor=cursor@entry=0x55b96aece980, flags=flags@entry=0, rollback=rollback@entry=false, mtr=mtr@entry=0x7f4e837fcc50) at ./storage/innobase/btr/btr0cur.cc:5842
|
#17 0x000055b967f1d9a1 in row_purge_remove_clust_if_poss_low (node=0x55b96aece8e0, mode=<optimized out>) at ./storage/innobase/row/row0purge.cc:220
|
#18 0x000055b967f205cd in row_purge_remove_clust_if_poss (node=0x55b96aece8e0) at ./storage/innobase/row/row0purge.cc:260
|
#19 row_purge_del_mark (node=0x55b96aece8e0) at ./storage/innobase/row/row0purge.cc:630
|
#20 row_purge_record_func (node=0x55b96aece8e0, undo_rec=0x7f4f9412f250 "", thr=0x55b96aecdd28, updated_extern=<optimized out>) at ./storage/innobase/row/row0purge.cc:1192
|
#21 0x000055b967f20cfe in row_purge (thr=<optimized out>, undo_rec=<optimized out>, node=0x55b96aece8e0) at ./storage/innobase/row/row0purge.cc:1253
|
#22 row_purge_step (thr=thr@entry=0x55b96aecdd28) at ./storage/innobase/row/row0purge.cc:1316
|
#23 0x000055b967ee91a3 in que_thr_step (thr=0x55b96aecdd28) at ./storage/innobase/que/que0que.cc:674
|
#24 que_run_threads_low (thr=<optimized out>) at ./storage/innobase/que/que0que.cc:730
|
#25 que_run_threads (thr=thr@entry=0x55b96aecdd28) at ./storage/innobase/que/que0que.cc:750
|
#26 0x000055b967f3ff50 in srv_task_execute () at ./storage/innobase/srv/srv0srv.cc:1656
|
#27 purge_worker_callback () at ./storage/innobase/srv/srv0srv.cc:1899
|
#28 0x000055b968039356 in tpool::task_group::execute (this=0x55b96921c280 <purge_task_group>, t=0x55b9691e9560 <purge_worker_task>) at ./tpool/task_group.cc:55
|
#29 0x000055b968037f07 in tpool::thread_pool_generic::worker_main (this=0x55b96ace7bd0, thread_var=0x55b96ace9080) at ./tpool/tpool_generic.cc:580
|
#30 0x00007f69d25f72b3 in ?? () from target:/lib/x86_64-linux-gnu/libstdc++.so.6
|
#31 0x00007f69d229eb43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
|
#32 0x00007f69d2330a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
|
t179
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
|
#1 0x000055b967f427c8 in srw_mutex_impl<true>::wait (lk=<optimized out>, this=0x7f68c804e858) at ./storage/innobase/sync/srw_lock.cc:238
|
#2 srw_mutex_impl<true>::wait_and_lock (this=this@entry=0x7f68c804e858) at ./storage/innobase/sync/srw_lock.cc:326
|
#3 0x000055b967f4292e in srw_mutex_impl<true>::wr_lock (this=0x7f68c804e858) at ./storage/innobase/include/srw_lock.h:134
|
#4 ssux_lock_impl<true>::rd_wait (this=this@entry=0x7f68c804e858) at ./storage/innobase/sync/srw_lock.cc:392
|
#5 0x000055b96783f2b5 in ssux_lock_impl<true>::rd_lock (this=0x7f68c804e858) at ./storage/innobase/include/srw_lock.h:247
|
#6 sux_lock<ssux_lock_impl<true> >::s_lock (this=<optimized out>) at ./storage/innobase/include/sux_lock.h:362
|
#7 buf_page_get_low (page_id=..., zip_size=<optimized out>, rw_latch=<optimized out>, guess=<optimized out>, mode=<optimized out>, mtr=<optimized out>, err=<optimized out>, allow_ibuf_merge=<optimized out>) at ./storage/innobase/buf/buf0buf.cc:2817
|
#8 0x000055b967f6ed53 in btr_block_get (index=..., page=page@entry=1204981, mode=mode@entry=1, merge=merge@entry=false, mtr=mtr@entry=0x7f4fa7ffb5d0, err=0x7f4fa7ffb1bc, err@entry=0x0) at ./storage/innobase/btr/btr0btr.cc:228
|
#9 0x000055b967f8c414 in btr_estimate_n_rows_in_range_on_level (mtr=..., is_n_rows_exact=<synthetic pointer>: true, n_rows_on_prev_level=<optimized out>, right_page_no=<optimized out>, left_cur=..., level=<optimized out>) at ./storage/innobase/include/buf0types.h:135
|
#10 btr_estimate_n_rows_in_range (index=index@entry=0x7f503c00a000, range_start=range_start@entry=0x7f4fa7ffbae0, range_end=range_end@entry=0x7f4fa7ffbb00) at ./storage/innobase/btr/btr0cur.cc:6351
|
#11 0x000055b967e5497c in ha_innobase::records_in_range (this=0x7f4dec88c200, keynr=<optimized out>, min_key=<optimized out>, max_key=0x7f4fa7ffbc10, pages=0x7f4fa7ffbbe0) at ./storage/innobase/handler/ha_innodb.cc:14336
|
#12 0x000055b967a702b3 in handler::multi_range_read_info_const (this=0x7f4dec88c200, keyno=keyno@entry=0, seq=0x7f4fa7ffbda0, seq_init_param=<optimized out>, n_ranges_arg=<optimized out>, bufsz=bufsz@entry=0x7f4fa7ffbc9c, flags=0x7f4fa7ffbc98, cost=0x7f4fa7ffbdd0) at ./sql/multi_range_read.cc:177
|
#13 0x000055b967a72da3 in DsMrr_impl::dsmrr_info_const (this=0x7f4dec88c6e8, keyno=0, seq=<optimized out>, seq_init_param=<optimized out>, n_ranges=<optimized out>, bufsz=0x7f4fa7ffbd7c, flags=0x7f4fa7ffbd78, cost=0x7f4fa7ffbdd0) at ./sql/multi_range_read.cc:1710
|
#14 0x000055b967c9d3cb in check_quick_select (is_ror_scan=<synthetic pointer>, cost=0x7f4fa7ffbdd0, bufsize=0x7f4fa7ffbd7c, mrr_flags=0x7f4fa7ffbd78, update_tbl_stats=true, tree=0x7f4c60031ae8, index_only=false, idx=0, param=0x7f4fa7ffc620) at ./sql/opt_range.cc:11574
|
#15 get_key_scans_params (param=0x7f4fa7ffc620, tree=0x7f4c60031a48, index_read_must_be_used=false, for_range_access=true, read_time=16067795.4) at ./sql/opt_range.cc:7484
|
#16 0x000055b967caf356 in SQL_SELECT::test_quick_select (this=this@entry=0x7f4c6002d728, thd=thd@entry=0x7f4c60017d88, keys_to_use=..., prev_tables=prev_tables@entry=0, limit=limit@entry=18446744073709551615, force_quick_range=force_quick_range@entry=false, ordered_output=<optimized out>, remove_false_parts_of_where=<optimized out>, only_single_index_range_scan=<optimized out>) at ./sql/opt_range.cc:2935
|
#17 0x000055b96798c425 in get_quick_record_count (limit=<optimized out>, keys=0x7f4c6004b2a0, table=<optimized out>, select=0x7f4c6002d728, thd=0x7f4c60017d88) at ./sql/sql_select.cc:5096
|
#18 make_join_statistics (join=0x7f4c6002be78, tables_list=..., keyuse_array=0x7f4c6002c190) at ./sql/sql_select.cc:5823
|
#19 0x000055b96799157a in JOIN::optimize_inner (this=0x7f4c6002be78) at ./sql/sql_select.cc:2505
|
#20 0x000055b967991b8a in JOIN::optimize (this=this@entry=0x7f4c6002be78) at ./sql/sql_select.cc:1844
|
#21 0x000055b967991c57 in mysql_select (thd=0x7f4c60017d88, tables=0x7f4c60029980, fields=..., conds=0x7f4c6002a880, og_num=1, order=0x7f4c6002bd08, group=0x0, having=0x0, proc_param=0x0, select_options=<optimized out>, result=0x7f4c6002be50, unit=0x7f4c6001bf38, select_lex=0x7f4c60028088) at ./sql/sql_select.cc:5038
|
#22 0x000055b967992464 in handle_select (thd=thd@entry=0x7f4c60017d88, lex=lex@entry=0x7f4c6001be70, result=result@entry=0x7f4c6002be50, setup_tables_done_option=setup_tables_done_option@entry=0) at ./sql/sql_select.cc:554
|
#23 0x000055b96791a025 in execute_sqlcom_select (thd=0x7f4c60017d88, all_tables=0x7f4c60029980) at ./sql/sql_parse.cc:6256
|
#24 0x000055b9679294c5 in mysql_execute_command (thd=0x7f4c60017d88, is_called_from_prepared_stmt=<optimized out>) at ./sql/sql_parse.cc:3946
|
#25 0x000055b96792aa77 in mysql_parse (thd=0x7f4c60017d88, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at ./sql/sql_parse.cc:8016
|
#26 0x000055b96792d1c5 in dispatch_command (command=<optimized out>, thd=0x7f4c60017d88, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at ./sql/sql_parse.cc:1993
|
#27 0x000055b96792eda8 in do_command (thd=0x7f4c60017d88, blocking=blocking@entry=true) at ./sql/sql_parse.cc:1409
|
a#28 0x000055b967a3d98f in do_handle_one_connection (connect=<optimized out>, put_in_cache=true) at ./sql/sql_connect.cc:1416
|
#29 0x000055b967a3dcdd in handle_one_connection (arg=arg@entry=0x55b96b006d98) at ./sql/sql_connect.cc:1318
|
#30 0x000055b967daa266 in pfs_spawn_thread (arg=0x55b96b0021a8) at ./storage/perfschema/pfs.cc:2201
|
#31 0x00007f69d229eb43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
|
#32 0x00007f69d2330a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
|
All waiting threads on fil_space_t S latch (about 2500 threads)
0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
|
#1 0x000055b967f42718 in srw_mutex_impl<false>::wait (lk=<optimized out>, this=0x55b96aeeb960) at ./storage/innobase/sync/srw_lock.cc:238
|
#2 srw_mutex_impl<false>::wait_and_lock (this=this@entry=0x55b96aeeb960) at ./storage/innobase/sync/srw_lock.cc:326
|
#3 0x000055b967f429ae in srw_mutex_impl<false>::wr_lock (this=0x55b96aeeb960) at ./storage/innobase/include/srw_lock.h:134
|
#4 ssux_lock_impl<false>::rd_wait (this=this@entry=0x55b96aeeb960) at ./storage/innobase/sync/srw_lock.cc:392
|
#5 0x000055b967e6434a in ssux_lock_impl<false>::rd_lock (this=<optimized out>) at ./storage/innobase/include/srw_lock.h:247
|
#6 srw_lock_impl<false>::rd_lock (line=1075, file=0x55b968307298 "./storage/innobase/include/fil0fil.h", this=0x55b96aeeb958) at ./storage/innobase/include/srw_lock.h:515
|
#7 fil_space_t::s_lock (this=0x55b96aeeb8b8) at ./storage/innobase/include/fil0fil.h:1075
|
#8 ha_innobase::info_low (this=0x7f501c1d49d0, flag=282, is_analyze=<optimized out>) at ./storage/innobase/handler/ha_innodb.cc:14832
|
#9 0x000055b967e6a298 in ha_innobase::info (flag=282, this=0x7f501c1d49d0) at ./storage/innobase/handler/ha_innodb.cc:15034
|
#10 ha_innobase::open (this=<optimized out>, name=<optimized out>) at ./storage/innobase/handler/ha_innodb.cc:6197
|
#11 0x000055b967b6238a in handler::ha_open (this=0x7f501c1d49d0, table_arg=table_arg@entry=0x7f501c1d41a8, name=0x7f4ddc31b1b8 "./tndb_prod_2/messages_inno", mode=mode@entry=2, test_if_locked=test_if_locked@entry=18, mem_root=mem_root@entry=0x0, partitions_to_open=0x0) at ./sql/handler.cc:3333
|
#12 0x000055b967a0de3b in open_table_from_share (thd=thd@entry=0x7f501c1be108, share=share@entry=0x7f4ddc31ad00, alias=alias@entry=0x7f501c1ce8a8, db_stat=db_stat@entry=33, prgflag=prgflag@entry=8, ha_open_flags=18, outparam=<optimized out>, is_create_table=<optimized out>, partitions_to_open=<optimized out>) at ./sql/table.cc:4417
|
#13 0x000055b9678b8475 in open_table (thd=0x7f501c1be108, table_list=0x7f501c1ce860, ot_ctx=0x7f4c2b460190) at ./sql/sql_base.cc:2036
|
#14 0x000055b9678bb29a in open_and_process_table (ot_ctx=0x7f4c2b460190, has_prelocking_list=false, prelocking_strategy=0x7f4c2b460280, flags=0, counter=0x7f4c2b46022c, tables=0x7f501c1ce860, thd=0x7f501c1be108) at ./sql/sql_base.cc:3847
|
#15 open_tables (thd=thd@entry=0x7f501c1be108, options=..., start=start@entry=0x7f4c2b460218, counter=counter@entry=0x7f4c2b46022c, flags=flags@entry=0, prelocking_strategy=prelocking_strategy@entry=0x7f4c2b460280) at ./sql/sql_base.cc:4330
|
#16 0x000055b9678bbb19 in open_and_lock_tables (thd=thd@entry=0x7f501c1be108, options=..., tables=<optimized out>, tables@entry=0x7f501c1ce860, derived=derived@entry=true, flags=flags@entry=0, prelocking_strategy=prelocking_strategy@entry=0x7f4c2b460280) at ./sql/sql_base.cc:5303
|
#17 0x000055b967919fd1 in open_and_lock_tables (flags=0, derived=true, tables=0x7f501c1ce860, thd=0x7f501c1be108) at ./sql/sql_base.h:509
|
#18 execute_sqlcom_select (thd=0x7f501c1be108, all_tables=0x7f501c1ce860) at ./sql/sql_parse.cc:6177
|
#19 0x000055b9679294c5 in mysql_execute_command (thd=0x7f501c1be108, is_called_from_prepared_stmt=<optimized out>) at ./sql/sql_parse.cc:3946
|
#20 0x000055b96792aa77 in mysql_parse (thd=0x7f501c1be108, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at ./sql/sql_parse.cc:8016
|
#21 0x000055b96792d1c5 in dispatch_command (command=<optimized out>, thd=0x7f501c1be108, packet=<optimized out>, packet_length=<optimized out>, blocking=<optimized out>) at ./sql/sql_parse.cc:1993
|
#22 0x000055b96792eda8 in do_command (thd=0x7f501c1be108, blocking=blocking@entry=true) at ./sql/sql_parse.cc:1409
|
#23 0x000055b967a3d98f in do_handle_one_connection (connect=<optimized out>, put_in_cache=true) at ./sql/sql_connect.cc:1416
|
#24 0x000055b967a3dcdd in handle_one_connection (arg=arg@entry=0x55b96b4ee598) at ./sql/sql_connect.cc:1318
|
#25 0x000055b967daa266 in pfs_spawn_thread (arg=0x55b96b4ee608) at ./storage/perfschema/pfs.cc:2201
|
#26 0x00007f69d229eb43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
|
#27 0x00007f69d2330a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
|
unfortunately, there is no mtr testcase. Is this an existing issue? Any bug fix(MDEV issue) that fixes this problem in recent versions?
|