Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-30637

Mariadb server hangs

    XMLWordPrintable

Details

    • Bug
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Incomplete
    • 10.6.11
    • N/A
    • None
    • ubuntu linux

    Description

      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?

      Attachments

        Issue Links

          Activity

            People

              marko Marko Mäkelä
              satya.bodapati Satya Bodapati
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.