| Bug #37395 | Falcon deadlock between Table::insert and Table::validateAndInsert | ||
|---|---|---|---|
| Submitted: | 13 Jun 2008 14:16 | Modified: | 12 Sep 2008 14:31 |
| Reporter: | Philip Stoev | Email Updates: | |
| Status: | Can't repeat | Impact on me: | |
| Category: | MySQL Server: Falcon storage engine | Severity: | S1 (Critical) |
| Version: | 6.0.5-rebuild | OS: | Any |
| Assigned to: | Kevin Lewis | CPU Architecture: | Any |
[13 Jun 2008 14:17]
Philip Stoev
Stack traces from the different types of threads involved: Thread 111 (Thread 4019764112 (LWP 32615)): #0 0xffffe410 in __kernel_vsyscall () #1 0x006cf256 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0 #2 0x08459b06 in Synchronize::sleep (this=0xf6fc9830) at Synchronize.cpp:122 #3 0x083bd0d5 in SyncObject::wait (this=0xf7300630, type=Exclusive, thread=0xf6fc9830, sync=0xef98b044, timeout=0) at SyncObject.cpp:413 #4 0x083bd363 in SyncObject::lock (this=0xf7300630, sync=0xef98b044, type=Exclusive, timeout=0) at SyncObject.cpp:265 #5 0x083bc1a6 in Sync::lock (this=0xef98b044, type=Exclusive) at Sync.cpp:58 #6 0x0841d9bb in RecordLeaf::retireRecords (this=0xf70fffb8, table=0xf73002a8, base=0, recordScavenge=0xef98b15c) at RecordLeaf.cpp:171 #7 0x0847384b in RecordGroup::retireRecords (this=0xf71040e0, table=0xf73002a8, base=-4, recordScavenge=0xef98b15c) at RecordGroup.cpp:124 #8 0x0847384b in RecordGroup::retireRecords (this=0xe7092da0, table=0xf73002a8, base=-4, recordScavenge=0xef98b15c) at RecordGroup.cpp:124 #9 0x083bdee6 in Table::retireRecords (this=0xf73002a8, recordScavenge=0xef98b15c) at Table.cpp:1805 #10 0x083eb66c in Database::retireRecords (this=0xf719b618, forced=false) at Database.cpp:1807 #11 0x083ebbaa in Database::scavenge (this=0xf719b618) at Database.cpp:1722 #12 0x084392c9 in Scavenger::execute (this=0xf6fa1ff0, scheduler=0xf6fa1f68) at Scavenger.cpp:58 #13 0x0843a651 in Scheduler::schedule (this=0xf6fa1f68) at Scheduler.cpp:136 #14 0x083c9f33 in Thread::thread (this=0xf6fc9830) at Thread.cpp:161 #15 0x083ca164 in Thread::thread (parameter=0xf6fc9830) at Thread.cpp:140 #16 0x006cb45b in start_thread () from /lib/libpthread.so.0 #17 0x0065224e in clone () from /lib/libc.so.6 Thread 102 (Thread 3750378384 (LWP 11536)): #0 0xffffe410 in __kernel_vsyscall () #1 0x006cf256 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0 #2 0x08459b06 in Synchronize::sleep (this=0xdddd7958) at Synchronize.cpp:122 #3 0x083bd0d5 in SyncObject::wait (this=0xf73002c0, type=Exclusive, thread=0xdddd7958, sync=0xdf8a23c0, timeout=0) at SyncObject.cpp:413 #4 0x083bd363 in SyncObject::lock (this=0xf73002c0, sync=0xdf8a23c0, type=Exclusive, timeout=0) at SyncObject.cpp:265 #5 0x083bc1a6 in Sync::lock (this=0xdf8a23c0, type=Exclusive) at Sync.cpp:58 #6 0x083becba in Table::insert (this=0xf73002a8, record=0x0, prior=0xdb5325b8, recordNumber=24501) at Table.cpp:1875 #7 0x083c17f4 in Table::rollbackRecord (this=0xf73002a8, recordToRollback=0xdb5325b8, transaction=0xf6fbbf28) at Table.cpp:995 #8 0x0841e62c in RecordVersion::rollback (this=0xdb5325b8, transaction=0xf6fbbf28) at RecordVersion.cpp:155 #9 0x083ced42 in Transaction::rollback (this=0xf6fbbf28) at Transaction.cpp:432 #10 0x083e0b0c in Connection::rollback (this=0xdddc8e50) at Connection.cpp:279 #11 0x083b1d46 in StorageConnection::rollback (this=0xdddc8df8) at StorageConnection.cpp:177 #12 0x083a9d29 in StorageInterface::rollback (hton=0x89fec98, thd=0xe1aa5d88, all=true) at ha_falcon.cpp:1193 #13 0x083138bd in ha_rollback_trans (thd=0xe1aa5d88, all=true) at handler.cc:1235 #14 0x0823e86c in end_trans (thd=0xe1aa5d88, completion=ROLLBACK) at sql_parse.cc:597 #15 0x0823fba0 in mysql_execute_command (thd=0xe1aa5d88) at sql_parse.cc:3808 #16 0x08246c4e in mysql_parse (thd=0xe1aa5d88, inBuf=0x9212840 "ROLLBACK", length=8, found_semicolon=0xdf8a332c) at sql_parse.cc:5623 #17 0x08247a88 in dispatch_command (command=COM_QUERY, thd=0xe1aa5d88, packet=<value optimized out>, packet_length=8) at sql_parse.cc:1031 #18 0x08247e72 in do_command (thd=0xe1aa5d88) at sql_parse.cc:723 #19 0x0823956a in handle_one_connection (arg=0xe1aa5e00) at sql_connect.cc:1134 #20 0x006cb45b in start_thread () from /lib/libpthread.so.0 #21 0x0065224e in clone () from /lib/libc.so.6
[13 Jun 2008 14:17]
Philip Stoev
Thread 101 (Thread 3858148240 (LWP 11629)):
#0 0xffffe410 in __kernel_vsyscall ()
#1 0x006cf256 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2 0x08459b06 in Synchronize::sleep (this=0xddde3240) at Synchronize.cpp:122
#3 0x083bd0d5 in SyncObject::wait (this=0xf7100150, type=Shared, thread=0xddde3240, sync=0xe5f682d0, timeout=0) at SyncObject.cpp:413
#4 0x083bd363 in SyncObject::lock (this=0xf7100150, sync=0xe5f682d0, type=Shared, timeout=0) at SyncObject.cpp:265
#5 0x083bc1a6 in Sync::lock (this=0xe5f682d0, type=Shared) at Sync.cpp:58
#6 0x0841d78c in RecordLeaf::fetch (this=0xf70fffb8, id=98) at RecordLeaf.cpp:68
#7 0x083c437b in Table::fetch (this=0xf73002a8, recordNumber=98) at Table.cpp:874
#8 0x083b2aa7 in StorageDatabase::nextIndexed (this=0xf6f9a110, storageTable=0xdfb85808, recordBitmap=0xe7072d78, recordNumber=-4, lockForUpdate=true)
at StorageDatabase.cpp:383
#9 0x083b7588 in StorageTable::nextIndexed (this=0xfffffffc, recordNumber=0, lockForUpdate=true) at StorageTable.cpp:170
#10 0x083aaafe in StorageInterface::index_next (this=0xe2eb3b80, buf=0xe5e6d148 "Ъ") at ha_falcon.cpp:1582
#11 0x083a95a0 in StorageInterface::read_range_first (this=0xe2eb3b80, start_key=0xe2eb3c14, end_key=0xe2eb3c24, eq_range_arg=true, sorted=false)
at ha_falcon.cpp:1556
#12 0x08312ee7 in handler::multi_range_read_next (this=0xe2eb3b80, range_info=0xfffffffc) at handler.cc:4249
#13 0x082f965b in QUICK_RANGE_SELECT::get_next (this=0xe1671bf0) at opt_range.cc:8511
#14 0x0830e5aa in rr_quick (info=0xe5f6870c) at records.cc:298
#15 0x082c4d14 in mysql_delete (thd=0xe6e7bf70, table_list=0xdc93e910, conds=0xdc93ec60, order=0xdc93f450, limit=18446744073709551615, options=0,
reset_auto_increment=false) at sql_delete.cc:281
#16 0x08242aec in mysql_execute_command (thd=0xe6e7bf70) at sql_parse.cc:2995
#17 0x08371196 in sp_instr_stmt::exec_core (this=0xb4b, thd=0xe6e7bf70, nextp=0xb4b) at sp_head.cc:2863
#18 0x0837361a in sp_lex_keeper::reset_lex_and_exec_core (this=0xdc93ed74, thd=0xe6e7bf70, nextp=0xe5f69530, open_tables=false, instr=0xdc93ed50)
at sp_head.cc:2692
#19 0x08374bbd in sp_instr_stmt::execute (this=0xdc93ed50, thd=0xe6e7bf70, nextp=0xe5f69530) at sp_head.cc:2806
#20 0x08373f5e in sp_head::execute (this=0x9045c70, thd=0xe6e7bf70) at sp_head.cc:1215
#21 0x083764dc in sp_head::execute_procedure (this=0x9045c70, thd=0xe6e7bf70, args=0xe6e7d580) at sp_head.cc:1939
#22 0x082401a7 in mysql_execute_command (thd=0xe6e7bf70) at sql_parse.cc:4085
#23 0x08246c4e in mysql_parse (thd=0xe6e7bf70, inBuf=0x902dd68 "CALL test.insdel1()", length=19, found_semicolon=0xe5f6a32c) at sql_parse.cc:5623
#24 0x08247a88 in dispatch_command (command=COM_QUERY, thd=0xe6e7bf70, packet=<value optimized out>, packet_length=19) at sql_parse.cc:1031
#25 0x08247e72 in do_command (thd=0xe6e7bf70) at sql_parse.cc:723
#26 0x0823956a in handle_one_connection (arg=0xe6e7bfe8) at sql_connect.cc:1134
#27 0x006cb45b in start_thread () from /lib/libpthread.so.0
#28 0x0065224e in clone () from /lib/libc.so.6
Thread 69 (Thread 3902151568 (LWP 13786)):
#0 0xffffe410 in __kernel_vsyscall ()
#1 0x006cf256 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
#2 0x08459b06 in Synchronize::sleep (this=0xddec6700) at Synchronize.cpp:122
#3 0x083bd0d5 in SyncObject::wait (this=0xf73002c0, type=Exclusive, thread=0xddec6700, sync=0xe895f380, timeout=0) at SyncObject.cpp:413
#4 0x083bd363 in SyncObject::lock (this=0xf73002c0, sync=0xe895f380, type=Exclusive, timeout=0) at SyncObject.cpp:265
#5 0x083bc1a6 in Sync::lock (this=0xe895f380, type=Exclusive) at Sync.cpp:58
#6 0x083c495f in Table::validateAndInsert (this=0xf73002a8, transaction=0xf70c1378, record=0xe34f4b90) at Table.cpp:3284
#7 0x083c54d1 in Table::deleteRecord (this=0xf73002a8, transaction=0xf70c1378, orgRecord=0xe7465480) at Table.cpp:1488
#8 0x083b2dca in StorageDatabase::deleteRow (this=0xf6f9a110, storageConnection=0xddec67d0, table=0xf73002a8, recordNumber=28518) at StorageDatabase.cpp:585
#9 0x083b749d in StorageTable::deleteRow (this=0xfffffffc, recordNumber=28518) at StorageTable.cpp:137
#10 0x083a98e5 in StorageInterface::delete_row (this=0xe860b8c8, buf=0xe862edd8 "Ъgo") at ha_falcon.cpp:1133
#11 0x08314855 in handler::ha_delete_row (this=0xe860b8c8, buf=0xe862edd8 "Ъgo") at handler.cc:5344
#12 0x082c4dbe in mysql_delete (thd=0xe8034680, table_list=0x949d3a8, conds=0x949d6f8, order=0x92b2248, limit=18446744073709551615, options=0,
reset_auto_increment=false) at sql_delete.cc:296
#13 0x08242aec in mysql_execute_command (thd=0xe8034680) at sql_parse.cc:2995
#14 0x08371196 in sp_instr_stmt::exec_core (this=0x121, thd=0xe8034680, nextp=0x121) at sp_head.cc:2863
#15 0x0837361a in sp_lex_keeper::reset_lex_and_exec_core (this=0x949d80c, thd=0xe8034680, nextp=0xe8960530, open_tables=false, instr=0x949d7e8)
at sp_head.cc:2692
#16 0x08374bbd in sp_instr_stmt::execute (this=0x949d7e8, thd=0xe8034680, nextp=0xe8960530) at sp_head.cc:2806
#17 0x08373f5e in sp_head::execute (this=0x8f497c8, thd=0xe8034680) at sp_head.cc:1215
#18 0x083764dc in sp_head::execute_procedure (this=0x8f497c8, thd=0xe8034680, args=0xe8035c90) at sp_head.cc:1939
#19 0x082401a7 in mysql_execute_command (thd=0xe8034680) at sql_parse.cc:4085
#20 0x08246c4e in mysql_parse (thd=0xe8034680, inBuf=0x97c6b28 "CALL test.insdel1()", length=19, found_semicolon=0xe896132c) at sql_parse.cc:5623
#21 0x08247a88 in dispatch_command (command=COM_QUERY, thd=0xe8034680, packet=<value optimized out>, packet_length=19) at sql_parse.cc:1031
#22 0x08247e72 in do_command (thd=0xe8034680) at sql_parse.cc:723
#23 0x0823956a in handle_one_connection (arg=0xe80346f8) at sql_connect.cc:1134
#24 0x006cb45b in start_thread () from /lib/libpthread.so.0
[13 Jun 2008 15:11]
Philip Stoev
Please see bug #36526 for a simpliar stalled threads printout.
[25 Jun 2008 22:40]
Kevin Lewis
Philip, Can you put a backtrace of ALL threads into an attached file? The four that you added do not seem to show the deadlock.
[26 Jun 2008 16:17]
Philip Stoev
Stack traces for bug 37395
Attachment: bug37395.stacks (text/plain), 283.80 KiB.
[26 Jun 2008 16:18]
Philip Stoev
Kevin, I just uploaded all stack traces from this bug. To the best of my understanding, they all belong to the several distinct types that I pasted previously. So maybe this is another bug there something is waiting for something that is no longer there.
[12 Sep 2008 14:31]
Kevin Lewis
I cannot see a conflict in the call stack provided. But that may be because the syncObjects involved in those functions have changed significantly since this was reported. Philip says that he has not seen any of these kinds of call stacks lately, that is, deadlocks involving many threads stuck in validateAndInsert. At the time this was reported, it was haapening fairly often, from several sources. Changing to 'Can't Repeat'. If deadlokcs start to re-occur with validateAndInsert(), then we can re-open this.
Description: When executing the rpl_sys test, the master deadlocked as follows: Stalled threads Thread 0xdddd7958 (-544588912) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xddec6700 (-392815728) sleep=1, grant=0, locks=1, who 0, parent=(nil) Pending Table::validateAndInsert state 0 (1) syncObject 0xf73002c0 Thread 0xdddfbcb8 (-419660912) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdddfd1d8 (-544789616) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde10438 (-473126000) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde22bb8 (-437019760) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde183e8 (-548811888) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde27a58 (-500147312) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde2baa8 (-463041648) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde3a960 (-426534000) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde4d0b0 (-482534512) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde60240 (-442709104) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde60da8 (-502649968) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde60808 (-445211760) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde728a8 (-430322800) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde73178 (-400966768) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde80350 (-502449264) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde8ec90 (-487339120) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde816b8 (-495342704) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde9f7c0 (-490738800) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde9ffd0 (-430122096) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xdde9ce80 (-531199088) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xddeb1058 (-541885552) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xddeb2168 (-429921392) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xddeb4088 (-425931888) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xddec27c0 (-393016432) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xddebfb30 (-508257392) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Thread 0xddec3450 (-507655280) sleep=1, grant=0, locks=2, who 0, parent=(nil) Pending Table::insert state 0 (1) syncObject 0xf73002c0 Stalled synchronization objects: SyncObject f73002c0: state 73, monitor 0, waiters 28 Waiting thread ddec6700 (-392815728), type 1; Table::validateAndInsert Waiting thread dddfbcb8 (-419660912), type 1; Table::insert Waiting thread dddfd1d8 (-544789616), type 1; Table::insert Waiting thread dde10438 (-473126000), type 1; Table::insert Waiting thread dde22bb8 (-437019760), type 1; Table::insert Waiting thread dde183e8 (-548811888), type 1; Table::insert Waiting thread dde27a58 (-500147312), type 1; Table::insert Waiting thread dde2baa8 (-463041648), type 1; Table::insert Waiting thread dde3a960 (-426534000), type 1; Table::insert Waiting thread dde4d0b0 (-482534512), type 1; Table::insert Waiting thread dde60240 (-442709104), type 1; Table::insert Waiting thread dde60da8 (-502649968), type 1; Table::insert Waiting thread dde60808 (-445211760), type 1; Table::insert Waiting thread dde728a8 (-430322800), type 1; Table::insert Waiting thread dde73178 (-400966768), type 1; Table::insert Waiting thread dde80350 (-502449264), type 1; Table::insert Waiting thread dde8ec90 (-487339120), type 1; Table::insert Waiting thread dde816b8 (-495342704), type 1; Table::insert Waiting thread dde9f7c0 (-490738800), type 1; Table::insert Waiting thread dde9ffd0 (-430122096), type 1; Table::insert Waiting thread dde9ce80 (-531199088), type 1; Table::insert Waiting thread ddeb1058 (-541885552), type 1; Table::insert Waiting thread ddeb2168 (-429921392), type 1; Table::insert Waiting thread ddeb4088 (-425931888), type 1; Table::insert Waiting thread dddd7958 (-544588912), type 1; Table::insert Waiting thread ddec27c0 (-393016432), type 1; Table::insert Waiting thread ddebfb30 (-508257392), type 1; Table::insert Waiting thread ddec3450 (-507655280), type 1; Table::insert How to repeat: run rpl_sys as described in https://inside.mysql.com/wiki/SystemQATestPlan