Closed Bug 1601919 Opened 4 years ago Closed 2 years ago

Intermittent dom/indexedDB/test/test_readonly_transactions.html | Test timed out.

Categories

(Core :: Storage: IndexedDB, defect, P5)

defect

Tracking

()

RESOLVED DUPLICATE of bug 1781616

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Filed by: rgurzau [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=279983430&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/K-bRoRFQTyu8oiyWq1PUZQ/runs/0/artifacts/public/logs/live_backing.log


[task 2019-12-06T10:12:45.648Z] 10:12:45 INFO - TEST-START | dom/indexedDB/test/test_readonly_transactions.html
[task 2019-12-06T10:17:51.266Z] 10:17:51 INFO - TEST-INFO | started process screentopng
[task 2019-12-06T10:17:51.745Z] 10:17:51 INFO - TEST-INFO | screentopng: exit 0
[task 2019-12-06T10:17:51.747Z] 10:17:51 INFO - Buffered messages logged at 10:12:45
[task 2019-12-06T10:17:51.747Z] 10:17:51 INFO - Running 'test_readonly_transactions.js'
[task 2019-12-06T10:17:51.748Z] 10:17:51 INFO - Pushing preferences
[task 2019-12-06T10:17:51.748Z] 10:17:51 INFO - Pushing permissions
[task 2019-12-06T10:17:51.749Z] 10:17:51 INFO - Clearing old databases
[task 2019-12-06T10:17:51.750Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Unsupported function type
[task 2019-12-06T10:17:51.750Z] 10:17:51 INFO - Running test in a worker
[task 2019-12-06T10:17:51.751Z] 10:17:51 INFO - Worker: loading ["http://mochi.test:8888/tests/dom/indexedDB/test/unit/test_readonly_transactions.js"]
[task 2019-12-06T10:17:51.751Z] 10:17:51 INFO - Worker: starting tests
[task 2019-12-06T10:17:51.751Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Unsupported function type: undefined
[task 2019-12-06T10:17:51.751Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Correct objectStoreNames list:
[task 2019-12-06T10:17:51.751Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Correct mode:
[task 2019-12-06T10:17:51.751Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Correct mode:
[task 2019-12-06T10:17:51.752Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Correct mode:
[task 2019-12-06T10:17:51.752Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Correct mode:
[task 2019-12-06T10:17:51.752Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Correct mode:
[task 2019-12-06T10:17:51.753Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Correct mode:
[task 2019-12-06T10:17:51.753Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Correct mode:
[task 2019-12-06T10:17:51.754Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Correct mode:
[task 2019-12-06T10:17:51.754Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Adding to a readonly transaction failed: undefined
[task 2019-12-06T10:17:51.754Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Adding to a readonly transaction failed: undefined
[task 2019-12-06T10:17:51.755Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Adding or modifying a readonly transaction failed: undefined
[task 2019-12-06T10:17:51.755Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Adding or modifying a readonly transaction failed: undefined
[task 2019-12-06T10:17:51.756Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Modifying a readonly transaction failed: undefined
[task 2019-12-06T10:17:51.756Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Modifying a readonly transaction failed: undefined
[task 2019-12-06T10:17:51.756Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Removing from a readonly transaction failed: undefined
[task 2019-12-06T10:17:51.757Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Removing from a readonly transaction failed: undefined
[task 2019-12-06T10:17:51.757Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Async/await tests shouldn't call finishTest(): undefined
[task 2019-12-06T10:17:51.758Z] 10:17:51 INFO - TEST-PASS | dom/indexedDB/test/test_readonly_transactions.html | Worker finished
[task 2019-12-06T10:17:51.758Z] 10:17:51 INFO - Cleaning up the databases
[task 2019-12-06T10:17:51.758Z] 10:17:51 INFO - Buffered messages finished
[task 2019-12-06T10:17:51.759Z] 10:17:51 INFO - TEST-UNEXPECTED-FAIL | dom/indexedDB/test/test_readonly_transactions.html | Test timed out.
[task 2019-12-06T10:17:51.759Z] 10:17:51 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2019-12-06T10:17:51.759Z] 10:17:51 INFO - reportError@SimpleTest/TestRunner.js:121:22
[task 2019-12-06T10:17:51.760Z] 10:17:51 INFO - TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:18
[task 2019-12-06T10:17:51.760Z] 10:17:51 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T10:17:51.760Z] 10:17:51 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T10:17:51.761Z] 10:17:51 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T10:17:51.761Z] 10:17:51 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T10:17:51.761Z] 10:17:51 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T10:17:51.762Z] 10:17:51 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T10:17:51.762Z] 10:17:51 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T10:17:51.762Z] 10:17:51 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T10:17:51.762Z] 10:17:51 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T10:17:51.762Z] 10:17:51 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T10:17:51.763Z] 10:17:51 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:170:15
[task 2019-12-06T10:17:51.763Z] 10:17:51 INFO - TestRunner.runTests/<@SimpleTest/TestRunner.js:388:20
[task 2019-12-06T10:17:51.763Z] 10:17:51 INFO - promise callback
TestRunner.runTests@SimpleTest/TestRunner.js:375:50
[task 2019-12-06T10:17:51.763Z] 10:17:51 INFO - RunSet.runtests@SimpleTest/setup.js:201:14
[task 2019-12-06T10:17:51.763Z] 10:17:51 INFO - RunSet.runall@SimpleTest/setup.js:180:12
[task 2019-12-06T10:17:51.764Z] 10:17:51 INFO - hookupTests@SimpleTest/setup.js:273:12
[task 2019-12-06T10:17:51.764Z] 10:17:51 INFO - parseTestManifest@http://mochi.test:8888/manifestLibrary.js:48:13
[task 2019-12-06T10:17:51.764Z] 10:17:51 INFO - getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:61:28
[task 2019-12-06T10:17:51.764Z] 10:17:51 INFO - EventHandlerNonNullgetTestManifest@http://mochi.test:8888/manifestLibrary.js:57:3
[task 2019-12-06T10:17:51.764Z] 10:17:51 INFO - hookup@SimpleTest/setup.js:253:20
[task 2019-12-06T10:17:51.765Z] 10:17:51 INFO - EventHandlerNonNull
@http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&manifestFile=tests.json&dumpOutputDirectory=%2Ftmp&cleanupCrashes=true:11:1
[task 2019-12-06T10:17:52.268Z] 10:17:52 INFO - GECKO(4321) | MEMORY STAT | vsize 2625MB | residentFast 118MB | heapAllocated 10MB
[task 2019-12-06T10:17:52.276Z] 10:17:52 INFO - TEST-OK | dom/indexedDB/test/test_readonly_transactions.html | took 306625ms

I have reproduced a hang on running this test case locally, but it seems to hang in a quite different way. I have two Pernosco traces:

However, here, the BAD run hangs already before actually running the test case. I tried to trace that down, and added some things to the notebook, but it got increasingly remote from anything related to IndexedDB, but I am not sure. It is again very annoying that there are plentiful uses of IndexedDB in the test harness, which may or may not relate to the issue.

The last activity common to both runs was [Parent 14881: Main Thread]: W/IndexedDB IndexedDB {962d6d91-a769-4fc6-97c7-d7e97220f97b}: Child Transaction[34]: Firing 'complete' event (an ActivityStream operation). The BAD run then goes on to close the idle IndexedDB connection a few minutes later. The BAD run is missing the whole loadURI call, but I wasn't able to figure out why.

Andrew, do you have an idea how to find out why this doesn't happen? Is it worthwhile that we look at that, or is there someone outside the team better suited to understand this?

Flags: needinfo?(bugmail)
Depends on: 1777914
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → DUPLICATE
Flags: needinfo?(bugmail)
You need to log in before you can comment on or make changes to this bug.