Description:
When executing a simple insert/update/delete scenario involving tables with various columns and indexes and various types of primary keys, the server deadlocked with:
one thread in:
#0 0x00110416 in __kernel_vsyscall ()
#1 0x00580ec2 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2 0x087e07a2 in safe_cond_timedwait (cond=0x8b4d3b8, mp=0x8b4cec4, abstime=0xa933d974, file=0x893be46 "log.cc", line=5823) at thr_mutex.c:289
#3 0x0837997f in MYSQL_BIN_LOG::wait_for_update_bin_log (this=0x8b4cec0, thd=0xb350120, timeout=0xa933d974) at log.cc:5822
#4 0x084509e2 in mysql_binlog_send (thd=0xb350120, log_ident=0xb36a368 "", pos=13171887, flags=0) at sql_repl.cc:814
#5 0x082ceb0e in dispatch_command (command=COM_BINLOG_DUMP, thd=0xb350120, packet=0xb3620d9 "", packet_length=10) at sql_parse.cc:1199
#6 0x082cf758 in do_command (thd=0xb350120) at sql_parse.cc:689
#7 0x082be097 in handle_one_connection (arg=0xb350120) at sql_connect.cc:1153
#8 0x0057d32f in start_thread () from /lib/libpthread.so.0
#9 0x0049a27e in clone () from /lib/libc.so.6
several threads in:
Thread 11 (Thread 0xa930d790 (LWP 10268)):
#0 0x00110416 in __kernel_vsyscall ()
#1 0x00583829 in __lll_lock_wait () from /lib/libpthread.so.0
#2 0x0057edb5 in _L_lock_758 () from /lib/libpthread.so.0
#3 0x0057ecce in pthread_mutex_lock () from /lib/libpthread.so.0
#4 0x087e015b in safe_mutex_lock (mp=0x8d8218c, try_lock=0 '\0', file=0x89b5e03 "ma_loghandler.c", line=1592) at thr_mutex.c:153
#5 0x087023de in translog_buffer_lock (buffer=0x8c82124) at ma_loghandler.c:1592
#6 0x08705916 in translog_lock () at ma_loghandler.c:2812
#7 0x0870d2ca in translog_write_fixed_record (lsn=0xa930b588, type=LOGREC_LONG_TRANSACTION_ID, tbl_info=0x0, short_trid=31802, parts=0xa930b4e4,
trn=0xa8604b08, hook_arg=0x0) at ma_loghandler.c:5906
#8 0x0870dc7a in translog_write_record (lsn=0xa930b588, type=LOGREC_LONG_TRANSACTION_ID, trn=0xa8604b08, tbl_info=0x0, rec_len=6, part_no=3,
parts_data=0xa930b570, store_share_id=0x0, hook_arg=0x0) at ma_loghandler.c:6149
#9 0x0870da39 in translog_write_record (lsn=0xa930b970, type=LOGREC_REDO_INSERT_ROW_HEAD, trn=0xa8604b08, tbl_info=0xa7f8f738, rec_len=49, part_no=4,
parts_data=0xa930b7f4, store_share_id=0xa930b950 "C", hook_arg=0x0) at ma_loghandler.c:6074
#10 0x0874f776 in write_block_record (info=0xa7f8f738, old_record=0x0, record=0xa815fb58 "ЪЪ\177ЖЪ", row=0xa7f8f77c, bitmap_blocks=0xa7f8f77c,
head_block_is_read=1 '\001', row_pos=0xa930bae0, undo_lsn=1, old_record_checksum=0) at ma_blockrec.c:2988
#11 0x08750639 in allocate_and_write_block_record (info=0xa7f8f738, record=0xa815fb58 "ЪЪ\177ЖЪ", row=0xa7f8f77c, undo_lsn=1) at ma_blockrec.c:3396
#12 0x08750809 in _ma_write_init_block_record (info=0xa7f8f738, record=0xa815fb58 "ЪЪ\177ЖЪ") at ma_blockrec.c:3439
#13 0x0875f10d in maria_write (info=0xa7f8f738, record=0xa815fb58 "ЪЪ\177ЖЪ") at ma_write.c:151
#14 0x08722660 in ha_maria::write_row (this=0xa81fb4c0, buf=0xa815fb58 "ЪЪ\177ЖЪ") at ha_maria.cc:968
#15 0x083e2bd2 in handler::ha_write_row (this=0xa81fb4c0, buf=0xa815fb58 "ЪЪ\177ЖЪ") at handler.cc:5223
---Type <return> to continue, or q <return> to quit---
#16 0x083f0950 in ha_partition::write_row (this=0xa8164bc8, buf=0xa815fb58 "ЪЪ\177ЖЪ") at ha_partition.cc:2934
#17 0x083e2bd2 in handler::ha_write_row (this=0xa8164bc8, buf=0xa815fb58 "ЪЪ\177ЖЪ") at handler.cc:5223
#18 0x083585ed in write_record (thd=0xb368120, table=0xa8121bb0, info=0xa930bf2c) at sql_insert.cc:1593
#19 0x0835c7bd in mysql_insert (thd=0xb368120, table_list=0xb3785e0, fields=@0xb3697e0, values_list=@0xb369804, update_fields=@0xb3697f8,
update_values=@0xb3697ec, duplic=DUP_ERROR, ignore=false) at sql_insert.cc:829
#20 0x082c8078 in mysql_execute_command (thd=0xb368120) at sql_parse.cc:2973
#21 0x082cd9f1 in mysql_parse (thd=0xb368120, inBuf=0xb3781e0 "INSERT INTO `table1_maria_key_pk_parts_2_char` ( `datetime` ) VALUES ( 0 )", length=74,
found_semicolon=0xa930ce70) at sql_parse.cc:5579
#22 0x082ce43b in dispatch_command (command=COM_QUERY, thd=0xb368120,
packet=0xb36c159 "INSERT INTO `table1_maria_key_pk_parts_2_char` ( `datetime` ) VALUES ( 0 )", packet_length=74) at sql_parse.cc:1002
#23 0x082cf758 in do_command (thd=0xb368120) at sql_parse.cc:689
#24 0x082be097 in handle_one_connection (arg=0xb368120) at sql_connect.cc:1153
#25 0x0057d32f in start_thread () from /lib/libpthread.so.0
#26 0x0049a27e in clone () from /lib/libc.so.6
and one thread in:
#0 0x00110416 in __kernel_vsyscall ()
#1 0x00583829 in __lll_lock_wait () from /lib/libpthread.so.0
#2 0x0057edb5 in _L_lock_758 () from /lib/libpthread.so.0
#3 0x0057ecce in pthread_mutex_lock () from /lib/libpthread.so.0
#4 0x087e015b in safe_mutex_lock (mp=0xb57956c, try_lock=0 '\0', file=0x89c011c "ma_key_recover.c", line=1284) at thr_mutex.c:153
#5 0x0873af7d in _ma_unlock_key_del (info=0xa8037c60) at ma_key_recover.c:1284
#6 0x08738320 in _ma_fast_unlock_key_del (info=0xa8037c60) at ma_key_recover.h:118
#7 0x087382d7 in write_hook_for_undo_key (type=LOGREC_UNDO_KEY_INSERT, trn=0xb304a68, tbl_info=0xa8037c60, lsn=0xa91e5b78, hook_arg=0xa91e5514)
at ma_key_recover.c:216
#8 0x08738497 in write_hook_for_undo_key_insert (type=LOGREC_UNDO_KEY_INSERT, trn=0xb304a68, tbl_info=0xa8037c60, lsn=0xa91e5b78, hook_arg=0xa91e5514)
at ma_key_recover.c:270
#9 0x0870b074 in translog_write_variable_record_1chunk (lsn=0xa91e5b78, type=LOGREC_UNDO_KEY_INSERT, tbl_info=0xa8037c60, short_trid=8367,
parts=0xa91e4ef4, buffer_to_flush=0x0, header_length=6, trn=0xb304a68, hook_arg=0xa91e5514) at ma_loghandler.c:4956
#10 0x0870d0dc in translog_write_variable_record (lsn=0xa91e5b78, type=LOGREC_UNDO_KEY_INSERT, tbl_info=0xa8037c60, short_trid=8367, parts=0xa91e4ef4,
trn=0xb304a68, hook_arg=0xa91e5514) at ma_loghandler.c:5837
#11 0x0870dc3a in translog_write_record (lsn=0xa91e5b78, type=LOGREC_UNDO_KEY_INSERT, trn=0xb304a68, tbl_info=0xa8037c60, rec_len=15, part_no=4,
parts_data=0xa91e552c, store_share_id=0xa91e5555 "k", hook_arg=0xa91e5514) at ma_loghandler.c:6144
#12 0x08763bc1 in _ma_write_undo_key_insert (info=0xa8037c60, key=0xa91e5c78, root=0xb57aae0, new_root=98304, res_lsn=0xa91e5b78) at ma_write.c:1721
#13 0x0875fc5b in _ma_ck_write_btree_with_log (info=0xa8037c60, key=0xa91e5c78, root=0xb57aae0, comp_flag=131076) at ma_write.c:413
#14 0x0875fa5f in _ma_ck_write_btree (info=0xa8037c60, key=0xa91e5c78) at ma_write.c:367
#15 0x0875f9db in _ma_ck_write (info=0xa8037c60, key=0xa91e5c78) at ma_write.c:352
#16 0x0875f2d6 in maria_write (info=0xa8037c60, record=0xa802d4b8 "ЪОЪ©Ч", ' ' <repeats 195 times>...) at ma_write.c:183
#17 0x08722660 in ha_maria::write_row (this=0xa8134ab0, buf=0xa802d4b8 "ЪОЪ©Ч", ' ' <repeats 195 times>...) at ha_maria.cc:968
#18 0x083e2bd2 in handler::ha_write_row (this=0xa8134ab0, buf=0xa802d4b8 "ЪОЪ©Ч", ' ' <repeats 195 times>...) at handler.cc:5223
#19 0x083585ed in write_record (thd=0xb6db1f8, table=0xa81a7900, info=0xa91e5f2c) at sql_insert.cc:1593
#20 0x0835c7bd in mysql_insert (thd=0xb6db1f8, table_list=0xb6ef540, fields=@0xb6dc8b8, values_list=@0xb6dc8dc, update_fields=@0xb6dc8d0,
update_values=@0xb6dc8c4, duplic=DUP_ERROR, ignore=false) at sql_insert.cc:829
#21 0x082c8078 in mysql_execute_command (thd=0xb6db1f8) at sql_parse.cc:2973
#22 0x082cd9f1 in mysql_parse (thd=0xb6db1f8, inBuf=0xb6ef1b8 "INSERT INTO `table0_maria_char` ( `set_key_utf8` ) VALUES ( 4 )", length=63,
found_semicolon=0xa91e6e70) at sql_parse.cc:5579
#23 0x082ce43b in dispatch_command (command=COM_QUERY, thd=0xb6db1f8, packet=0xb6dd089 "INSERT INTO `table0_maria_char` ( `set_key_utf8` ) VALUES ( 4 )",
packet_length=63) at sql_parse.cc:1002
#24 0x082cf758 in do_command (thd=0xb6db1f8) at sql_parse.cc:689
#25 0x082be097 in handle_one_connection (arg=0xb6db1f8) at sql_connect.cc:1153
#26 0x0057d32f in start_thread () from /lib/libpthread.so.0
#27 0x0049a27e in clone () from /lib/libc.so.6
How to repeat:
If this is repeatable, a test case will be provided.
Description: When executing a simple insert/update/delete scenario involving tables with various columns and indexes and various types of primary keys, the server deadlocked with: one thread in: #0 0x00110416 in __kernel_vsyscall () #1 0x00580ec2 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0 #2 0x087e07a2 in safe_cond_timedwait (cond=0x8b4d3b8, mp=0x8b4cec4, abstime=0xa933d974, file=0x893be46 "log.cc", line=5823) at thr_mutex.c:289 #3 0x0837997f in MYSQL_BIN_LOG::wait_for_update_bin_log (this=0x8b4cec0, thd=0xb350120, timeout=0xa933d974) at log.cc:5822 #4 0x084509e2 in mysql_binlog_send (thd=0xb350120, log_ident=0xb36a368 "", pos=13171887, flags=0) at sql_repl.cc:814 #5 0x082ceb0e in dispatch_command (command=COM_BINLOG_DUMP, thd=0xb350120, packet=0xb3620d9 "", packet_length=10) at sql_parse.cc:1199 #6 0x082cf758 in do_command (thd=0xb350120) at sql_parse.cc:689 #7 0x082be097 in handle_one_connection (arg=0xb350120) at sql_connect.cc:1153 #8 0x0057d32f in start_thread () from /lib/libpthread.so.0 #9 0x0049a27e in clone () from /lib/libc.so.6 several threads in: Thread 11 (Thread 0xa930d790 (LWP 10268)): #0 0x00110416 in __kernel_vsyscall () #1 0x00583829 in __lll_lock_wait () from /lib/libpthread.so.0 #2 0x0057edb5 in _L_lock_758 () from /lib/libpthread.so.0 #3 0x0057ecce in pthread_mutex_lock () from /lib/libpthread.so.0 #4 0x087e015b in safe_mutex_lock (mp=0x8d8218c, try_lock=0 '\0', file=0x89b5e03 "ma_loghandler.c", line=1592) at thr_mutex.c:153 #5 0x087023de in translog_buffer_lock (buffer=0x8c82124) at ma_loghandler.c:1592 #6 0x08705916 in translog_lock () at ma_loghandler.c:2812 #7 0x0870d2ca in translog_write_fixed_record (lsn=0xa930b588, type=LOGREC_LONG_TRANSACTION_ID, tbl_info=0x0, short_trid=31802, parts=0xa930b4e4, trn=0xa8604b08, hook_arg=0x0) at ma_loghandler.c:5906 #8 0x0870dc7a in translog_write_record (lsn=0xa930b588, type=LOGREC_LONG_TRANSACTION_ID, trn=0xa8604b08, tbl_info=0x0, rec_len=6, part_no=3, parts_data=0xa930b570, store_share_id=0x0, hook_arg=0x0) at ma_loghandler.c:6149 #9 0x0870da39 in translog_write_record (lsn=0xa930b970, type=LOGREC_REDO_INSERT_ROW_HEAD, trn=0xa8604b08, tbl_info=0xa7f8f738, rec_len=49, part_no=4, parts_data=0xa930b7f4, store_share_id=0xa930b950 "C", hook_arg=0x0) at ma_loghandler.c:6074 #10 0x0874f776 in write_block_record (info=0xa7f8f738, old_record=0x0, record=0xa815fb58 "ЪЪ\177ЖЪ", row=0xa7f8f77c, bitmap_blocks=0xa7f8f77c, head_block_is_read=1 '\001', row_pos=0xa930bae0, undo_lsn=1, old_record_checksum=0) at ma_blockrec.c:2988 #11 0x08750639 in allocate_and_write_block_record (info=0xa7f8f738, record=0xa815fb58 "ЪЪ\177ЖЪ", row=0xa7f8f77c, undo_lsn=1) at ma_blockrec.c:3396 #12 0x08750809 in _ma_write_init_block_record (info=0xa7f8f738, record=0xa815fb58 "ЪЪ\177ЖЪ") at ma_blockrec.c:3439 #13 0x0875f10d in maria_write (info=0xa7f8f738, record=0xa815fb58 "ЪЪ\177ЖЪ") at ma_write.c:151 #14 0x08722660 in ha_maria::write_row (this=0xa81fb4c0, buf=0xa815fb58 "ЪЪ\177ЖЪ") at ha_maria.cc:968 #15 0x083e2bd2 in handler::ha_write_row (this=0xa81fb4c0, buf=0xa815fb58 "ЪЪ\177ЖЪ") at handler.cc:5223 ---Type <return> to continue, or q <return> to quit--- #16 0x083f0950 in ha_partition::write_row (this=0xa8164bc8, buf=0xa815fb58 "ЪЪ\177ЖЪ") at ha_partition.cc:2934 #17 0x083e2bd2 in handler::ha_write_row (this=0xa8164bc8, buf=0xa815fb58 "ЪЪ\177ЖЪ") at handler.cc:5223 #18 0x083585ed in write_record (thd=0xb368120, table=0xa8121bb0, info=0xa930bf2c) at sql_insert.cc:1593 #19 0x0835c7bd in mysql_insert (thd=0xb368120, table_list=0xb3785e0, fields=@0xb3697e0, values_list=@0xb369804, update_fields=@0xb3697f8, update_values=@0xb3697ec, duplic=DUP_ERROR, ignore=false) at sql_insert.cc:829 #20 0x082c8078 in mysql_execute_command (thd=0xb368120) at sql_parse.cc:2973 #21 0x082cd9f1 in mysql_parse (thd=0xb368120, inBuf=0xb3781e0 "INSERT INTO `table1_maria_key_pk_parts_2_char` ( `datetime` ) VALUES ( 0 )", length=74, found_semicolon=0xa930ce70) at sql_parse.cc:5579 #22 0x082ce43b in dispatch_command (command=COM_QUERY, thd=0xb368120, packet=0xb36c159 "INSERT INTO `table1_maria_key_pk_parts_2_char` ( `datetime` ) VALUES ( 0 )", packet_length=74) at sql_parse.cc:1002 #23 0x082cf758 in do_command (thd=0xb368120) at sql_parse.cc:689 #24 0x082be097 in handle_one_connection (arg=0xb368120) at sql_connect.cc:1153 #25 0x0057d32f in start_thread () from /lib/libpthread.so.0 #26 0x0049a27e in clone () from /lib/libc.so.6 and one thread in: #0 0x00110416 in __kernel_vsyscall () #1 0x00583829 in __lll_lock_wait () from /lib/libpthread.so.0 #2 0x0057edb5 in _L_lock_758 () from /lib/libpthread.so.0 #3 0x0057ecce in pthread_mutex_lock () from /lib/libpthread.so.0 #4 0x087e015b in safe_mutex_lock (mp=0xb57956c, try_lock=0 '\0', file=0x89c011c "ma_key_recover.c", line=1284) at thr_mutex.c:153 #5 0x0873af7d in _ma_unlock_key_del (info=0xa8037c60) at ma_key_recover.c:1284 #6 0x08738320 in _ma_fast_unlock_key_del (info=0xa8037c60) at ma_key_recover.h:118 #7 0x087382d7 in write_hook_for_undo_key (type=LOGREC_UNDO_KEY_INSERT, trn=0xb304a68, tbl_info=0xa8037c60, lsn=0xa91e5b78, hook_arg=0xa91e5514) at ma_key_recover.c:216 #8 0x08738497 in write_hook_for_undo_key_insert (type=LOGREC_UNDO_KEY_INSERT, trn=0xb304a68, tbl_info=0xa8037c60, lsn=0xa91e5b78, hook_arg=0xa91e5514) at ma_key_recover.c:270 #9 0x0870b074 in translog_write_variable_record_1chunk (lsn=0xa91e5b78, type=LOGREC_UNDO_KEY_INSERT, tbl_info=0xa8037c60, short_trid=8367, parts=0xa91e4ef4, buffer_to_flush=0x0, header_length=6, trn=0xb304a68, hook_arg=0xa91e5514) at ma_loghandler.c:4956 #10 0x0870d0dc in translog_write_variable_record (lsn=0xa91e5b78, type=LOGREC_UNDO_KEY_INSERT, tbl_info=0xa8037c60, short_trid=8367, parts=0xa91e4ef4, trn=0xb304a68, hook_arg=0xa91e5514) at ma_loghandler.c:5837 #11 0x0870dc3a in translog_write_record (lsn=0xa91e5b78, type=LOGREC_UNDO_KEY_INSERT, trn=0xb304a68, tbl_info=0xa8037c60, rec_len=15, part_no=4, parts_data=0xa91e552c, store_share_id=0xa91e5555 "k", hook_arg=0xa91e5514) at ma_loghandler.c:6144 #12 0x08763bc1 in _ma_write_undo_key_insert (info=0xa8037c60, key=0xa91e5c78, root=0xb57aae0, new_root=98304, res_lsn=0xa91e5b78) at ma_write.c:1721 #13 0x0875fc5b in _ma_ck_write_btree_with_log (info=0xa8037c60, key=0xa91e5c78, root=0xb57aae0, comp_flag=131076) at ma_write.c:413 #14 0x0875fa5f in _ma_ck_write_btree (info=0xa8037c60, key=0xa91e5c78) at ma_write.c:367 #15 0x0875f9db in _ma_ck_write (info=0xa8037c60, key=0xa91e5c78) at ma_write.c:352 #16 0x0875f2d6 in maria_write (info=0xa8037c60, record=0xa802d4b8 "ЪОЪ©Ч", ' ' <repeats 195 times>...) at ma_write.c:183 #17 0x08722660 in ha_maria::write_row (this=0xa8134ab0, buf=0xa802d4b8 "ЪОЪ©Ч", ' ' <repeats 195 times>...) at ha_maria.cc:968 #18 0x083e2bd2 in handler::ha_write_row (this=0xa8134ab0, buf=0xa802d4b8 "ЪОЪ©Ч", ' ' <repeats 195 times>...) at handler.cc:5223 #19 0x083585ed in write_record (thd=0xb6db1f8, table=0xa81a7900, info=0xa91e5f2c) at sql_insert.cc:1593 #20 0x0835c7bd in mysql_insert (thd=0xb6db1f8, table_list=0xb6ef540, fields=@0xb6dc8b8, values_list=@0xb6dc8dc, update_fields=@0xb6dc8d0, update_values=@0xb6dc8c4, duplic=DUP_ERROR, ignore=false) at sql_insert.cc:829 #21 0x082c8078 in mysql_execute_command (thd=0xb6db1f8) at sql_parse.cc:2973 #22 0x082cd9f1 in mysql_parse (thd=0xb6db1f8, inBuf=0xb6ef1b8 "INSERT INTO `table0_maria_char` ( `set_key_utf8` ) VALUES ( 4 )", length=63, found_semicolon=0xa91e6e70) at sql_parse.cc:5579 #23 0x082ce43b in dispatch_command (command=COM_QUERY, thd=0xb6db1f8, packet=0xb6dd089 "INSERT INTO `table0_maria_char` ( `set_key_utf8` ) VALUES ( 4 )", packet_length=63) at sql_parse.cc:1002 #24 0x082cf758 in do_command (thd=0xb6db1f8) at sql_parse.cc:689 #25 0x082be097 in handle_one_connection (arg=0xb6db1f8) at sql_connect.cc:1153 #26 0x0057d32f in start_thread () from /lib/libpthread.so.0 #27 0x0049a27e in clone () from /lib/libc.so.6 How to repeat: If this is repeatable, a test case will be provided.