Percona XtraDB Storage Engine for MySQL

XtraDB hangs in 10 threads TPC-C

Reported by Vadim Tkachenko on 2009-02-07
2
Affects Status Importance Assigned to Milestone
Percona-XtraDB
Fix Released
Critical
Unassigned
Percona patches
Fix Released
Medium
Unassigned

Bug Description

(gdb) info threads
  20 Thread 0x40a2f950 (LWP 13698) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  19 Thread 0x41776950 (LWP 13699) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  18 Thread 0x41f77950 (LWP 13700) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  17 Thread 0x42778950 (LWP 13701) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  16 Thread 0x4377a950 (LWP 13721) 0x00007ffdc811c482 in select () from /lib/libc.so.6
  15 Thread 0x43f7b950 (LWP 13722) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  14 Thread 0x4477c950 (LWP 13723) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  13 Thread 0x447bd950 (LWP 13724) 0x00007ffdc93d4e7b in sigwait () from /lib/libpthread.so.0
  12 Thread 0x40a70950 (LWP 13761) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  11 Thread 0x447fe950 (LWP 13763) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  10 Thread 0x4483f950 (LWP 13766) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  9 Thread 0x44880950 (LWP 13768) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  8 Thread 0x448c1950 (LWP 13770) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  7 Thread 0x44902950 (LWP 13771) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  6 Thread 0x44943950 (LWP 13772) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  5 Thread 0x44984950 (LWP 13773) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  4 Thread 0x449c5950 (LWP 13774) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  3 Thread 0x44a06950 (LWP 13775) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  2 Thread 0x40c8c950 (LWP 15994) 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  1 Thread 0x7ffdc97f46f0 (LWP 13695) 0x00007ffdc811c482 in select () from /lib/libc.so.6

(gdb) thread apply all backtrace

