Closed
Bug 525356
Opened 15 years ago
Closed 15 years ago
windows debug unit tests: test_connection_executeAsync.js and test_statement_executeAsync.js failing frequently (fatal assertion)
Categories
(Core :: SQLite and Embedded Database Bindings, defect)
Tracking
()
RESOLVED
FIXED
mozilla1.9.3a1
Tracking | Status | |
---|---|---|
status1.9.2 | --- | beta5-fixed |
People
(Reporter: dbaron, Assigned: sdwilsh)
References
Details
(Keywords: intermittent-failure)
Attachments
(1 file, 3 obsolete files)
3.06 KB,
patch
|
asuth
:
review+
beltzner
:
approval1.9.2+
|
Details | Diff | Splinter Review |
A very frequent (as in, possibly too frequent to enable the builds) random orange on the Windows debug everythingelse is:
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256837459.1256841719.26784.gz
WINNT 5.2 mozilla-central test debug everythingelse on 2009/10/29 10:30:59
TEST-UNEXPECTED-FAIL | e:\builds\moz2_slave\mozilla-central-win32-debug-unittest-everythingelse\build\xpcshell\tests\test_storage\unit\test_connection_executeAsync.js | test failed (with xpcshell return code: 3), see following log:
###!!! ASSERTION: sqlite3_close failed. There are probably outstanding statements that are listed above!: 'srv == SQLITE_OK', file e:/builds/moz2_slave/mozilla-central-win32-debug/build/storage/src/mozStorageConnection.cpp, line 523
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256830304.1256834457.5855.gz
WINNT 5.2 mozilla-central test debug everythingelse on 2009/10/29 08:31:44
TEST-UNEXPECTED-FAIL | e:\builds\moz2_slave\mozilla-central-win32-debug-unittest-everythingelse\build\xpcshell\tests\test_storage\unit\test_connection_executeAsync.js | test failed (with xpcshell return code: 3), see following log:
WARNING: NS_ENSURE_TRUE(mThread != PR_GetCurrentThread()) failed: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/xpcom/threads/nsThread.cpp, line 440
WARNING: SQL statement 'INSERT INTO test (id, string, number, nuller, blober) VALUES (:int, :text, :real, :null, :blob)' was not finalized: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/storage/src/mozStorageConnection.cpp, line 510
WARNING: SQL statement 'INSERT INTO test (id, string, number, nuller, blober) VALUES (:int, :text, :real, :null, :blob)' was not finalized: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/storage/src/mozStorageConnection.cpp, line 510
WARNING: SQL statement 'INSERT INTO test (id, string, number, nuller, blober) VALUES (:int, :text, :real, :null, :blob)' was not finalized: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/storage/src/mozStorageConnection.cpp, line 510
WARNING: SQL statement 'INSERT INTO test (id, string, number, nuller, blober) VALUES (:int, :text, :real, :null, :blob)' was not finalized: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/storage/src/mozStorageConnection.cpp, line 510
WARNING: SQL statement 'INSERT INTO test (id, string, number, nuller, blober) VALUES (:int, :text, :real, :null, :blob)' was not finalized: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/storage/src/mozStorageConnection.cpp, line 510
###!!! ASSERTION: sqlite3_close failed. There are probably outstanding statements that are listed above!: 'srv == SQLITE_OK', file e:/builds/moz2_slave/mozilla-central-win32-debug/build/storage/src/mozStorageConnection.cpp, line 523
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1256827051.1256832725.16725.gz
WINNT 5.2 mozilla-central test debug everythingelse on 2009/10/29 07:37:31
TEST-UNEXPECTED-FAIL | e:\builds\moz2_slave\mozilla-central-win32-debug-unittest-everythingelse\build\xpcshell\tests\test_storage\unit\test_connection_executeAsync.js | test failed (with xpcshell return code: 3), see following log:
WARNING: NS_ENSURE_TRUE(mThread != PR_GetCurrentThread()) failed: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/xpcom/threads/nsThread.cpp, line 440
WARNING: SQL statement 'INSERT INTO test (id, string, number, nuller, blober) VALUES (:int, :text, :real, :null, :blob)' was not finalized: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/storage/src/mozStorageConnection.cpp, line 510
WARNING: SQL statement 'INSERT INTO test (id, string, number, nuller, blober) VALUES (:int, :text, :real, :null, :blob)' was not finalized: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/storage/src/mozStorageConnection.cpp, line 510
WARNING: SQL statement 'INSERT INTO test (id, string, number, nuller, blober) VALUES (:int, :text, :real, :null, :blob)' was not finalized: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/storage/src/mozStorageConnection.cpp, line 510
WARNING: SQL statement 'INSERT INTO test (id, string, number, nuller, blober) VALUES (:int, :text, :real, :null, :blob)' was not finalized: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/storage/src/mozStorageConnection.cpp, line 510
WARNING: SQL statement 'INSERT INTO test (id, string, number, nuller, blober) VALUES (:int, :text, :real, :null, :blob)' was not finalized: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/storage/src/mozStorageConnection.cpp, line 510
###!!! ASSERTION: sqlite3_close failed. There are probably outstanding statements that are listed above!: 'srv == SQLITE_OK', file e:/builds/moz2_slave/mozilla-central-win32-debug/build/storage/src/mozStorageConnection.cpp, line 523
Assignee | ||
Comment 1•15 years ago
|
||
I'm betting these are the cached async statements from http://mxr.mozilla.org/mozilla-central/source/storage/test/unit/test_connection_executeAsync.js#164. Not sure why they aren't being finalized though...
Assignee | ||
Comment 2•15 years ago
|
||
I'd also love to know what WARNING: NS_ENSURE_TRUE(mThread != PR_GetCurrentThread()) failed: file e:/builds/moz2_slave/mozilla-central-win32-debug/build/xpcom/threads/nsThread.cpp, line 440 is from. That happens right before my warnings. Maybe we can add some debugging code there to get a stack?
Comment 3•15 years ago
|
||
Do you think we can change these sqlite assertions such that they trigger Breakpad, getting us an actual stack when they happen on debug unittests?
(See bug 524522 for the JS_ASSERT equivalent.)
Reporter | ||
Comment 4•15 years ago
|
||
This is just the standard NS_ASSERTION, but xpcshell tests are run with fatal assertions.
Assignee | ||
Comment 5•15 years ago
|
||
This is actually a storage error - I just use NS_ERROR. Do we have a macro that magically triggers breakpad?
I would love to see the stack in the error from comment 2 though. I suspect that that may be related to the failure.
Comment 6•15 years ago
|
||
Ah, sorry. I think we get screwed by our stackwalking code here because the PDB files aren't where it expects them to be, since we're running from a packaged build. They are available though, in the symbols package (although they're compressed, but symsrv.dll knows how to deal with that as long as you give it a directory to use as a downstream store.)
Comment 7•15 years ago
|
||
(In reply to comment #6)
> Ah, sorry. I think we get screwed by our stackwalking code here because the PDB
> files aren't where it expects them to be, since we're running from a packaged
> build. They are available though, in the symbols package (although they're
> compressed, but symsrv.dll knows how to deal with that as long as you give it a
> directory to use as a downstream store.)
So, whats the next step here?
We're having to run unittests both ways until this is fixed, and the extra load is hurting wait times.
Comment 8•15 years ago
|
||
Comment 9•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257533106.1257537408.23678.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/06 10:45:06
Blocks: 438871
Whiteboard: [orange]
Comment 10•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257579867.1257583703.30090.gz#err0
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/06 23:44:27
Comment 11•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257704856.1257708862.14528.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/08 10:27:36
Reporter | ||
Comment 12•15 years ago
|
||
Now that we got build hiddenness sorted out, I decided to enable the build anyway, so this will probably be the most common random orange (or maybe second, behind the places test failures) until it's fixed.
Comment 13•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257711194.1257715348.21867.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/08 12:13:14
Comment 14•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257711805.1257719485.1412.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/08 12:23:25
Comment 15•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257720058.1257725205.30622.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/08 14:40:58
Comment 16•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257804320.1257808970.32313.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/09 14:05:20
Comment 17•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257809907.1257814934.2245.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/09 15:38:27
Comment 18•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257791949.1257796777.25228.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/09 10:39:09
Comment 19•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257830788.1257836109.16111.gz#err0
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/09 21:26:28
Comment 20•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257875780.1257880442.12448.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/10 09:56:20
Comment 21•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257873050.1257879310.31228.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/10 09:10:50
Comment 22•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257870980.1257877644.13491.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/10 08:36:20
Comment 23•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1257968262.1257973297.30961.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/11 11:37:42
"s: moz2-win32-slave38"
Comment 24•15 years ago
|
||
Btw, I filed bug 528019 on the failure in "test_statement_executeAsync.js" in that last log. (Looks similar to this bug's failure, but it's in a different test, and I didn't see it mentioned here explicitly, so I figured it merited a different bug.)
I see now that some (but not all) of the earlier logs here have that failure as well -- I'll note those on the other bug.
Comment 25•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258027033.1258031970.11637.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/12 03:57:13
Reporter | ||
Comment 26•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258060851.1258067808.2381.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/12 13:20:51
Comment 27•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258081555.1258086853.21997.gz#err1
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/12 19:05:55
Comment 28•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258070062.1258077904.19636.gz#err6
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/12 15:54:22
Comment 29•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258119658.1258125323.7599.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/13 05:40:58
"s: moz2-win32-slave32"
Comment 30•15 years ago
|
||
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/13 10:31:33
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258137093.1258143024.21524.gz
Comment 31•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258132314.1258139882.16485.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/13 09:11:54
"s: moz2-win32-slave19"
Assignee | ||
Updated•15 years ago
|
Summary: windows debug unit tests: test_storage\unit\test_connection_executeAsync.js failing frequently (fatal assertion) → windows debug unit tests: test_connection_executeAsync.js and test_statement_executeAsync.js failing frequently (fatal assertion)
Assignee | ||
Comment 33•15 years ago
|
||
(In reply to comment #0)
> WARNING: NS_ENSURE_TRUE(mThread != PR_GetCurrentThread()) failed: file
> e:/builds/moz2_slave/mozilla-central-win32-debug/build/xpcom/threads/nsThread.cpp,
> line 440
So, this is the problem, and this is why the bug is happening. The only way this could happen is if the connection's last reference was freed on the async thread, and then we call close, which calls Shutdown. Doing more investigation now.
Assignee | ||
Comment 34•15 years ago
|
||
So, AsyncStatementFinalizer (in mozStorageStatement.cpp) should really be holding onto (strong reference) the Connection that creates it. However, that means the last reference to the connection would still be on the async thread, so we'd still hit some of this (the Shutdown call would fail). However, I'm not sure we should care if that Shutdown call fails, since it'll shutdown anyway when the thread is released for the last time (I think - need to verify that. Do not want it hanging around until xpcom-shutdown-threads).
Assignee | ||
Comment 35•15 years ago
|
||
Also, this is a really subtle thread-safety bug. I'm glad we caught this :)
This would result in a leaked connection in non-debug builds (sqlite3 object, not mozilla::storage::Connection).
Assignee | ||
Comment 36•15 years ago
|
||
Confirmed that not shutting down will keep the thread alive. Need to proxy the release, which is all sorts of sadfaces.
Comment 37•15 years ago
|
||
Comment 38•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258209183.1258216167.31854.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/14 06:33:03
"s: moz2-win32-slave22"
Reporter | ||
Comment 39•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258248780.1258254353.1512.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/14 17:33:00
TEST-UNEXPECTED-FAIL | e:\builds\moz2_slave\mozilla-central-win32-debug-unittest-everythingelse\build\xpcshell\tests\test_storage\unit\test_statement_executeAsync.js | test failed (with xpcshell return code: 3), see following log:
Comment 40•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258258769.1258264312.12608.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/14 20:19:29
"s: moz2-win32-slave37"
Comment 41•15 years ago
|
||
Comment 42•15 years ago
|
||
Comment 43•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258295298.1258302436.6167.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/15 06:28:18
"s: moz2-win32-slave18"
Comment 44•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258302997.1258308188.8545.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/15 08:36:37
"s: moz2-win32-slave16"
Comment 45•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258313427.1258318393.27224.gz
Linux mozilla-central debug test everythingelse on 2009/11/15 11:30:27
s: moz2-linux-slave18
Comment 46•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258383331.1258390032.17057.gz
WINNT 5.2 mozilla-central debug test everythingelse
Comment 47•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258385775.1258391397.975.gz
WINNT 5.2 mozilla-central debug test everythingelse
Comment 48•15 years ago
|
||
Comment 49•15 years ago
|
||
Comment 50•15 years ago
|
||
Comment 51•15 years ago
|
||
Comment 52•15 years ago
|
||
Reporter | ||
Comment 53•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258462064.1258469113.8433.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/17 04:47:44
"s: moz2-win32-slave28"
TEST-UNEXPECTED-FAIL | e:\builds\moz2_slave\mozilla-central-win32-debug-unittest-everythingelse\build\xpcshell\tests\test_storage\unit\test_connection_executeAsync.js | test failed (with xpcshell return code: 3), see following log:
TEST-UNEXPECTED-FAIL | e:\builds\moz2_slave\mozilla-central-win32-debug-unittest-everythingelse\build\xpcshell\tests\test_storage\unit\test_statement_executeAsync.js | test failed (with xpcshell return code: 3), see following log:
Reporter | ||
Comment 54•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258459314.1258466689.12839.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/17 04:01:54
"s: moz2-win32-slave07"
TEST-UNEXPECTED-FAIL | e:\builds\moz2_slave\mozilla-central-win32-debug-unittest-everythingelse\build\xpcshell\tests\test_storage\unit\test_connection_executeAsync.js | test failed (with xpcshell return code: 3), see following log:
TEST-UNEXPECTED-FAIL | e:\builds\moz2_slave\mozilla-central-win32-debug-unittest-everythingelse\build\xpcshell\tests\test_storage\unit\test_statement_executeAsync.js | test failed (with xpcshell return code: 3), see following log:
Comment 55•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258485475.1258492471.16862.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/17 11:17:55
"s: moz2-win32-slave01"
Assignee | ||
Updated•15 years ago
|
Assignee: nobody → sdwilsh
Assignee | ||
Comment 56•15 years ago
|
||
Attachment #413094 -
Flags: review?(bugmail)
Assignee | ||
Updated•15 years ago
|
Whiteboard: [orange] → [orange][needs review asuth]
Updated•15 years ago
|
Attachment #413094 -
Flags: review?(bugmail) → review+
Assignee | ||
Updated•15 years ago
|
Whiteboard: [orange][needs review asuth] → [orange][can land]
Reporter | ||
Comment 57•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258643242.1258648613.24170.gz
Linux mozilla-central debug test everythingelse on 2009/11/19 07:07:22
s: moz2-linux-slave19
TEST-UNEXPECTED-FAIL | /builds/moz2_slave/mozilla-central-linux-debug-unittest-everythingelse/build/xpcshell/tests/test_storage/unit/test_connection_executeAsync.js | test failed (with xpcshell return code: 1), see following log:
TEST-UNEXPECTED-FAIL | /builds/moz2_slave/mozilla-central-linux-debug-unittest-everythingelse/build/xpcshell/tests/test_storage/unit/test_connection_executeAsync.js | application crashed (minidump found)
2 libnspr4.so!PR_Abort [prlog.c:24ddb9b3d3ed : 548 + 0x4]
eip = 0x00ae5605 esp = 0xb5dcecb0 ebp = 0xb5dcecb8
Found by: previous frame's frame pointer
3 libxul.so!_ZL5AbortPKc [nsDebugImpl.cpp:24ddb9b3d3ed : 370 + 0x4]
eip = 0x0207ff54 esp = 0xb5dcecc0 ebp = 0xb5dcecc8
Found by: previous frame's frame pointer
4 libxul.so!NS_DebugBreak_P [nsDebugImpl.cpp:24ddb9b3d3ed : 350 + 0xd]
eip = 0x02080564 esp = 0xb5dcecd0 ebp = 0xb5dcf0f8
Found by: previous frame's frame pointer
5 libxul.so!mozilla::storage::Connection::Close() [mozStorageConnection.cpp:24ddb9b3d3ed : 522 + 0x37]
eip = 0x01ddc8f8 esp = 0xb5dcf100 ebp = 0xb5dcf1b8
Found by: previous frame's frame pointer
...
Reporter | ||
Comment 58•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258642928.1258649496.1741.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/19 07:02:08
"s: moz2-win32-slave34"
TEST-UNEXPECTED-FAIL | e:\builds\moz2_slave\mozilla-central-win32-debug-unittest-everythingelse\build\xpcshell\tests\test_storage\unit\test_connection_executeAsync.js | test failed (with xpcshell return code: 3), see following log:
Reporter | ||
Comment 59•15 years ago
|
||
I landed this (despite the freeze) as part of an effort to get the tree green enough again that people won't just ignore the orange:
http://hg.mozilla.org/mozilla-central/rev/4a0bf3ffd767
(Was this something you wanted to try to get on 1.9.2?)
Status: NEW → RESOLVED
Closed: 15 years ago
Resolution: --- → FIXED
Whiteboard: [orange][can land] → [orange]
Reporter | ||
Comment 60•15 years ago
|
||
Backed out due to pretty much everything crashing:
http://hg.mozilla.org/mozilla-central/rev/83a14d23f6cd
http://hg.mozilla.org/mozilla-central/rev/76d83d28411e
There's a decent looking log in:
http://tinderbox.mozilla.org/showlog.cgi?tree=Firefox-Unittest&errorparser=unittest&logfile=1258666173.1258666870.11273.gz&buildtime=1258666173&buildname=Linux%20mozilla-central%20debug%20test%20mochitests-2%2f5&fulltext=1
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Assignee | ||
Comment 61•15 years ago
|
||
So, the log is rather interesting:
Thread 6 (crashed)
0 libxul.so!NS_ProxyRelease(nsIEventTarget*, nsISupports*, int) [nsProxyRelease.cpp : 75 + 0x8]
eip = 0x0165d53d esp = 0xb36ff280 ebp = 0xb36ff2b8 ebx = 0x019e150c
esi = 0xb374d140 edi = 0x00000000 eax = 0x00000028 ecx = 0xb36ffc00
edx = 0x0168b93b efl = 0x00010246
Found by: given as instruction pointer in context
1 libxul.so!mozilla::storage::(anonymous namespace)::AsyncStatementFinalizer::Run() [nsProxyRelease.h : 61 + 0x8]
eip = 0x01557315 esp = 0xb36ff2c0 ebp = 0xb36ff2d8
Found by: previous frame's frame pointer
2 libxul.so!nsThread::ProcessNextEvent(int, int*) [nsThread.cpp:c6991463f32a : 527 + 0xa]
eip = 0x0168b842 esp = 0xb36ff2e0 ebp = 0xb36ff318
Found by: previous frame's frame pointer
3 libxul.so!NS_ProcessNextEvent_P(nsIThread*, int) [nsThreadUtils.cpp : 250 + 0xd]
eip = 0x0165bd18 esp = 0xb36ff320 ebp = 0xb36ff348
Found by: previous frame's frame pointer
4 libxul.so!nsThread::ThreadFunc(void*) [nsThread.cpp:c6991463f32a : 253 + 0x9]
eip = 0x0168bf8f esp = 0xb36ff350 ebp = 0xb36ff388
Found by: previous frame's frame pointer
5 libnspr4.so!_pt_root [ptthread.c:c6991463f32a : 228 + 0x8]
eip = 0x0013eec1 esp = 0xb36ff390 ebp = 0xb36ff3b8
Found by: previous frame's frame pointer
6 libpthread-2.5.so + 0x52da
eip = 0x00c042db esp = 0xb36ff3c0 ebp = 0xb36ff4a8
Found by: previous frame's frame pointer
This means that it crashed in NS_RELEASE, which means the object was already free'd I guess. This also implies that the thread that called finalize here is the background thread. I cannot explain the double free, but I can explain how we end up being called on the background thread. mozilla::storage::AsyncExecuteStatements::mStatements is an array of StatementData objects, each of which holds a reference to its owning mozilla::storage::Statement object. If this is the last reference to that Statement, it'll be released on the background thread. This is fixable, but I'll need the work in bug 496019 to do so.
Actually, that explains the double release too, since we unconditionally call Finalize in ~Statement. Fix forthcoming.
Status: REOPENED → ASSIGNED
Depends on: 496019
Assignee | ||
Comment 62•15 years ago
|
||
Only a small difference here. Hold onto the connection instead of the statement, and proxy to the connections opened thread to be sure.
Attachment #413094 -
Attachment is obsolete: true
Attachment #413450 -
Flags: review?(bugmail)
Comment 63•15 years ago
|
||
Comment on attachment 413450 [details] [diff] [review]
v2.0
It is safe to hand out a reference to the Connection because the Statement holds a reference to the Connection until its death, a death which cannot possibly occur until after Finalize returns. This means that the refcount of Connection is >= 1 at the time we are adding a new reference to it and everything is safe.
Attachment #413450 -
Flags: review?(bugmail) → review+
Comment 64•15 years ago
|
||
Hm, I think bugzilla has a new bug, as I'm pretty sure I pasted in a lot more than that last comment. What I really wrote:
If I understand the rationale correctly, the idea is that Finalize is called during the destructor, so Finalize is not allowed to go around creating new references to the Statement. This is why you are changing the patch to hold a reference to the Connection instead of the Statement.
It is safe to hand out a reference to the Connection because the Statement holds a reference to the Connection until its death, a death which cannot possibly occur until after Finalize returns. This means that the refcount of Connection is >= 1 at the time we are adding a new reference to it and everything is safe.
We don't actually need a reference to the Connection saved in the finalizer, we just need something to proxy the release of the Connection reference to the main thread in the event we are on the async thread in case there is incorrect storage-using code at work.
Correct storage-using code would have manually finalized each statement and issued a call to asyncClose. AsyncCloseConnection holds onto a copy of the Connection and dispatch itself to the main thread. Since it ends up being the last piece of code being run on the async thread, there is also no chance of any other code trying to destroy the Connection on the async thread.
In the incorrect case, the dependence of the code on the statement finalizer to proxy the release raises an edge-case flag, since it's possible for bad code to call Finalize on that statement but not call asyncClose on the Statement. Happily, in that case the AsyncStatementFinalizer must already be in the async thread's queue with a Connection reference and will still ensure that the proxy release happens when it runs.
It would be great if you could add some comments to the code about why we pass a reference to the Connection and why we must proxy its release; it's not particularly obvious. At the minimum you should make the doxygen you are adding for the AsyncStatementFinalizer be correct. ("@param aParent" is from the last iteration of the patch.)
PS: shouldn't threadOpenedOn be mThreadOpenedOn?
Reporter | ||
Comment 65•15 years ago
|
||
I was going to test attachment 413450 [details] [diff] [review], but it doesn't seem to apply on top of current mozilla-central.
Comment 66•15 years ago
|
||
You need https://bugzilla.mozilla.org/attachment.cgi?id=413085 from bug 496019 which this bug has been marked as depending on.
Comment 67•15 years ago
|
||
(In reply to comment #64)
> PS: shouldn't threadOpenedOn be mThreadOpenedOn?
Whoops, had missed that it was public. Forget this point.
Assignee | ||
Comment 68•15 years ago
|
||
Updated per review comments.
Attachment #413450 -
Attachment is obsolete: true
Comment 69•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258754362.1258759684.5620.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/20 13:59:22
"s: moz2-win32-slave35"
Comment 70•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258772195.1258778892.21591.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/20 18:56:35
"s: moz2-win32-slave14"
Comment 71•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258801904.1258807855.15341.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/21 03:11:44
"s: moz2-win32-slave16"
Comment 72•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258892222.1258897570.16879.gz
WINNT 5.2 mozilla-central debug test everythingelse
Comment 73•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258906939.1258912206.25764.gz
WINNT 5.2 mozilla-central debug test everythingelse
Comment 74•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258921236.1258927942.10440.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/22 12:20:36
"s: moz2-win32-slave34"
Comment 75•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1258991815.1258997565.15960.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/23 07:56:55
"s: moz2-win32-slave35"
Comment 76•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259027894.1259035484.24432.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/23 17:58:14
"s: moz2-win32-slave25"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259037109.1259042496.6635.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/23 20:31:49
"s: moz2-win32-slave30"
Reporter | ||
Comment 77•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259039101.1259044408.27475.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/23 21:05:01
"s: moz2-win32-slave15"
TEST-UNEXPECTED-FAIL | e:\builds\moz2_slave\mozilla-central-win32-debug-unittest-everythingelse\build\xpcshell\tests\test_storage\unit\test_statement_executeAsync.js | test failed (with xpcshell return code: 3), see following log:
Comment 78•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259082175.1259087400.6650.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/24 09:02:55
"s: moz2-win32-slave40"
Comment 79•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259105905.1259113760.15775.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/24 15:38:25
"s: moz2-win32-slave41"
Comment 80•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259140144.1259145729.18454.gz
WINNT 5.2 mozilla-central debug test everythingelse
Comment 81•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259136455.1259141974.6385.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/25 00:07:35
"s: moz2-win32-slave38"
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259130697.1259136830.13874.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/24 22:31:37
"s: moz2-win32-slave35"
Comment 82•15 years ago
|
||
Comment 83•15 years ago
|
||
Comment 84•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259190792.1259197152.30368.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/11/25 15:13:12
"s: moz2-win32-slave31"
Comment 85•15 years ago
|
||
Comment 86•15 years ago
|
||
Comment 87•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259668507.1259673927.16758.gz&fulltext=1
WINNT 5.2 mozilla-central debug test everythingelse on 2009/12/01 03:55:07
Assignee | ||
Comment 88•15 years ago
|
||
I hope to land this later today. I'll check with drivers for an exception to the freeze due to the orangeness of this bug.
Assignee | ||
Comment 89•15 years ago
|
||
Status: ASSIGNED → RESOLVED
Closed: 15 years ago → 15 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla1.9.3a1
Assignee | ||
Comment 90•15 years ago
|
||
Asking for review for a bit of a sanity check to make sure this still makes sense without the other changes. I'm pretty sure it does, but an extra pair of eyes is always good.
Attachment #415471 -
Flags: review?(bugmail)
Comment 91•15 years ago
|
||
Comment on attachment 415471 [details] [diff] [review]
v2.1
I understand the scope of this bug to be that sqlite3_close fails in a unit test where the Connection is implicitly closed due to its reference count hitting zero and the closing happening before the async thread has had a chance to process its async statement finalization.
I concur that this patch will fix this by causing the Connection to stay alive until after the statement has been finalized.
Attachment #415471 -
Flags: review?(bugmail) → review+
Assignee | ||
Comment 92•15 years ago
|
||
I do not know how yet, but we were leaking (suspect bug 496019, not this). Backed out. We can take the 1.9.2 patch on mozilla-central once it greens up, so we no longer need the dependency.
http://build.mozillamessaging.com/buildbot/production/builders/WINNT%205.2%20comm-central%20bloat/builds/257/steps/shell_23/logs/stdio
http://hg.mozilla.org/mozilla-central/rev/c9b4ceaff189
http://hg.mozilla.org/mozilla-central/rev/1da324b95182
Comment 93•15 years ago
|
||
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox-Unittest/1259762054.1259767545.18016.gz
WINNT 5.2 mozilla-central debug test everythingelse on 2009/12/02 05:54:14
Assignee | ||
Updated•15 years ago
|
Attachment #413716 -
Attachment is obsolete: true
Assignee | ||
Updated•15 years ago
|
Attachment #415471 -
Attachment description: v2.1 for 1.9.2 → v2.1
Comment 94•15 years ago
|
||
Comment on attachment 415471 [details] [diff] [review]
v2.1
a192=beltzner
Attachment #415471 -
Flags: approval1.9.2+
Assignee | ||
Comment 95•15 years ago
|
||
This should stick better.
http://hg.mozilla.org/mozilla-central/rev/23d7fdb2efb6
Status: REOPENED → RESOLVED
Closed: 15 years ago → 15 years ago
Resolution: --- → FIXED
Assignee | ||
Comment 96•15 years ago
|
||
status1.9.2:
--- → final-fixed
Updated•12 years ago
|
Keywords: intermittent-failure
Updated•12 years ago
|
Whiteboard: [orange]
Updated•4 months ago
|
Product: Toolkit → Core
You need to log in
before you can comment on or make changes to this bug.
Description
•