Closed Bug 610789 Opened 14 years ago Closed 12 years ago

Intermittent failure in dom/indexedDB/test/test_writer_starvation.html | indexedDB error, code 1

Categories

(Core :: Storage: IndexedDB, defect)

Product:
Core
Component:
Storage: IndexedDB
Platform:
x86
macOS
Type:
defect
Priority:
Not set
Severity:
critical

Tracking

()

Status:
RESOLVED WORKSFORME

People

(Reporter: ehsan.akhgari, Unassigned)

References

Details

(Keywords: crash, intermittent-failure) 

http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1289338217.1289338687.15902.gz
Rev3 MacOSX Snow Leopard 10.6.2 mozilla-central debug test mochitests-2/5 on 2010/11/09 13:30:17

2481 INFO TEST-PASS | /tests/dom/indexedDB/test/test_writer_starvation.html | Correct mode - 1 should equal 1
2482 INFO TEST-PASS | /tests/dom/indexedDB/test/test_writer_starvation.html | Correct mode - 1 should equal 1
2483 INFO TEST-PASS | /tests/dom/indexedDB/test/test_writer_starvation.html | Correct mode - 1 should equal 1
2484 INFO TEST-PASS | /tests/dom/indexedDB/test/test_writer_starvation.html | Correct mode - 1 should equal 1
2485 INFO TEST-PASS | /tests/dom/indexedDB/test/test_writer_starvation.html | Correct mode - 1 should equal 1
2486 INFO TEST-PASS | /tests/dom/indexedDB/test/test_writer_starvation.html | write callback came before later reads - 101 should equal 101
WARNING: SQLite returned error code 1 , Storage will convert it to NS_ERROR_FAILURE: file /builds/slave/mozilla-central-macosx64-debug/build/storage/src/mozStoragePrivateHelpers.cpp, line 107
WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /builds/slave/mozilla-central-macosx64-debug/build/storage/src/mozStorageService.cpp, line 560
WARNING: NS_ENSURE_SUCCESS(rv, 0L) failed with result 0x80004005: file /builds/slave/mozilla-central-macosx64-debug/build/dom/indexedDB/IDBFactory.cpp, line 569
WARNING: NS_ENSURE_TRUE(connection) failed: file /builds/slave/mozilla-central-macosx64-debug/build/dom/indexedDB/IDBTransaction.cpp, line 254
NEXT ERROR 2487 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/indexedDB/test/test_writer_starvation.html | indexedDB error (0): The operation failed for reasons unrelated to the database itself and not covered by any other error code.
###!!! ASSERTION: This had better not be null!: 'mConnection', file /builds/slave/mozilla-central-macosx64-debug/build/dom/indexedDB/IDBTransaction.cpp, line 787
mozilla::dom::indexedDB::CommitHelper::Run [dom/indexedDB/IDBTransaction.cpp:789]
mozilla::dom::indexedDB::TransactionThreadPool::TransactionQueue::Run [dom/indexedDB/TransactionThreadPool.cpp:614]
nsThreadPool::Run [xpcom/threads/nsThreadPool.cpp:222]
nsThread::ProcessNextEvent [xpcom/threads/nsThread.cpp:609]
NS_ProcessNextEvent_P [nsThreadUtils.cpp:250]
nsThread::ThreadFunc [xpcom/threads/nsThread.cpp:276]
_pt_root [nsprpub/pr/src/pthreads/ptthread.c:190]
libSystem.B.dylib + 0x39f8e
###!!! ASSERTION: You can't dereference a NULL nsCOMPtr with operator->().: 'mRawPtr != 0', file ../../dist/include/nsCOMPtr.h, line 819
nsCOMPtr<mozIStorageConnection>::operator-> [nsCOMPtr.h:820]
mozilla::dom::indexedDB::CommitHelper::Run [dom/indexedDB/IDBTransaction.cpp:798]
mozilla::dom::indexedDB::TransactionThreadPool::TransactionQueue::Run [dom/indexedDB/TransactionThreadPool.cpp:614]
nsThreadPool::Run [xpcom/threads/nsThreadPool.cpp:222]
nsThread::ProcessNextEvent [xpcom/threads/nsThread.cpp:609]
NS_ProcessNextEvent_P [nsThreadUtils.cpp:250]
nsThread::ThreadFunc [xpcom/threads/nsThread.cpp:276]
_pt_root [nsprpub/pr/src/pthreads/ptthread.c:190]
libSystem.B.dylib + 0x39f8e
NEXT ERROR TEST-UNEXPECTED-FAIL | /tests/dom/indexedDB/test/test_writer_starvation.html | Exited with code 1 during test run
Severity: normal → critical
Ben claims with absolute certainty that he thinks that this could maybe have possibly gotten fixed. Perhaps.
Summary: Intermittent failure in dom/indexedDB/test/test_writer_starvation.html | indexedDB error (0): The operation failed for reasons unrelated to the database itself and not covered by any other error code, followed by a crash → Intermittent failure in dom/indexedDB/test/test_writer_starvation.html | indexedDB error, code 1
Pretty sure this was fixed with bug 619568.
Status: NEW → RESOLVED
Closed: 13 years ago
Resolution: --- → FIXED
http://tinderbox.mozilla.org/showlog.cgi?log=Firefox/1295652850.1295653540.11567.gz
Rev3 WINNT 5.1 mozilla-central opt test mochitests-2/5 on 2011/01/21 15:34:10
s: talos-r3-xp-022

