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

sysbench drops tps to 0 in write only scenario

    XMLWordPrintable

Details

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

    Description

      In the 4u16gb environment, execute the following commands:

      ./sysbench --db-driver=mysql --report-interval=1 --tables=128 --table-size=25000 --mysql-db=white_paper --mysql-host=192.168.65.251 --mysql-port=3306 --mysql-user=root --mysql-password=xxx --threads=100 --time=150 --percentile=95 ./oltp_write_only.lua prepare  
       
      ./sysbench --db-driver=mysql --report-interval=1 --tables=128 --table-size=25000 --mysql-db=white_paper --mysql-host=192.168.65.251 --mysql-port=3306 --mysql-user=root --mysql-password=xxx --threads=200 --time=150 --percentile=95 ./oltp_write_only.lua run  
      

      In the 10.5.16 environment, the data behaves normally, and there are no instances where TPS drops to 0. However, in the 10.11.11 environment, TPS occasionally drops to 0 for a few seconds, as shown below:

      [ 34s ] thds: 200 tps: 4403.88 qps: 26165.27 (r/w/o: 0.00/17386.51/8778.75) lat (ms,95%): 94.10 err/s: 0.00 reconn/s: 0.00  
      [ 35s ] thds: 200 tps: 4236.78 qps: 25621.65 (r/w/o: 0.00/17155.09/8466.55) lat (ms,95%): 80.03 err/s: 0.00 reconn/s: 0.00  
      [ 36s ] thds: 200 tps: 612.05 qps: 3556.29 (r/w/o: 0.00/2319.19/1237.10) lat (ms,95%): 80.03 err/s: 0.00 reconn/s: 0.00  
      [ 37s ] thds: 200 tps: 0.00 qps: 7.00 (r/w/o: 0.00/7.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00  
      [ 38s ] thds: 200 tps: 0.00 qps: 5.00 (r/w/o: 0.00/5.00/0.00) lat (ms,95%): 0.00 err/s: 0.00 reconn/s: 0.00  
      [ 39s ] thds: 200 tps: 29.00 qps: 142.00 (r/w/o: 0.00/86.00/56.00) lat (ms,95%): 3911.79 err/s: 0.00 reconn/s: 0.00  
      [ 40s ] thds: 200 tps: 3773.98 qps: 22713.88 (r/w/o: 0.00/15168.92/7544.96) lat (ms,95%): 114.72 err/s: 0.00 reconn/s: 0.00  
      [ 41s ] thds: 200 tps: 4056.79 qps: 24243.75 (r/w/o: 0.00/16124.17/8119.58) lat (ms,95%): 90.78 err/s: 0.00 reconn/s: 0.00  
      

      When performing a pstack dump during the periods where TPS drops to 0, it was found that many threads were stuck in lock-waiting stacks, whereas this does not occur under normal conditions. The stack trace is as follows:

      Thread 569 (LWP 1108834):  
      #0  0x00007f42b327de99 in syscall () from /lib64/libc.so.6  
      #1  0x0000563a7a32cd70 in srw_mutex_impl<true>::wait (lk=<optimized out>, this=0x7f4288097c38) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/storage/innobase/sync/srw_lock.cc:252  
      #2  srw_mutex_impl<true>::wait_and_lock (this=this@entry=0x7f4288097c38) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/storage/innobase/sync/srw_lock.cc:313  
      #3  0x0000563a79bebd98 in srw_mutex_impl<true>::wr_lock (this=0x7f4288097c38) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/storage/innobase/include/buf0buf.h:1276  
      #4  ssux_lock_impl<true>::wr_lock (this=0x7f4288097c38) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/storage/innobase/include/srw_lock.h:271  
      #5  sux_lock<ssux_lock_impl<true> >::x_lock_upgraded (this=0x7f4288097c38) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/storage/innobase/include/sux_lock.h:460  
      #6  buf_page_get_low (page_id=..., zip_size=<optimized out>, rw_latch=<optimized out>, guess=<optimized out>, mode=<optimized out>, mtr=0x7f4073a6bbb0, err=<optimized out>, allow_ibuf_merge=<optimized out>) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/storage/innobase/buf/buf0buf.cc:3286  
      #7  0x0000563a7a3740cd in btr_cur_t::search_leaf (this=this@entry=0x7f40783a9bc0, tuple=tuple@entry=0x7f42984dc5c0, mode=<optimized out>, latch_mode=latch_mode@entry=BTR_MODIFY_LEAF, mtr=mtr@entry=0x7f4073a6bbb0) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/storage/innobase/btr/btr0cur.cc:1268  
      #8  0x0000563a79be8e1c in btr_pcur_open_with_no_init (mtr=0x7f4073a6bbb0, cursor=0x7f40783a9bc0, latch_mode=BTR_MODIFY_LEAF, mode=<optimized out>, tuple=0x7f42984dc5c0) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/storage/innobase/include/btr0pcur.inl:322  
      #9  btr_pcur_t::restore_position (this=this@entry=0x7f40783a9bc0, restore_latch_mode=BTR_MODIFY_LEAF, mtr=mtr@entry=0x7f4073a6bbb0) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/storage/innobase/btr/btr0pcur.cc:437  
      #10 0x0000563a7a3234fe in row_upd_clust_step (node=0x7f40783a9aa0, thr=0x7f40783a9eb0) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/storage/innobase/row/row0upd.cc:2632  
      #11 0x0000563a7a324cd0 in row_upd (thr=0x7f40783a9eb0, node=0x7f40783a9aa0) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/storage/innobase/row/row0upd.cc:2779  
      #12 row_upd_step (thr=thr@entry=0x7f40783a9eb0) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/storage/innobase/row/row0upd.cc:2921  
      #13 0x0000563a7a2fe7cc in row_update_for_mysql (prebuilt=0x7f40783a9340) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/storage/innobase/row/row0mysql.cc:1663  
      #14 0x0000563a7a242777 in ha_innobase::delete_row (this=0x7f40783a7300, record=<optimized out>) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/storage/innobase/handler/ha_innodb.cc:8743  
      #15 0x0000563a79f72d28 in handler::ha_delete_row (this=0x7f40783a7300, buf=0x7f40783a7b00 "\377I1") at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/sql/handler.cc:7893  
      #16 0x0000563a79cbaa08 in mysql_delete (thd=thd@entry=0x7f4054b54188, table_list=<optimized out>, conds=<optimized out>, order_list=order_list@entry=0x7f40237a81d0, limit=18446744073709551615, options=<optimized out>, result=<optimized out>) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/sql/sql_delete.cc:867  
      #17 0x0000563a79d046d9 in mysql_execute_command (thd=0x7f4054b54188, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=true) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/sql/sql_limit.h:94  
      #18 0x0000563a79d27c03 in Prepared_statement::execute (this=0x7f40237a71c8, expanded_query=<optimized out>, open_cursor=<optimized out>) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/sql/sql_prepare.cc:5281  
      #19 0x0000563a79d27eb7 in Prepared_statement::execute_loop (packet=<optimized out>, packet_end=<optimized out>, open_cursor=<optimized out>, expanded_query=0x7f4073a6d2a0, this=0x7f40237a71c8) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/sql/sql_prepare.cc:4682  
      #20 Prepared_statement::execute_loop (this=0x7f40237a71c8, expanded_query=0x7f4073a6d2a0, open_cursor=<optimized out>, packet=<optimized out>, packet_end=<optimized out>) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/sql/sql_prepare.cc:4631  
      #21 0x0000563a79d28965 in mysql_stmt_execute_common (thd=0x7f4054b54188, stmt_id=<optimized out>, packet=0x7f405551ad82 "", packet_end=0x7f405551ad8e "", cursor_flags=0, bulk_op=<optimized out>, read_types=false) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/sql/sql_prepare.cc:3597  
      #22 0x0000563a79d28b4c in mysqld_stmt_execute (thd=thd@entry=0x7f4054b54188, packet_arg=packet_arg@entry=0x7f405551ad79 "}\001", packet_length=packet_length@entry=21) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/sql/sql_prepare.cc:3368  
      #23 0x0000563a79d08d91 in dispatch_command (command=COM_STMT_EXECUTE, thd=0x7f4054b54188, packet=0x7f405551ad79 "}\001", packet_length=<optimized out>, blocking=<optimized out>) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/sql/sql_parse.cc:1831  
      #24 0x0000563a79d0a453 in do_command (thd=thd@entry=0x7f4054b54188, blocking=blocking@entry=false) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/sql/sql_parse.cc:1419  
      #25 0x0000563a79eef37b in threadpool_process_request (thd=0x7f4054b54188) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/sql/threadpool_common.cc:438  
      #26 tp_callback (c=0x563a82f2aae0) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/sql/threadpool_common.cc:252  
      #27 0x0000563a7a0f8aad in worker_main (param=param@entry=0x563a7db00dc8) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/sql/threadpool_generic.cc:1556  
      #28 0x0000563a7a1c2c99 in pfs_spawn_thread (arg=0x7f402c785148) at /data/fuxi_ci_workspace/6836726a778a61604ca7bf1a/mariadb_105_x86/storage/perfschema/pfs.cc:2201  
      #29 0x00007f42b334bf3b in ?? () from /lib64/libpthread.so.0  
      --Type <RET> for more, q to quit, c to continue without paging--  
      #30 0x00007f42b3283520 in clone () from /lib64/libc.so.6  
      

      Comparing with 10.5.16, I found a relevant MR modification: "Replace InnoDB rw_lock_t with sux_lock": https://github.com/MariaDB/server/commit/03ca6495df31313c96e38834b9a235245e2ae2a8
      This issue is suspected to be caused by this modification.

      Attachments

        Issue Links

          Activity

            People

              marko Marko Mäkelä
              ohye3188 小舟从此逝
              Votes:
              0 Vote for this issue
              Watchers:
              3 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.