Bug #37725 | Falcon: assertion in waitForTransaction "waitingFor was not NULL" | ||
---|---|---|---|
Submitted: | 29 Jun 2008 11:15 | Modified: | 1 Oct 2008 12:11 |
Reporter: | Philip Stoev | Email Updates: | |
Status: | Closed | Impact on me: | |
Category: | MySQL Server: Falcon storage engine | Severity: | S1 (Critical) |
Version: | 6.0-falcon | OS: | Any |
Assigned to: | Vladislav Vaintroub | CPU Architecture: | Any |
[29 Jun 2008 11:15]
Philip Stoev
[29 Jun 2008 11:15]
Philip Stoev
(gdb) print * waitingFor $4 = {_vptr.Transaction = 0x88a1a10, connection = 0xad813138, database = 0xb7370640, transactionId = 29371, oldestActive = 29287, blockedBy = 0, curSavePointId = 3, next = 0xb71f8468, prior = 0xb7222240, waitingFor = 0x0, savePoints = 0xb71fef4c, freeSavePoints = 0xb71fef38, localSavePoints = {{ next = 0x0, savepoints = 0xcccccccc, backloggedRecords = 0xcccccccc, records = 0xcccccccc, id = -858993460}, {next = 0xb71fef10, savepoints = 0xcccccccc, backloggedRecords = 0xcccccccc, records = 0xcccccccc, id = -858993460}, {next = 0xb71fef24, savepoints = 0x0, backloggedRecords = 0x0, records = 0xb71ff174, id = 3}, {next = 0xb71fef60, savepoints = 0x0, backloggedRecords = 0x0, records = 0xb71ff174, id = 2}, { next = 0x0, savepoints = 0x0, backloggedRecords = 0x0, records = 0xb71ff174, id = 1}}, deferredIndexes = 0xad81fa98, thread = 0xad813058, blockingRecord = 0x0, backloggedRecords = 0x0, startTime = 775, deferredIndexCount = 1, statesAllocated = 9, isolationLevel = 8, xidLength = 0, mySqlThreadId = 9, xid = 0x0, states = 0xb7217cc8, commitTriggers = false, systemTransaction = false, hasUpdates = true, writePending = true, pendingPageWrites = false, hasLocks = true, syncActive = {<SynchronizationObject> = {_vptr.SynchronizationObject = 0x889f458}, monitorCount = 0, mutex = {<SynchronizationObject> = {_vptr.SynchronizationObject = 0x88ab7b8}, holder = 0x0, mutex = {__data = {__lock = 0, __count = 0, __owner = 0, __kind = 0, __nusers = 0, {__spins = 0, __list = {__next = 0x0}}}, __size = '\0' <repeats 23 times>, __align = 0}}, queue = 0xb71abe60, exclusiveThread = 0xad813058, readers = 0, waiters = 5, lockState = -1, stalls = 6, objectId = 141846, sharedCount = 0, collisionCount = 0, exclusiveCount = 1, waitCount = 6, queueLength = 15, where = 0x88a1454 "Transaction::waitForTransaction", name = 0xb7200c58 "Transaction::syncActive"}, syncIndexes = {<SynchronizationObject> = {_vptr.SynchronizationObject = 0x889f458}, monitorCount = 0, mutex = {<SynchronizationObject> = { _vptr.SynchronizationObject = 0x88ab7b8}, holder = 0x0, mutex = {__data = {__lock = 0, __count = 0, __owner = 0, __kind = 0, __nusers = 0, { __spins = 0, __list = {__next = 0x0}}}, __size = '\0' <repeats 23 times>, __align = 0}}, queue = 0x0, exclusiveThread = 0x0, readers = 0, waiters = 0, lockState = 0, stalls = 0, objectId = 141847, sharedCount = 0, collisionCount = 0, exclusiveCount = 1, waitCount = 0, queueLength = 0, where = 0x88a1237 "Transaction::add", name = 0xb71ff1f8 "Transaction::syncIndexes"}, syncObject = {<SynchronizationObject> = { _vptr.SynchronizationObject = 0x889f458}, monitorCount = 0, mutex = {<SynchronizationObject> = {_vptr.SynchronizationObject = 0x88ab7b8}, holder = 0x0, mutex = {__data = {__lock = 0, __count = 0, __owner = 0, __kind = 0, __nusers = 0, {__spins = 0, __list = {__next = 0x0}}}, __size = '\0' <repeats 23 times>, __align = 0}}, queue = 0x0, exclusiveThread = 0x0, readers = 0, waiters = 0, lockState = 0, stalls = 0, objectId = 141848, sharedCount = 0, collisionCount = 0, exclusiveCount = 2, waitCount = 0, queueLength = 0, where = 0x88a17aa "Transaction::initialize", name = 0xb71f8e30 "Transaction::syncObject"}, syncSavepoints = {<SynchronizationObject> = {_vptr.SynchronizationObject = 0x889f458}, monitorCount = 0, mutex = {<SynchronizationObject> = {_vptr.SynchronizationObject = 0x88ab7b8}, holder = 0x0, mutex = {__data = {__lock = 0, __count = 0, __owner = 0, __kind = 0, __nusers = 0, {__spins = 0, __list = {__next = 0x0}}}, __size = '\0' <repeats 23 times>, __align = 0}}, queue = 0x0, exclusiveThread = 0x0, readers = 0, waiters = 0, lockState = 0, stalls = 0, objectId = 141849, sharedCount = 0, collisionCount = 0, exclusiveCount = 0, waitCount = 0, queueLength = 0, where = 0x0, name = 0xb71ff230 "Transaction::syncSavepoints"}, totalRecordData = 0, totalRecords = 399, chilledRecords = 0, chilledBytes = 0, thawedRecords = 0, thawedBytes = 0, debugThawedRecords = 0, debugThawedBytes = 0, committedRecords = 0, deletedRecords = 0, chillPoint = 0xb71ff174, scanIndexCount = 2, numberStates = 8, state = 0, dependencies = 7, useCount = 15, inList = 1, firstRecord = 0xa9ad0738, lastRecord = 0xa9ad54c8}
[29 Jun 2008 11:15]
Philip Stoev
(gdb) print * transaction $7 = {_vptr.Transaction = 0x88a1a10, connection = 0xad813138, database = 0xb7370640, transactionId = 29371, oldestActive = 29287, blockedBy = 0, curSavePointId = 3, next = 0xb71f8468, prior = 0xb7222240, waitingFor = 0x0, savePoints = 0xb71fef4c, freeSavePoints = 0xb71fef38, localSavePoints = {{ next = 0x0, savepoints = 0xcccccccc, backloggedRecords = 0xcccccccc, records = 0xcccccccc, id = -858993460}, {next = 0xb71fef10, savepoints = 0xcccccccc, backloggedRecords = 0xcccccccc, records = 0xcccccccc, id = -858993460}, {next = 0xb71fef24, savepoints = 0x0, backloggedRecords = 0x0, records = 0xb71ff174, id = 3}, {next = 0xb71fef60, savepoints = 0x0, backloggedRecords = 0x0, records = 0xb71ff174, id = 2}, { next = 0x0, savepoints = 0x0, backloggedRecords = 0x0, records = 0xb71ff174, id = 1}}, deferredIndexes = 0xad81fa98, thread = 0xad813058, blockingRecord = 0x0, backloggedRecords = 0x0, startTime = 775, deferredIndexCount = 1, statesAllocated = 9, isolationLevel = 8, xidLength = 0, mySqlThreadId = 9, xid = 0x0, states = 0xb7217cc8, commitTriggers = false, systemTransaction = false, hasUpdates = true, writePending = true, pendingPageWrites = false, hasLocks = true, syncActive = {<SynchronizationObject> = {_vptr.SynchronizationObject = 0x889f458}, monitorCount = 0, mutex = {<SynchronizationObject> = {_vptr.SynchronizationObject = 0x88ab7b8}, holder = 0x0, mutex = {__data = {__lock = 0, __count = 0, __owner = 0, __kind = 0, __nusers = 0, {__spins = 0, __list = {__next = 0x0}}}, __size = '\0' <repeats 23 times>, __align = 0}}, queue = 0xb71abe60, exclusiveThread = 0xad813058, readers = 0, waiters = 5, lockState = -1, stalls = 6, objectId = 141846, sharedCount = 0, collisionCount = 0, exclusiveCount = 1, waitCount = 6, queueLength = 15, where = 0x88a1454 "Transaction::waitForTransaction", name = 0xb7200c58 "Transaction::syncActive"}, syncIndexes = {<SynchronizationObject> = {_vptr.SynchronizationObject = 0x889f458}, monitorCount = 0, mutex = {<SynchronizationObject> = { _vptr.SynchronizationObject = 0x88ab7b8}, holder = 0x0, mutex = {__data = {__lock = 0, __count = 0, __owner = 0, __kind = 0, __nusers = 0, { __spins = 0, __list = {__next = 0x0}}}, __size = '\0' <repeats 23 times>, __align = 0}}, queue = 0x0, exclusiveThread = 0x0, readers = 0, waiters = 0, lockState = 0, stalls = 0, objectId = 141847, sharedCount = 0, collisionCount = 0, exclusiveCount = 1, waitCount = 0, queueLength = 0, where = 0x88a1237 "Transaction::add", name = 0xb71ff1f8 "Transaction::syncIndexes"}, syncObject = {<SynchronizationObject> = { _vptr.SynchronizationObject = 0x889f458}, monitorCount = 0, mutex = {<SynchronizationObject> = {_vptr.SynchronizationObject = 0x88ab7b8}, holder = 0x0, mutex = {__data = {__lock = 0, __count = 0, __owner = 0, __kind = 0, __nusers = 0, {__spins = 0, __list = {__next = 0x0}}}, __size = '\0' <repeats 23 times>, __align = 0}}, queue = 0x0, exclusiveThread = 0x0, readers = 0, waiters = 0, lockState = 0, stalls = 0, objectId = 141848, sharedCount = 0, collisionCount = 0, exclusiveCount = 2, waitCount = 0, queueLength = 0, where = 0x88a17aa "Transaction::initialize", name = 0xb71f8e30 "Transaction::syncObject"}, syncSavepoints = {<SynchronizationObject> = {_vptr.SynchronizationObject = 0x889f458}, monitorCount = 0, mutex = {<SynchronizationObject> = {_vptr.SynchronizationObject = 0x88ab7b8}, holder = 0x0, mutex = {__data = {__lock = 0, __count = 0, __owner = 0, __kind = 0, __nusers = 0, {__spins = 0, __list = {__next = 0x0}}}, __size = '\0' <repeats 23 times>, __align = 0}}, queue = 0x0, exclusiveThread = 0x0, readers = 0, waiters = 0, lockState = 0, stalls = 0, objectId = 141849, sharedCount = 0, collisionCount = 0, exclusiveCount = 0, waitCount = 0, queueLength = 0, where = 0x0, name = 0xb71ff230 "Transaction::syncSavepoints"}, totalRecordData = 0, totalRecords = 399, chilledRecords = 0, chilledBytes = 0, thawedRecords = 0, thawedBytes = 0, debugThawedRecords = 0, debugThawedBytes = 0, committedRecords = 0, deletedRecords = 0, chillPoint = 0xb71ff174, scanIndexCount = 2, numberStates = 8, state = 0, dependencies = 7, useCount = 15, inList = 1, firstRecord = 0xa9ad0738, lastRecord = 0xa9ad54c8}
[29 Jun 2008 15:32]
Philip Stoev
Grammar file for bug 37726
Attachment: bug37725.yy (text/plain), 1.52 KiB.
[29 Jun 2008 15:34]
Philip Stoev
To run the test case, please check out the mysql-test-extra-6.0 tree. Then run: $ cd mysql-test-extra-6.0/mysql-test/gentest $ ./runall.pl --basedir=/path/to/6.0-falcon --engine=Falcon --grammar=/location/of/bug37726.yy The script will start the server and proceed to run random queries against it. Crash should happen within 5 minutes. Please let me know if a simpler test case is required.
[7 Jul 2008 21:57]
Kevin Lewis
Vlad, Will you take a high priority look at this? Philip thinks it is a regression and thus may be a showstopper for 6.0.6.
[8 Jul 2008 10:24]
Philip Stoev
Thread stacks for bug 37725
Attachment: bug37725.threads (text/plain), 37.63 KiB.
[8 Jul 2008 11:14]
Philip Stoev
(gdb) print this->waitingFor $1 = (volatile Transaction *) 0xb71feee0 (gdb) print * this->waitingFor $2 = {_vptr.Transaction = 0x88a1a10, connection = 0xad813138, database = 0xb7370640, transactionId = 29371, oldestActive = 29287, blockedBy = 0, curSavePointId = 3, next = 0xb71f8468, prior = 0xb7222240, waitingFor = 0x0, savePoints = 0xb71fef4c, freeSavePoints = 0xb71fef38, localSavePoints = {{next = 0x0, savepoints = 0xcccccccc, backloggedRecords = 0xcccccccc, records = 0xcccccccc, id = -858993460}, { next = 0xb71fef10, savepoints = 0xcccccccc, backloggedRecords = 0xcccccccc, records = 0xcccccccc, id = -858993460}, { next = 0xb71fef24, savepoints = 0x0, backloggedRecords = 0x0, records = 0xb71ff174, id = 3}, {next = 0xb71fef60, savepoints = 0x0, backloggedRecords = 0x0, records = 0xb71ff174, id = 2}, {next = 0x0, savepoints = 0x0, backloggedRecords = 0x0, records = 0xb71ff174, id = 1}}, deferredIndexes = 0xad81fa98, thread = 0xad813058, blockingRecord = 0x0, backloggedRecords = 0x0, startTime = 775, deferredIndexCount = 1, statesAllocated = 9, isolationLevel = 8, xidLength = 0, mySqlThreadId = 9, xid = 0x0, states = 0xb7217cc8, commitTriggers = false, systemTransaction = false, hasUpdates = true, writePending = true, pendingPageWrites = false, hasLocks = true, syncActive = {<SynchronizationObject> = { _vptr.SynchronizationObject = 0x889f458}, monitorCount = 0, mutex = {<SynchronizationObject> = { _vptr.SynchronizationObject = 0x88ab7b8}, holder = 0x0, mutex = { __data = {__lock = 0, __count = 0, __owner = 0, __kind = 0, __nusers = 0, {__spins = 0, __list = {__next = 0x0}}}, __size = '\0' <repeats 23 times>, __align = 0}}, queue = 0xb71abe60, exclusiveThread = 0xad813058, readers = 0, waiters = 5, lockState = -1, stalls = 6, objectId = 141846, sharedCount = 0, collisionCount = 0, exclusiveCount = 1, waitCount = 6, queueLength = 15, where = 0x88a1454 "Transaction::waitForTransaction", name = 0xb7200c58 "Transaction::syncActive"}, syncIndexes = {<SynchronizationObject> = { _vptr.SynchronizationObject = 0x889f458}, monitorCount = 0, mutex = {<SynchronizationObject> = { _vptr.SynchronizationObject = 0x88ab7b8}, holder = 0x0, mutex = { __data = {__lock = 0, __count = 0, __owner = 0, __kind = 0, __nusers = 0, {__spins = 0, __list = {__next = 0x0}}}, __size = '\0' <repeats 23 times>, __align = 0}}, queue = 0x0, exclusiveThread = 0x0, readers = 0, waiters = 0, lockState = 0, stalls = 0, objectId = 141847, sharedCount = 0, collisionCount = 0, exclusiveCount = 1, waitCount = 0, queueLength = 0, where = 0x88a1237 "Transaction::add", name = 0xb71ff1f8 "Transaction::syncIndexes"}, syncObject = {<SynchronizationObject> = { _vptr.SynchronizationObject = 0x889f458}, monitorCount = 0, mutex = {<SynchronizationObject> = { _vptr.SynchronizationObject = 0x88ab7b8}, holder = 0x0, mutex = { __data = {__lock = 0, __count = 0, __owner = 0, __kind = 0, __nusers = 0, {__spins = 0, __list = {__next = 0x0}}}, __size = '\0' <repeats 23 times>, __align = 0}}, queue = 0x0, exclusiveThread = 0x0, readers = 0, waiters = 0, lockState = 0, stalls = 0, objectId = 141848, sharedCount = 0, collisionCount = 0, exclusiveCount = 2, waitCount = 0, queueLength = 0, where = 0x88a17aa "Transaction::initialize", name = 0xb71f8e30 "Transaction::syncObject"}, syncSavepoints = {<SynchronizationObject> = { _vptr.SynchronizationObject = 0x889f458}, monitorCount = 0, mutex = {<SynchronizationObject> = { _vptr.SynchronizationObject = 0x88ab7b8}, holder = 0x0, mutex = { __data = {__lock = 0, __count = 0, __owner = 0, __kind = 0, __nusers = 0, {__spins = 0, __list = {__next = 0x0}}}, __size = '\0' <repeats 23 times>, __align = 0}}, queue = 0x0, exclusiveThread = 0x0, readers = 0, waiters = 0, lockState = 0, stalls = 0, objectId = 141849, sharedCount = 0, collisionCount = 0, exclusiveCount = 0, waitCount = 0, queueLength = 0, where = 0x0, name = 0xb71ff230 "Transaction::syncSavepoints"}, totalRecordData = 0, totalRecords = 399, chilledRecords = 0, chilledBytes = 0, thawedRecords = 0, thawedBytes = 0, debugThawedRecords = 0, debugThawedBytes = 0, committedRecords = 0, deletedRecords = 0, chillPoint = 0xb71ff174, scanIndexCount = 2, numberStates = 8, state = 0, dependencies = 7, useCount = 15, inList = 1, firstRecord = 0xa9ad0738, lastRecord = 0xa9ad54c8}
[9 Jul 2008 19:38]
Philip Stoev
Results from testing the patch from http://lists.mysql.com/commits/49256 no patch, no -march=i486 = crash no patch, -march=i486 = no crash patch, -march=i486 = no crash patch, no -march=i486 - does not compile Vlad says: Now my working theory is that without -march=i486, compiler backend would not bother with cmpxchg semantics and that possibly rearranged instructions in such a way that is ZF flag was modified again which would in crash at runtime. I make it the case for Build-Team , I know maria is using exactly the same inline assembly, so it is not only Falcon case. The problem does not seem to appear on gcc4.1, interesting.
[9 Jul 2008 19:56]
Vladislav Vaintroub
Build-team, assigning to you. Basically, what we've found during the test on philips GCC 4.3.0 compiler on 32 bit is that if -march is not set (to i486 or later) compare-exchange inline assembly appears to be broken - the assembly equivalent of __sync_bool_compare_and_swap does not always retuern correct value , using GCC atomic builtins results into link error. So could I make a request to compile with at least -march=i486 on 32 bit linux ? or -march=i586/i686 if you like it better.
[11 Jul 2008 10:23]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/49547 2731 Vladislav Vaintroub 2008-07-11 Bug#37725 : assertion in transaction::waitForTransaction The patch fixes the problem where Transaction::waitingFor is not reset if LOCK_TIMEOUT exception is thrown by Sync::timedout().
[11 Jul 2008 16:54]
Kevin Lewis
Vlad, Code looks good. Nice catch (pun intended)
[22 Aug 2008 21:21]
Kevin Lewis
This fix is in version 6.0.6
[1 Oct 2008 12:11]
Jon Stephens
Documented in the 6.0.6 changelog as follows: Binaries built using gcc 4.3 could crash when running large numbers of DML statements on Falcon tables.