4760 ERROR TEST-UNEXPECTED-FAIL |
/tests/dom/indexedDB/test/test_writer_starvation.html | indexedDB error, code 1
4761 ERROR TEST-UNEXPECTED-FAIL |
/tests/dom/indexedDB/test/test_writer_starvation.html |
[SimpleTest/SimpleTest.js, window.onerror] An error occurred - [object Event]
at undefined:undefined
4785 ERROR TEST-UNEXPECTED-FAIL |
/tests/dom/src/jsurl/test/test_bug351633-1.html | [SimpleTest/SimpleTest.js,
window.onerror] An error occurred - uncaught exception: [object StopIteration]
at :0

http://tinderbox.mozilla.org/showlog.cgi?log=TraceMonkey/1295906097.1295906792.28443.gz
Rev3 WINNT 5.1 tracemonkey opt test mochitests-2/5 on 2011/01/24 13:54:57
s: talos-r3-xp-036

2643 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/indexedDB/test/test_writer_starvation.html | indexedDB error, code 1
2644 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/indexedDB/test/test_writer_starvation.html | [SimpleTest/SimpleTest.js, window.onerror] An error occurred - [object Event] at undefined:undefined
2649 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/src/jsurl/test/test_bug351633-1.html | [SimpleTest/SimpleTest.js, window.onerror] An error occurred - uncaught exception: [object StopIteration] at :0
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
This failure seem to be almost permaorange when updating SQLite to 3.7.6.2, see http://tbpl.mozilla.org/?tree=Places&rev=566d8cc6d924 (ignore bug# and such, those changesets will be backed out)
I've done some debugging of the cases where we see a warning related to SQLite returning SQLITE_SCHEMA.
Looks like due to the stressing work this test does (opening more than 100 connections) we go over the safe reprepare limit of SQLite.
Practically, if a statement is prepared and then the schema changes, a subsequent statement step() fails, and SQLite automatically reprepares the statement, but only up to 5 times.
Sometimes in the test we hit that 7, 8 times due to the high number of connections, and SQlite gives up returning an error.
Looking at a queries dump it's not immediately clear what causes the schema invalidation, I just sent a mail to SQLite support to signal the issue and get hints.
Notice I can't ensure that ALL failures here are due to this limit since the error is also randomly changing, but some of them are due to this and it may cause unexpected consequences.
Based on the list of things that may invalidate statements I got from drh, our possible culprit is: PRAGMA foreign_keys = ON
When this pragma is executed all prepared statements have to be reprepared, and each indexedDB connection invokes it on creation.
We do more than just setting foreign_key on each new connection, Storage itself invokes sqlite3_create_function and sqlite3_create_collation, these also cause schema invalidation and repreparations. We cannot easily avoid hitting the  low repreparations limit when a lot of connections are created in a small timeframe.
I think the only way to go for now is to get a build flag to increase number of repreparations, drh said it was already under discussion.
Ben also answered me that each transaction in indexedDB has its own thread, so connections reuse is not easy.
Will push to Try a test patch with the limit artificially increased and see what happens.
So, SQLite 3.7.6 and 3.7.7 hit this random failure more often because of this fix:
http://www.sqlite.org/src/tktview?name=f7b4edece2

Opening a connection that is using shared cache may now invalidate the schema, since indexedDB uses shared cache mode (or better OpenDatabaseWithVFS does) it will invalidate the schema more often. Not using a shared cache would not hit this increase.

I didn't find discussion about shared cache in bug 593045, I suppose it was done for lower memory usage and table-locking due to the possibly high number of connections, but it's just my supposition. Ben, Sdwilsh may you comment on this?

Btw, to move on, we'll get a new compile-time option to increase the maximum number of statements reparse before throwing SQLITE_SCHEMA error, due to the nature of indexedDB and other Storage implmenters, I think it's a good idea for us to increase that limit, that by default is really low at 5 tries.
(In reply to comment #57)
> Opening a connection that is using shared cache may now invalidate the schema,
> since indexedDB uses shared cache mode (or better OpenDatabaseWithVFS does) it
> will invalidate the schema more often. Not using a shared cache would not hit
> this increase.
Uh, I thought we were not using shared cache with IndexedDB.  bent?
Component: DOM → DOM: IndexedDB
Version: Trunk → unspecified
Status: REOPENED → RESOLVED
Closed: 13 years ago → 12 years ago
Resolution: --- → WORKSFORME
Whiteboard: [orange]
You need to log in before you can comment on or make changes to this bug.