Thread 20 (Thread 0x40a2f950 (LWP 13698)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x0000000000794123 in os_aio_simulated_handle ()
#3 0x000000000075db3f in fil_aio_wait ()
#4 0x00000000007d5540 in io_handler_thread ()
#5 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#6 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 19 (Thread 0x41776950 (LWP 13699)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x0000000000794123 in os_aio_simulated_handle ()
#3 0x000000000075db3f in fil_aio_wait ()
#4 0x00000000007d5540 in io_handler_thread ()
#5 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#6 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 18 (Thread 0x41f77950 (LWP 13700)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x0000000000794123 in os_aio_simulated_handle ()
#3 0x000000000075db3f in fil_aio_wait ()
#4 0x00000000007d5540 in io_handler_thread ()
#5 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#6 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 17 (Thread 0x42778950 (LWP 13701)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x00000000007d811c in sync_array_wait_event ()
#3 0x00000000007d97a2 in mutex_spin_wait ()
#4 0x000000000073c1cc in buf_page_io_complete ()
#5 0x000000000075dcb7 in fil_aio_wait ()
#6 0x00000000007d5540 in io_handler_thread ()
#7 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#8 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#9 0x0000000000000000 in ?? ()

Thread 16 (Thread 0x4377a950 (LWP 13721)):
#0 0x00007ffdc811c482 in select () from /lib/libc.so.6
#1 0x0000000000797adb in os_thread_sleep ()
#2 0x00000000007d4435 in srv_lock_timeout_and_monitor_thread ()
#3 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#4 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#5 0x0000000000000000 in ?? ()

Thread 15 (Thread 0x43f7b950 (LWP 13722)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x00000000007d811c in sync_array_wait_event ()
#3 0x00000000007d97a2 in mutex_spin_wait ()
#4 0x00000000007d31eb in srv_error_monitor_thread ()
---Type <return> to continue, or q <return> to quit---
#5 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#6 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 14 (Thread 0x4477c950 (LWP 13723)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x00000000007d811c in sync_array_wait_event ()
#3 0x00000000007d97a2 in mutex_spin_wait ()
#4 0x000000000078607b in log_buffer_flush_to_disk ()
#5 0x00000000007d22b1 in srv_master_thread ()
#6 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#7 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#8 0x0000000000000000 in ?? ()

Thread 13 (Thread 0x447bd950 (LWP 13724)):
#0 0x00007ffdc93d4e7b in sigwait () from /lib/libpthread.so.0
#1 0x000000000059e45b in signal_hand ()
#2 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#3 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#4 0x0000000000000000 in ?? ()

Thread 12 (Thread 0x40a70950 (LWP 13761)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x00000000007d811c in sync_array_wait_event ()
#3 0x00000000007d88ca in rw_lock_s_lock_spin ()
#4 0x000000000073e16f in buf_page_get_gen ()
#5 0x00000000007778fd in ibuf_insert_low ()
#6 0x0000000000778ad5 in ibuf_insert ()
#7 0x000000000072ccf8 in btr_cur_search_to_nth_level ()
#8 0x00000000007b3766 in row_ins_index_entry_low ()
#9 0x00000000007b4bc7 in row_ins_step ()
#10 0x00000000007bb656 in row_insert_for_mysql ()
#11 0x000000000072095e in ha_innobase::write_row ()
#12 0x000000000068a8a5 in handler::ha_write_row ()
#13 0x0000000000619abc in write_record ()
#14 0x000000000061d865 in mysql_insert ()
#15 0x00000000005af4bb in mysql_execute_command ()
#16 0x0000000000622cca in Prepared_statement::execute ()
#17 0x0000000000625c8c in Prepared_statement::execute_loop ()
#18 0x0000000000626365 in mysql_stmt_execute ()
#19 0x00000000005b482e in dispatch_command ()
#20 0x00000000005b5ad6 in do_command ()
#21 0x00000000005a8646 in handle_one_connection ()
#22 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#23 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#24 0x0000000000000000 in ?? ()

Thread 11 (Thread 0x447fe950 (LWP 13763)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x00000000007d811c in sync_array_wait_event ()
#3 0x00000000007d88ca in rw_lock_s_lock_spin ()
#4 0x000000000073e16f in buf_page_get_gen ()
#5 0x00000000007778fd in ibuf_insert_low ()
#6 0x0000000000778ad5 in ibuf_insert ()
---Type <return> to continue, or q <return> to quit---
#7 0x000000000072ccf8 in btr_cur_search_to_nth_level ()
#8 0x00000000007b3766 in row_ins_index_entry_low ()
#9 0x00000000007b4bc7 in row_ins_step ()
#10 0x00000000007bb656 in row_insert_for_mysql ()
#11 0x000000000072095e in ha_innobase::write_row ()
#12 0x000000000068a8a5 in handler::ha_write_row ()
#13 0x0000000000619abc in write_record ()
#14 0x000000000061d865 in mysql_insert ()
#15 0x00000000005af4bb in mysql_execute_command ()
#16 0x0000000000622cca in Prepared_statement::execute ()
#17 0x0000000000625c8c in Prepared_statement::execute_loop ()
#18 0x0000000000626365 in mysql_stmt_execute ()
#19 0x00000000005b482e in dispatch_command ()
#20 0x00000000005b5ad6 in do_command ()
#21 0x00000000005a8646 in handle_one_connection ()
#22 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#23 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#24 0x0000000000000000 in ?? ()

Thread 10 (Thread 0x4483f950 (LWP 13766)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x0000000000742732 in buf_flush_buffered_writes ()
#3 0x0000000000743bea in buf_flush_batch ()
#4 0x00000000007444fa in buf_flush_free_margin ()
#5 0x0000000000749e8f in buf_read_page ()
#6 0x000000000073ee3d in buf_page_get_gen ()
#7 0x000000000072ca0e in btr_cur_search_to_nth_level ()
#8 0x00000000007c61b3 in row_search_for_mysql ()
#9 0x000000000071ceda in ha_innobase::index_read ()
#10 0x0000000000686609 in handler::index_read_idx_map ()
#11 0x00000000005ffb65 in join_read_const ()
#12 0x000000000060790d in join_read_const_table ()
#13 0x000000000060cdfe in make_join_statistics ()
#14 0x000000000060e7db in JOIN::optimize ()
#15 0x0000000000611d40 in mysql_select ()
#16 0x000000000061754c in handle_select ()
#17 0x00000000005abecd in execute_sqlcom_select ()
#18 0x00000000005afbc3 in mysql_execute_command ()
#19 0x0000000000622cca in Prepared_statement::execute ()
#20 0x0000000000625c8c in Prepared_statement::execute_loop ()
#21 0x0000000000626365 in mysql_stmt_execute ()
#22 0x00000000005b482e in dispatch_command ()
#23 0x00000000005b5ad6 in do_command ()
#24 0x00000000005a8646 in handle_one_connection ()
#25 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#26 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#27 0x0000000000000000 in ?? ()

Thread 9 (Thread 0x44880950 (LWP 13768)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x00000000007d811c in sync_array_wait_event ()
#3 0x00000000007d88ca in rw_lock_s_lock_spin ()
#4 0x000000000073e16f in buf_page_get_gen ()
#5 0x000000000072ca0e in btr_cur_search_to_nth_level ()
#6 0x00000000007c5f78 in row_search_for_mysql ()
---Type <return> to continue, or q <return> to quit---
#7 0x000000000071ceda in ha_innobase::index_read ()
#8 0x0000000000686609 in handler::index_read_idx_map ()
#9 0x00000000005ffb65 in join_read_const ()
#10 0x000000000060790d in join_read_const_table ()
#11 0x000000000060cdfe in make_join_statistics ()
#12 0x000000000060e7db in JOIN::optimize ()
#13 0x0000000000611d40 in mysql_select ()
#14 0x000000000061754c in handle_select ()
#15 0x00000000005abecd in execute_sqlcom_select ()
#16 0x00000000005afbc3 in mysql_execute_command ()
#17 0x0000000000622cca in Prepared_statement::execute ()
#18 0x0000000000625c8c in Prepared_statement::execute_loop ()
#19 0x0000000000626365 in mysql_stmt_execute ()
#20 0x00000000005b482e in dispatch_command ()
#21 0x00000000005b5ad6 in do_command ()
#22 0x00000000005a8646 in handle_one_connection ()
#23 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#24 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#25 0x0000000000000000 in ?? ()

Thread 8 (Thread 0x448c1950 (LWP 13770)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x00000000007d811c in sync_array_wait_event ()
#3 0x00000000007d88ca in rw_lock_s_lock_spin ()
#4 0x000000000073e16f in buf_page_get_gen ()
#5 0x00000000007778fd in ibuf_insert_low ()
#6 0x0000000000778ad5 in ibuf_insert ()
#7 0x000000000072ccf8 in btr_cur_search_to_nth_level ()
#8 0x00000000007b3766 in row_ins_index_entry_low ()
#9 0x00000000007b4bc7 in row_ins_step ()
#10 0x00000000007bb656 in row_insert_for_mysql ()
#11 0x000000000072095e in ha_innobase::write_row ()
#12 0x000000000068a8a5 in handler::ha_write_row ()
#13 0x0000000000619abc in write_record ()
#14 0x000000000061d865 in mysql_insert ()
#15 0x00000000005af4bb in mysql_execute_command ()
#16 0x0000000000622cca in Prepared_statement::execute ()
#17 0x0000000000625c8c in Prepared_statement::execute_loop ()
#18 0x0000000000626365 in mysql_stmt_execute ()
#19 0x00000000005b482e in dispatch_command ()
#20 0x00000000005b5ad6 in do_command ()
#21 0x00000000005a8646 in handle_one_connection ()
#22 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#23 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#24 0x0000000000000000 in ?? ()

Thread 7 (Thread 0x44902950 (LWP 13771)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x00000000007d811c in sync_array_wait_event ()
#3 0x00000000007d88ca in rw_lock_s_lock_spin ()
#4 0x000000000073e16f in buf_page_get_gen ()
#5 0x00000000007778fd in ibuf_insert_low ()
#6 0x0000000000778ad5 in ibuf_insert ()
#7 0x000000000072ccf8 in btr_cur_search_to_nth_level ()
#8 0x00000000007b3766 in row_ins_index_entry_low ()
---Type <return> to continue, or q <return> to quit---
#9 0x00000000007b4bc7 in row_ins_step ()
#10 0x00000000007bb656 in row_insert_for_mysql ()
#11 0x000000000072095e in ha_innobase::write_row ()
#12 0x000000000068a8a5 in handler::ha_write_row ()
#13 0x0000000000619abc in write_record ()
#14 0x000000000061d865 in mysql_insert ()
#15 0x00000000005af4bb in mysql_execute_command ()
#16 0x0000000000622cca in Prepared_statement::execute ()
#17 0x0000000000625c8c in Prepared_statement::execute_loop ()
#18 0x0000000000626365 in mysql_stmt_execute ()
#19 0x00000000005b482e in dispatch_command ()
#20 0x00000000005b5ad6 in do_command ()
#21 0x00000000005a8646 in handle_one_connection ()
#22 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#23 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#24 0x0000000000000000 in ?? ()

Thread 6 (Thread 0x44943950 (LWP 13772)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x00000000007d811c in sync_array_wait_event ()
#3 0x00000000007d936f in rw_lock_x_lock_func ()
#4 0x0000000000747a9b in buf_LRU_free_block ()
#5 0x0000000000748abe in buf_LRU_search_and_free_block ()
#6 0x0000000000748eea in buf_LRU_try_free_flushed_blocks ()
#7 0x000000000072cf85 in btr_cur_search_to_nth_level ()
#8 0x00000000007b3766 in row_ins_index_entry_low ()
#9 0x00000000007b4bc7 in row_ins_step ()
#10 0x00000000007bb656 in row_insert_for_mysql ()
#11 0x000000000072095e in ha_innobase::write_row ()
#12 0x000000000068a8a5 in handler::ha_write_row ()
#13 0x0000000000619abc in write_record ()
#14 0x000000000061d865 in mysql_insert ()
#15 0x00000000005af4bb in mysql_execute_command ()
#16 0x0000000000622cca in Prepared_statement::execute ()
#17 0x0000000000625c8c in Prepared_statement::execute_loop ()
#18 0x0000000000626365 in mysql_stmt_execute ()
#19 0x00000000005b482e in dispatch_command ()
#20 0x00000000005b5ad6 in do_command ()
#21 0x00000000005a8646 in handle_one_connection ()
#22 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#23 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#24 0x0000000000000000 in ?? ()

Thread 5 (Thread 0x44984950 (LWP 13773)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x00000000007d811c in sync_array_wait_event ()
#3 0x00000000007d97a2 in mutex_spin_wait ()
#4 0x0000000000785f76 in log_close ()
#5 0x000000000079162c in mtr_commit ()
#6 0x00000000007ca9ce in row_upd_clust_rec ()
#7 0x00000000007ce410 in row_upd_clust_step ()
#8 0x00000000007cee6b in row_upd_step ()
#9 0x00000000007ba416 in row_update_for_mysql ()
#10 0x000000000071ff4b in ha_innobase::update_row ()
#11 0x000000000068a7c8 in handler::ha_update_row ()
---Type <return> to continue, or q <return> to quit---
#12 0x000000000062aac8 in mysql_update ()
#13 0x00000000005afa84 in mysql_execute_command ()
#14 0x0000000000622cca in Prepared_statement::execute ()
#15 0x0000000000625c8c in Prepared_statement::execute_loop ()
#16 0x0000000000626365 in mysql_stmt_execute ()
#17 0x00000000005b482e in dispatch_command ()
#18 0x00000000005b5ad6 in do_command ()
#19 0x00000000005a8646 in handle_one_connection ()
#20 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#21 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#22 0x0000000000000000 in ?? ()

Thread 4 (Thread 0x449c5950 (LWP 13774)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x00000000007d811c in sync_array_wait_event ()
#3 0x00000000007d88ca in rw_lock_s_lock_spin ()
#4 0x000000000073e16f in buf_page_get_gen ()
#5 0x00000000007721e5 in ibuf_bitmap_get_map_page ()
#6 0x0000000000779702 in ibuf_merge_or_delete_for_page ()
#7 0x000000000073c237 in buf_page_io_complete ()
#8 0x00000000007495f7 in buf_read_page_low ()
#9 0x0000000000749e76 in buf_read_page ()
#10 0x000000000073ee3d in buf_page_get_gen ()
#11 0x000000000072ca0e in btr_cur_search_to_nth_level ()
#12 0x00000000007c61b3 in row_search_for_mysql ()
#13 0x000000000071ceda in ha_innobase::index_read ()
#14 0x0000000000686609 in handler::index_read_idx_map ()
#15 0x00000000005ffb65 in join_read_const ()
#16 0x000000000060790d in join_read_const_table ()
#17 0x000000000060cdfe in make_join_statistics ()
#18 0x000000000060e7db in JOIN::optimize ()
#19 0x0000000000611d40 in mysql_select ()
#20 0x000000000061754c in handle_select ()
#21 0x00000000005abecd in execute_sqlcom_select ()
#22 0x00000000005afbc3 in mysql_execute_command ()
#23 0x0000000000622cca in Prepared_statement::execute ()
#24 0x0000000000625c8c in Prepared_statement::execute_loop ()
#25 0x0000000000626365 in mysql_stmt_execute ()
#26 0x00000000005b482e in dispatch_command ()
#27 0x00000000005b5ad6 in do_command ()
#28 0x00000000005a8646 in handle_one_connection ()
#29 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#30 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#31 0x0000000000000000 in ?? ()

Thread 3 (Thread 0x44a06950 (LWP 13775)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x00000000007d811c in sync_array_wait_event ()
#3 0x00000000007d88ca in rw_lock_s_lock_spin ()
#4 0x000000000073e16f in buf_page_get_gen ()
#5 0x00000000007778fd in ibuf_insert_low ()
#6 0x0000000000778ad5 in ibuf_insert ()
#7 0x000000000072ccf8 in btr_cur_search_to_nth_level ()
#8 0x00000000007b3766 in row_ins_index_entry_low ()
#9 0x00000000007b4bc7 in row_ins_step ()
---Type <return> to continue, or q <return> to quit---
#10 0x00000000007bb656 in row_insert_for_mysql ()
#11 0x000000000072095e in ha_innobase::write_row ()
#12 0x000000000068a8a5 in handler::ha_write_row ()
#13 0x0000000000619abc in write_record ()
#14 0x000000000061d865 in mysql_insert ()
#15 0x00000000005af4bb in mysql_execute_command ()
#16 0x0000000000622cca in Prepared_statement::execute ()
#17 0x0000000000625c8c in Prepared_statement::execute_loop ()
#18 0x0000000000626365 in mysql_stmt_execute ()
#19 0x00000000005b482e in dispatch_command ()
#20 0x00000000005b5ad6 in do_command ()
#21 0x00000000005a8646 in handle_one_connection ()
#22 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#23 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#24 0x0000000000000000 in ?? ()

Thread 2 (Thread 0x40c8c950 (LWP 15994)):
#0 0x00007ffdc93d12d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x00000000007d811c in sync_array_wait_event ()
#3 0x00000000007d97a2 in mutex_spin_wait ()
#4 0x00000000007864b3 in log_print ()
#5 0x00000000007d3bb3 in srv_printf_innodb_monitor ()
#6 0x000000000071e076 in innodb_show_status ()
#7 0x000000000068c417 in ha_show_status ()
#8 0x00000000005af951 in mysql_execute_command ()
#9 0x00000000005b43d7 in mysql_parse ()
#10 0x00000000005b4f3b in dispatch_command ()
#11 0x00000000005b5ad6 in do_command ()
#12 0x00000000005a8646 in handle_one_connection ()
#13 0x00007ffdc93cd3ea in start_thread () from /lib/libpthread.so.0
#14 0x00007ffdc8123c6d in clone () from /lib/libc.so.6
#15 0x0000000000000000 in ?? ()

Thread 1 (Thread 0x7ffdc97f46f0 (LWP 13695)):
#0 0x00007ffdc811c482 in select () from /lib/libc.so.6
#1 0x00000000005a2b4d in handle_connections_sockets ()
#2 0x00000000005a36e8 in main ()
#0 0x00007ffdc811c482 in select () from /lib/libc.so.6

Vadim Tkachenko (vadim-tk) wrote :
Download full text (7.6 KiB)

In many others runs it worked fine, bit I again hung with 50 threads
(gdb) info threads
  66 Thread 0x421d6950 (LWP 5330) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  65 Thread 0x429d7950 (LWP 5331) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  64 Thread 0x431d8950 (LWP 5332) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  63 Thread 0x439d9950 (LWP 5333) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  62 Thread 0x441da950 (LWP 5334) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  61 Thread 0x449db950 (LWP 5335) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  60 Thread 0x451dc950 (LWP 5336) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  59 Thread 0x459dd950 (LWP 5337) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  58 Thread 0x461de950 (LWP 5338) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  57 Thread 0x469df950 (LWP 5339) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  56 Thread 0x4132a950 (LWP 5364) 0x00007fa620df8482 in select () from /lib/libc.so.6
  55 Thread 0x471e0950 (LWP 5365) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  54 Thread 0x479e1950 (LWP 5367) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  53 Thread 0x47a22950 (LWP 5368) 0x00007fa6220b0e7b in sigwait () from /lib/libpthread.so.0
  52 Thread 0x4136b950 (LWP 5406) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  51 Thread 0x47a63950 (LWP 5408) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  50 Thread 0x47aa4950 (LWP 5410) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  49 Thread 0x47ae5950 (LWP 5414) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  48 Thread 0x47b26950 (LWP 5415) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  47 Thread 0x47b67950 (LWP 5416) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  46 Thread 0x47ba8950 (LWP 5417) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  45 Thread 0x47be9950 (LWP 5419) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  44 Thread 0x47c2a950 (LWP 5422) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  43 Thread 0x47c6b950 (LWP 5423) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  42 Thread 0x47cac950 (LWP 5424) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  41 Thread 0x47ced950 (LWP 5426) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  40 Thread 0x47d2e950 (LWP 5428) 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
  39 T...

Read more...

Vadim Tkachenko (vadim-tk) wrote :
Download full text (72.5 KiB)

Backtraces for 50 threads
(gdb) thread apply all backtrace

Thread 66 (Thread 0x421d6950 (LWP 5330)):
#0 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x0000000000794123 in os_aio_simulated_handle ()
#3 0x000000000075db3f in fil_aio_wait ()
#4 0x00000000007d5540 in io_handler_thread ()
#5 0x00007fa6220a93ea in start_thread () from /lib/libpthread.so.0
#6 0x00007fa620dffc6d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 65 (Thread 0x429d7950 (LWP 5331)):
#0 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x0000000000794123 in os_aio_simulated_handle ()
#3 0x000000000075db3f in fil_aio_wait ()
#4 0x00000000007d5540 in io_handler_thread ()
#5 0x00007fa6220a93ea in start_thread () from /lib/libpthread.so.0
#6 0x00007fa620dffc6d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 64 (Thread 0x431d8950 (LWP 5332)):
#0 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x00000000007d811c in sync_array_wait_event ()
#3 0x00000000007d88ca in rw_lock_s_lock_spin ()
#4 0x000000000073e16f in buf_page_get_gen ()
#5 0x00000000007721e5 in ibuf_bitmap_get_map_page ()
#6 0x0000000000779702 in ibuf_merge_or_delete_for_page ()
#7 0x000000000073c237 in buf_page_io_complete ()
#8 0x000000000075dcb7 in fil_aio_wait ()
#9 0x00000000007d5540 in io_handler_thread ()
#10 0x00007fa6220a93ea in start_thread () from /lib/libpthread.so.0
#11 0x00007fa620dffc6d in clone () from /lib/libc.so.6
#12 0x0000000000000000 in ?? ()

Thread 63 (Thread 0x439d9950 (LWP 5333)):
#0 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x00000000007d811c in sync_array_wait_event ()
#3 0x00000000007d88ca in rw_lock_s_lock_spin ()
#4 0x000000000073e16f in buf_page_get_gen ()
#5 0x00000000007721e5 in ibuf_bitmap_get_map_page ()
#6 0x0000000000779702 in ibuf_merge_or_delete_for_page ()
#7 0x000000000073c237 in buf_page_io_complete ()
#8 0x000000000075dcb7 in fil_aio_wait ()
#9 0x00000000007d5540 in io_handler_thread ()
#10 0x00007fa6220a93ea in start_thread () from /lib/libpthread.so.0
#11 0x00007fa620dffc6d in clone () from /lib/libc.so.6
#12 0x0000000000000000 in ?? ()

Thread 62 (Thread 0x441da950 (LWP 5334)):
#0 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x0000000000794123 in os_aio_simulated_handle ()
#3 0x000000000075db3f in fil_aio_wait ()
#4 0x00000000007d5540 in io_handler_thread ()
---Type <return> to continue, or q <return> to quit---
#5 0x00007fa6220a93ea in start_thread () from /lib/libpthread.so.0
#6 0x00007fa620dffc6d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 61 (Thread 0x449db950 (LWP 5335)):
#0 0x00007fa6220ad2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x0000000000796f8d in os_event_wait_low ()
#2 0x0000000000794123 in os_ai...

Changed in percona-xtradb:
importance: Undecided → Critical
assignee: nobody → yasufumi-kinoshita
Vadim Tkachenko (vadim-tk) wrote :
Download full text (9.4 KiB)

more info from hang
mysql> show processlist;
+-----+------+-----------+------+---------+------+------------+------------------------------------------------------------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
+-----+------+-----------+------+---------+------+------------+------------------------------------------------------------------------------------------------------+
| 2 | root | | test | Execute | 422 | statistics | SELECT count(*) FROM stock WHERE s_w_id = ? AND s_i_id = ? AND s_quantity < ? |
| 3 | root | | test | Execute | 422 | update | INSERT INTO history(h_c_d_id, h_c_w_id, h_c_id, h_d_id, h_w_id, h_date, h_amount, h_data) VALUES(?, |
| 4 | root | | test | Execute | 422 | Updating | UPDATE orders SET o_carrier_id = ? WHERE o_id = ? AND o_d_id = ? AND o_w_id = ? |
| 5 | root | | test | Execute | 422 | update | INSERT INTO order_line (ol_o_id, ol_d_id, ol_w_id, ol_number, ol_i_id, ol_supply_w_id, ol_quantity, |
| 6 | root | | test | Execute | 422 | update | INSERT INTO orders (o_id, o_d_id, o_w_id, o_c_id, o_entry_d, o_ol_cnt, o_all_local) VALUES(?, ?, ?, |
| 7 | root | | test | Execute | 422 | statistics | SELECT s_quantity, s_data, s_dist_01, s_dist_02, s_dist_03, s_dist_04, s_dist_05, s_dist_06, s_dist_ |
| 8 | root | | test | Execute | 422 | Updating | UPDATE order_line SET ol_delivery_d = ? WHERE ol_o_id = ? AND ol_d_id = ? AND ol_w_id = ? |
| 9 | root | | test | Execute | 422 | statistics | SELECT w_street_1, w_street_2, w_city, w_state, w_zip, w_name FROM warehouse WHERE w_id = ? |
| 10 | root | | test | Execute | 422 | statistics | SELECT c_discount, c_last, c_credit, w_tax FROM customer, warehouse WHERE w_id = ? AND c_w_id = w_id |
| 11 | root | | test | Execute | 422 | init | UPDATE stock SET s_quantity = ? WHERE s_i_id = ? AND s_w_id = ? |
| 12 | root | | test | Execute | 422 | update | INSERT INTO order_line (ol_o_id, ol_d_id, ol_w_id, ol_number, ol_i_id, ol_supply_w_id, ol_quantity, |
| 13 | root | | test | Execute | 422 | statistics | SELECT c_discount, c_last, c_credit, w_tax FROM customer, warehouse WHERE w_id = ? AND c_w_id = w_id |
| 14 | root | | test | Execute | 422 | update | INSERT INTO order_line (ol_o_id, ol_d_id, ol_w_id, ol_number, ol_i_id, ol_supply_w_id, ol_quantity, |
| 15 | root | | test | Execute | 422 | init | UPDATE stock SET s_quantity = ? WHERE s_i_id = ? AND s_w_id = ? |
| 16 | root | | test | Execute | 422 | init | UPDATE stock SET s_quantity = ? WHERE s_i_id = ? AND s_w_id = ? |
| 17 | root | | test | Execute | 422 | update | INSERT INTO history(h_c_d_id, h_c_w_id, h_c_id, h_d_id, h_w_id, h_date...

Read more...

Vadim Tkachenko (vadim-tk) wrote :

I can't run mysql> show innodb status\G - it also hangs.
May the problem is in SHOW INNODB STATUS ?

Vadim Tkachenko (vadim-tk) wrote :
Download full text (205.8 KiB)

Backtrace with symbolic info

(gdb) thread apply all bt

Thread 68 (Thread 0x40c06950 (LWP 28615)):
#0 0x00007fdbf29e22d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x000000000072dede in os_event_wait_low (event=0x27661a0, reset_sig_count=<value optimized out>) at os/os0sync.c:422
#2 0x000000000072c144 in os_aio_simulated_handle (global_segment=0, message1=0x40c060e0, message2=0x40c060d8, type=0x40c060d0)
    at os/os0file.c:3955
#3 0x00000000006f9e23 in fil_aio_wait (segment=0) at fil/fil0fil.c:4500
#4 0x00000000007692ca in io_handler_thread (arg=<value optimized out>) at srv/srv0start.c:433
#5 0x00007fdbf29de3ea in start_thread () from /lib/libpthread.so.0
#6 0x00007fdbf1734c6d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 67 (Thread 0x41f5c950 (LWP 28616)):
#0 0x00007fdbf29e22d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x000000000072dede in os_event_wait_low (event=0x2766240, reset_sig_count=<value optimized out>) at os/os0sync.c:422
#2 0x000000000072c144 in os_aio_simulated_handle (global_segment=1, message1=0x41f5c0e0, message2=0x41f5c0d8, type=0x41f5c0d0)
    at os/os0file.c:3955
#3 0x00000000006f9e23 in fil_aio_wait (segment=1) at fil/fil0fil.c:4500
#4 0x00000000007692ca in io_handler_thread (arg=<value optimized out>) at srv/srv0start.c:433
#5 0x00007fdbf29de3ea in start_thread () from /lib/libpthread.so.0
#6 0x00007fdbf1734c6d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 66 (Thread 0x4275d950 (LWP 28617)):
#0 0x00007fdbf29e22d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x000000000072dede in os_event_wait_low (event=0x27662e0, reset_sig_count=<value optimized out>) at os/os0sync.c:422
#2 0x000000000072c144 in os_aio_simulated_handle (global_segment=2, message1=0x4275d0e0, message2=0x4275d0d8, type=0x4275d0d0)
    at os/os0file.c:3955
#3 0x00000000006f9e23 in fil_aio_wait (segment=2) at fil/fil0fil.c:4500
#4 0x00000000007692ca in io_handler_thread (arg=<value optimized out>) at srv/srv0start.c:433
#5 0x00007fdbf29de3ea in start_thread () from /lib/libpthread.so.0
#6 0x00007fdbf1734c6d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 65 (Thread 0x42f5e950 (LWP 28618)):
#0 0x00007fdbf29e22d9 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#1 0x000000000072dede in os_event_wait_low (event=0x277ada0, reset_sig_count=<value optimized out>) at os/os0sync.c:422
#2 0x0000000000769d0a in sync_array_wait_event (arr=0x100a7d0, index=49) at sync/sync0arr.c:445
#3 0x000000000076a54a in rw_lock_s_lock_spin (lock=0xbd1920, pass=<value optimized out>, file_name=0x8c5224 "buf/buf0buf.c",
    line=1913) at sync/sync0rw.c:371
#4 0x00000000006dd95a in buf_page_get_gen (space=27, zip_size=0, offset=163841, rw_latch=2, guess=0x0, mode=10,
    file=0x8cbf3c "ibuf/ibuf0ibuf.c", line=775, mtr=0x42f5db70) at ../../storage/innobase/include/sync0rw.ic:327
#5 0x000000000070d124 in ibuf_bitmap_get_map_page (space=41397724, page_no=<value optimized out>, zip_size=128,
    mtr=<value optimized out>) at ibuf/ibuf0ibuf.c:773
#6 0x0000000000711a1e in ibuf_merge_or_delete_for_page...

If reproduce again, please take also the content of
"LRU_list_mutex" and "flush_list_mutex" and "page_hash_latch".

They contain the owner ID of the thread. It will help analysis much.

Download full text (190.7 KiB)

(gdb) print LRU_list_mutex
$1 = {event = 0x24e0c60, lock_word = 1, os_fast_mutex = {__data =
{__lock = 1, __count = 0, __owner = 30676, __nusers = 1,
      __kind = 3, __spins = 0, __list = {__prev = 0x0, __next = 0x0}},
    __size =
"\001\000\000\000\000\000\000\000?w\000\000\001\000\000\000\003", '\0'
<repeats 22 times>, __align = 1}, waiters = 1,
  list = {prev = 0xbd18a0, next = 0xbd17a0}, cfile_name = 0x8c5224
"buf/buf0buf.c", cline = 938, count_os_wait = 19309}
(gdb) print flush_list_mutex
$2 = {event = 0x24e0d00, lock_word = 1, os_fast_mutex = {__data =
{__lock = 1, __count = 0, __owner = 30676, __nusers = 1,
      __kind = 3, __spins = 0, __list = {__prev = 0x0, __next = 0x0}},
    __size =
"\001\000\000\000\000\000\000\000?w\000\000\001\000\000\000\003", '\0'
<repeats 22 times>, __align = 1}, waiters = 1,
  list = {prev = 0xbd1720, next = 0xbd1620}, cfile_name = 0x8c5224
"buf/buf0buf.c", cline = 939, count_os_wait = 2199}
(gdb) print page_hash_latch
$3 = {s_event = 0x24e0da0, x_event = 0x24e0e40, wait_ex_event =
0x24e0ee0, lock_word = 1048576, reader_count = 0, writer = 351,
  writer_thread = 1204177232, writer_count = 0, pass = 0, s_waiters = 1,
x_waiters = 0, wait_ex_waiters = 1, list = {
    prev = 0x7fbdc4db80f0, next = 0xbcf720}, cfile_name = 0x8c5224
"buf/buf0buf.c", last_s_file_name = 0x8c413a "btr/btr0sea.c",
  last_x_file_name = 0x8c5f16 "buf/buf0lru.c", writer_is_wait_ex = 1,
cline = 940, last_s_line = 821, last_x_line = 1450,
  magic_n = 22643}

Thread 68 (Thread 0x4096c950 (LWP 30531)):
#0 0x00007fbe8ca8d2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib/libpthread.so.0
#1 0x000000000072dede in os_event_wait_low (event=0x24cc1a0,
reset_sig_count=<value optimized out>) at os/os0sync.c:422
#2 0x000000000072c144 in os_aio_simulated_handle (global_segment=0,
message1=0x4096c0e0, message2=0x4096c0d8, type=0x4096c0d0)
    at os/os0file.c:3955
#3 0x00000000006f9e23 in fil_aio_wait (segment=0) at fil/fil0fil.c:4500
#4 0x00000000007692ca in io_handler_thread (arg=<value optimized out>)
at srv/srv0start.c:433
#5 0x00007fbe8ca893ea in start_thread () from /lib/libpthread.so.0
#6 0x00007fbe8b7dfc6d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 67 (Thread 0x4116d950 (LWP 30532)):
#0 0x00007fbe8ca8d2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib/libpthread.so.0
#1 0x000000000072dede in os_event_wait_low (event=0x24cc240,
reset_sig_count=<value optimized out>) at os/os0sync.c:422
#2 0x000000000072c144 in os_aio_simulated_handle (global_segment=1,
message1=0x4116d0e0, message2=0x4116d0d8, type=0x4116d0d0)
    at os/os0file.c:3955
#3 0x00000000006f9e23 in fil_aio_wait (segment=1) at fil/fil0fil.c:4500
#4 0x00000000007692ca in io_handler_thread (arg=<value optimized out>)
at srv/srv0start.c:433
#5 0x00007fbe8ca893ea in start_thread () from /lib/libpthread.so.0
#6 0x00007fbe8b7dfc6d in clone () from /lib/libc.so.6
#7 0x0000000000000000 in ?? ()

Thread 66 (Thread 0x4196e950 (LWP 30533)):
#0 0x00007fbe8ca8d2d9 in pthread_cond_wait@@GLIBC_2.3.2 () from
/lib/libpthread.so.0
#1 0x000000000072dede in os_event_wait_low (event=0x24e0da0,
reset_sig_count=<value optimized out>) at os/os0sync.c:422
#2 0...

I think there may be probability of hardware bug(?) or timing problem of memory access.
But we should consider such problem.

I will implement some safety code.

(*) page_hash_latch is not locked, but x_lock is still waiting.

lock_word = 1048576 ( unlocked ), reader_count = 0, writer = 351 ( RW_LOCK_EXCLUSIVE ),
writer_thread = 1204177232 ( 47c64950 ) , writer_count = 0, pass = 0, s_waiters = 1,
x_waiters = 0, wait_ex_waiters = 1,
last_s_file_name = 0x8c413a "btr/btr0sea.c",
last_x_file_name = 0x8c5f16 "buf/buf0lru.c", writer_is_wait_ex = 1,
last_s_line = 821, last_x_line = 1450,

Download full text (22.5 KiB)

Yasufumi,

It does not seem hardware bug, I have no problem with standard Innodb.

Also why you think it is related to page_hash. As you see show innodb
status also hang, there is mutex srv_monitor_mutex affected. It seems
sync_array is in problem place.

On 2/9/09, Yasufumi Kinoshita <email address hidden> wrote:
> I think there may be probability of hardware bug(?) or timing problem of
> memory access.
> But we should consider such problem.
>
> I will implement some safety code.
>
>
> (*) page_hash_latch is not locked, but x_lock is still waiting.
>
> lock_word = 1048576 ( unlocked ), reader_count = 0, writer = 351 (
> RW_LOCK_EXCLUSIVE ),
> writer_thread = 1204177232 ( 47c64950 ) , writer_count = 0, pass = 0,
> s_waiters = 1,
> x_waiters = 0, wait_ex_waiters = 1,
> last_s_file_name = 0x8c413a "btr/btr0sea.c",
> last_x_file_name = 0x8c5f16 "buf/buf0lru.c", writer_is_wait_ex = 1,
> last_s_line = 821, last_x_line = 1450,
>
> --
> XtraDB hangs in 10 threads TPC-C
> https://bugs.launchpad.net/bugs/326445
> You received this bug notification because you are a direct subscriber
> of the bug.
>
> Status in Percona XtraDB Storage Engine for MySQL: New
>
> Bug description:
> (gdb) info threads
> 20 Thread 0x40a2f950 (LWP 13698) 0x00007ffdc93d12d9 in
> pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
> 19 Thread 0x41776950 (LWP 13699) 0x00007ffdc93d12d9 in
> pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
> 18 Thread 0x41f77950 (LWP 13700) 0x00007ffdc93d12d9 in
> pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
> 17 Thread 0x42778950 (LWP 13701) 0x00007ffdc93d12d9 in
> pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
> 16 Thread 0x4377a950 (LWP 13721) 0x00007ffdc811c482 in select () from
> /lib/libc.so.6
> 15 Thread 0x43f7b950 (LWP 13722) 0x00007ffdc93d12d9 in
> pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
> 14 Thread 0x4477c950 (LWP 13723) 0x00007ffdc93d12d9 in
> pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
> 13 Thread 0x447bd950 (LWP 13724) 0x00007ffdc93d4e7b in sigwait () from
> /lib/libpthread.so.0
> 12 Thread 0x40a70950 (LWP 13761) 0x00007ffdc93d12d9 in
> pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
> 11 Thread 0x447fe950 (LWP 13763) 0x00007ffdc93d12d9 in
> pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
> 10 Thread 0x4483f950 (LWP 13766) 0x00007ffdc93d12d9 in
> pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
> 9 Thread 0x44880950 (LWP 13768) 0x00007ffdc93d12d9 in
> pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
> 8 Thread 0x448c1950 (LWP 13770) 0x00007ffdc93d12d9 in
> pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
> 7 Thread 0x44902950 (LWP 13771) 0x00007ffdc93d12d9 in
> pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
> 6 Thread 0x44943950 (LWP 13772) 0x00007ffdc93d12d9 in
> pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
> 5 Thread 0x44984950 (LWP 13773) 0x00007ffdc93d12d9 in
> pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
> 4 Thread 0x449c5950 (LWP 13774) 0x00007ffdc93d12d9 in
> pthread_cond_wait@@GLIBC_...

Vadim,

The standard Innodb doesn't use instructions of atomic operation hardly.
And the other mutex may be only affected by the hungup of the x-lock waiting.

Changed in percona-xtradb:
status: New → Fix Committed

It may be medium.
Because percona-patches don't use "page_hash_latch" yet (uses page_hash_mutex)

I have never experienced such hungup of our tpc-c workload up to over 16 CPU (x86_64).

Changed in percona-patches:
assignee: nobody → yasufumi-kinoshita
importance: Undecided → Medium
status: New → Confirmed
Changed in percona-xtradb:
status: Fix Committed → Fix Released
Changed in percona-patches:
status: Confirmed → Fix Committed
Changed in percona-patches:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers