// Start up and build used scripts/mysql_install_db --basedir=/export/umesh/server/binaries/mysql-5.6.25 --datadir=/export/umesh/server/binaries/mysql-5.6.25/21128134 bin/mysqld --basedir=/export/umesh/server/binaries/mysql-5.6.25 --datadir=/export/umesh/server/binaries/mysql-5.6.25/21128134 --core-file --socket=/tmp/mysql_ushastry.sock --port=15000 --log-error=/export/umesh/server/binaries/mysql-5.6.25/21128134/log.err 2>&1 & commit: 9294a4969387cd882ef2ae3ee001aed9ecd13616 date: 2015-05-05 12:50:42 +0200 build-date: 2015-05-05 12:54:12 +0200 short: 9294a49 branch: mysql-5.6.25-release MySQL source 5.6.25 // Session 1 ( completed after >30+min) [umshastr@hod03]~/bugs/sysbench: bin/sysbench --version sysbench 0.5 [umshastr@hod03]~/bugs/sysbench: bin/sysbench --test=sysbench/tests/db/oltp.lua --oltp-table-size=50000000 --mysql-db=test --mysql-user=root --mysql-socket=/tmp/mysql_ushastry.sock prepare sysbench 0.5: multi-threaded system evaluation benchmark Creating table 'sbtest1'... Inserting 50000000 records into 'sbtest1' // Session 2 (Had to wait for 5+ minutes to see that hang) mysql> show variables like '%version%'; +-------------------------+---------------------------------------------------------+ | Variable_name | Value | +-------------------------+---------------------------------------------------------+ | innodb_version | 5.6.25 | | protocol_version | 10 | | slave_type_conversions | | | version | 5.6.25-enterprise-commercial-advanced | | version_comment | MySQL Enterprise Server - Advanced Edition (Commercial) | | version_compile_machine | x86_64 | | version_compile_os | linux-glibc2.5 | +-------------------------+---------------------------------------------------------+ 7 rows in set (0.00 sec) mysql> create table app (id int primary key); Query OK, 0 rows affected (0.01 sec) mysql> select * from app; Empty set (0.00 sec) mysql> flush tables app for export; Query OK, 0 rows affected (0.00 sec) mysql> unlock tables; Query OK, 0 rows affected (0.00 sec) mysql> flush tables app for export; Query OK, 0 rows affected (0.01 sec) mysql> unlock tables; Query OK, 0 rows affected (0.00 sec) mysql> flush tables app for export; Query OK, 0 rows affected (0.00 sec) mysql> unlock tables; Query OK, 0 rows affected (0.00 sec) mysql> flush tables app for export; Query OK, 0 rows affected (57 min 6.64 sec) mysql> // mysql> show processlist; +----+------+-----------+------+---------+------+-------------+-----------------------------+ | Id | User | Host | db | Command | Time | State | Info | +----+------+-----------+------+---------+------+-------------+-----------------------------+ | 2 | root | localhost | test | Query | 3174 | System lock | flush tables app for export | | 4 | root | localhost | NULL | Query | 0 | init | show processlist | +----+------+-----------+------+---------+------+-------------+-----------------------------+ 2 rows in set (0.00 sec) // [umshastr@hod03]~/bugs: perf record -g --pid=29945 [umshastr@hod03]~/bugs: perf report|c++filt # ======== # captured on: Fri May 22 09:47:57 2015 # hostname : hod03 # os release : 3.8.13-44.1.1.el7uek.x86_64 # perf version : 3.8.13-44.1.1.el7uek.x86_64 # arch : x86_64 # nrcpus online : 32 # nrcpus avail : 32 # cpudesc : Intel(R) Xeon(R) CPU E5-2650 v2 @ 2.60GHz # cpuid : GenuineIntel,6,62,4 # total memory : 264098884 kB # cmdline : /usr/libexec/perf.3.8.13-44.1.1.el7uek.x86_64 record -g --pid=29945 # event : name = cycles, type = 0, config = 0x0, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, excl_host = 0, excl_guest = 1, precise_ip = 0, id = { 854, 855, 856, 857, 858, 859, 86 0, 861, 862, 863, 864, 865, 866, 867, 868, 869, 870, 871, 872, 873, 874, 875, 876, 877 } # HEADER_CPU_TOPOLOGY info available, use -I to display # HEADER_NUMA_TOPOLOGY info available, use -I to display # pmu mappings: cpu = 4, software = 1, tracepoint = 2, breakpoint = 5 # ======== # # Samples: 3M of event 'cycles' # Event count (approx.): 1920504956731 # # Overhead Command Shared Object Symbol # ........ ....... ................... ........................................................................................................................................................ ....................................... # 15.70% mysqld mysqld [.] buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*) | --- buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*) | |--73.61%-- btr_cur_search_to_nth_level(dict_index_t*, unsigned long, dtuple_t const*, unsigned long, unsigned long, btr_cur_t*, unsigned long, char const*, unsigned long, mtr_t* ) | | | |--85.95%-- ibuf_merge(unsigned long, unsigned long*, bool) | | ibuf_contract_in_background(unsigned long, unsigned long) | | row_quiesce_table_start(dict_table_t*, trx_t*) | | ha_innobase::external_lock(THD*, int) | | handler::ha_external_lock(THD*, int) | | mysql_lock_tables(THD*, TABLE**, unsigned int, unsigned int) | | lock_tables(THD*, TABLE_LIST*, unsigned int, unsigned int) | | open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*) | | flush_tables_for_export(THD*, TABLE_LIST*) | | mysql_execute_command(THD*) | | mysql_parse(THD*, char*, unsigned int, Parser_state*) | | dispatch_command(enum_server_command, THD*, char*, unsigned int) | | do_command(THD*) | | do_handle_one_connection(THD*) | | handle_one_connection | | pfs_spawn_thread | | start_thread | | | |--6.32%-- row_ins_sec_index_entry_low(unsigned long, unsigned long, dict_index_t*, mem_block_info_t*, mem_block_info_t*, dtuple_t*, unsigned long, que_thr_t*) | | row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*) | | row_ins_step(que_thr_t*) | | row_insert_for_mysql(unsigned char*, row_prebuilt_t*) | | ha_innobase::write_row(unsigned char*) | | handler::ha_write_row(unsigned char*) | | write_record(THD*, TABLE*, COPY_INFO*, COPY_INFO*) | | mysql_insert(THD*, TABLE_LIST*, List&, List >&, List&, List&, enum_duplicates, bool) | | mysql_execute_command(THD*) | | mysql_parse(THD*, char*, unsigned int, Parser_state*) | | dispatch_command(enum_server_command, THD*, char*, unsigned int) | | do_command(THD*) | | do_handle_one_connection(THD*) | | handle_one_connection | | pfs_spawn_thread | | start_thread | | | |--5.00%-- ibuf_insert_low(unsigned long, ibuf_op_t, unsigned long, dtuple_t const*, unsigned long, dict_index_t*, unsigned long, unsigned long, unsigned long, que_thr _t*) | | ibuf_insert(ibuf_op_t, dtuple_t const*, dict_index_t*, unsigned long, unsigned long, unsigned long, que_thr_t*) | | btr_cur_search_to_nth_level(dict_index_t*, unsigned long, dtuple_t const*, unsigned long, unsigned long, btr_cur_t*, unsigned long, char const*, unsigned lo ng, mtr_t*) | | row_ins_sec_index_entry_low(unsigned long, unsigned long, dict_index_t*, mem_block_info_t*, mem_block_info_t*, dtuple_t*, unsigned long, que_thr_t*) | | row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*) | | row_ins_step(que_thr_t*) | | row_insert_for_mysql(unsigned char*, row_prebuilt_t*) | | ha_innobase::write_row(unsigned char*) | | handler::ha_write_row(unsigned char*) | | write_record(THD*, TABLE*, COPY_INFO*, COPY_INFO*) | | mysql_insert(THD*, TABLE_LIST*, List&, List >&, List&, List&, enum_duplicates, bool) | | mysql_execute_command(THD*) | | mysql_parse(THD*, char*, unsigned int, Parser_state*) | | dispatch_command(enum_server_command, THD*, char*, unsigned int) | | do_command(THD*) | | do_handle_one_connection(THD*) | | handle_one_connection | | pfs_spawn_thread | | start_thread | | | |--1.20%-- btr_pcur_open_on_user_rec_func(dict_index_t*, dtuple_t const*, unsigned long, unsigned long, btr_pcur_t*, char const*, unsigned long, mtr_t*) | | ibuf_merge_or_delete_for_page(buf_block_t*, unsigned long, unsigned long, unsigned long, unsigned long) | | buf_page_io_complete(buf_page_t*) | | | | | |--87.08%-- fil_aio_wait(unsigned long) | | | io_handler_thread | | | start_thread | | | | | --12.92%-- buf_read_page_low(dberr_t*, bool, unsigned long, unsigned long, unsigned long, unsigned long, long, unsigned long) | | | | | |--58.22%-- buf_read_ibuf_merge_pages(bool, unsigned long const*, long const*, unsigned long const*, unsigned long) | | | ibuf_merge(unsigned long, unsigned long*, bool) | | | ibuf_insert_low(unsigned long, ibuf_op_t, unsigned long, dtuple_t const*, unsigned long, dict_index_t*, unsigned long, unsigned long, unsigned long, que_thr_t*) | | | ibuf_insert(ibuf_op_t, dtuple_t const*, dict_index_t*, unsigned long, unsigned long, unsigned long, que_thr_t*) | | | btr_cur_search_to_nth_level(dict_index_t*, unsigned long, dtuple_t const*, unsigned long, unsigned long, btr_cur_t*, unsigned long, ch ar const*, unsigned long, mtr_t*) | | | row_ins_sec_index_entry_low(unsigned long, unsigned long, dict_index_t*, mem_block_info_t*, mem_block_info_t*, dtuple_t*, unsigne g, que_thr_t*) | | | row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*) | | | row_ins_step(que_thr_t*) | | | row_insert_for_mysql(unsigned char*, row_prebuilt_t*) | | | ha_innobase::write_row(unsigned char*) | | | handler::ha_write_row(unsigned char*) | | | write_record(THD*, TABLE*, COPY_INFO*, COPY_INFO*) | | | mysql_insert(THD*, TABLE_LIST*, List&, List >&, List&, List&, enum_duplicates, bool) | | | mysql_execute_command(THD*) | | | mysql_parse(THD*, char*, unsigned int, Parser_state*) | | | dispatch_command(enum_server_command, THD*, char*, unsigned int) | | | do_command(THD*) | | | do_handle_one_connection(THD*) | | | handle_one_connection | | | pfs_spawn_thread | | | start_thread | | | | | --41.78%-- buf_read_page(unsigned long, unsigned long, unsigned long) | | buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*) | | | | | |--83.61%-- btr_cur_latch_leaves(unsigned char*, unsigned long, unsigned long, unsigned long, unsigned long, btr_cur_t*, mtr_t*) | | | btr_cur_search_to_nth_level(dict_index_t*, unsigned long, dtuple_t const*, unsigned long, unsigned long, btr_cur_t*, unsign ed long, char const*, unsigned long, mtr_t*) | | | row_ins_sec_index_entry_low(unsigned long, unsigned long, dict_index_t*, mem_block_info_t*, mem_block_info_t*, dtuple_t*, u nsigned long, que_thr_t*) | | | row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*) | | | row_ins_step(que_thr_t*) | | | row_insert_for_mysql(unsigned char*, row_prebuilt_t*) | | | ha_innobase::write_row(unsigned char*) | | | handler::ha_write_row(unsigned char*) | | | write_record(THD*, TABLE*, COPY_INFO*, COPY_INFO*) | | | mysql_insert(THD*, TABLE_LIST*, List&, List >&, List&, List&, enum_duplicates, bool) | | | mysql_execute_command(THD*) | | | mysql_parse(THD*, char*, unsigned int, Parser_state*) | | | dispatch_command(enum_server_command, THD*, char*, unsigned int) | | | do_command(THD*) | | | do_handle_one_connection(THD*) | | | handle_one_connection | | | pfs_spawn_thread | | | start_thread | | | | | --16.39%-- btr_cur_search_to_nth_level(dict_index_t*, unsigned long, dtuple_t const*, unsigned long, unsigned long, btr_cur_t*, unsig ned long, char const*, unsigned long, mtr_t*) | | row_ins_sec_index_entry_low(unsigned long, unsigned long, dict_index_t*, mem_block_info_t*, mem_block_info_t*, dtuple_t*, u nsigned long, que_thr_t*) | | row_ins_sec_index_entry(dict_index_t*, dtuple_t*, que_thr_t*) | | row_ins_step(que_thr_t*) | | row_insert_for_mysql(unsigned char*, row_prebuilt_t*) | | ha_innobase::write_row(unsigned char*) | | handler::ha_write_row(unsigned char*) | | write_record(THD*, TABLE*, COPY_INFO*, COPY_INFO*) | | mysql_insert(THD*, TABLE_LIST*, List&, List >&, List&, List&, enum_duplicates, bool) | | mysql_execute_command(THD*) | | mysql_parse(THD*, char*, unsigned int, Parser_state*)