Closed Bug 1415911 Opened 7 years ago Closed 4 years ago

Intermittent browser/components/migration/tests/unit/test_MigrationUtils_timedRetry.js | testgetRowsFromDBWithoutLocksRetries - [testgetRowsFromDBWithoutLocksRetries : 253] A promise chain failed to handle a rejection: Error(s) encountered during statemen

Categories

(Firefox :: Migration, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Assigned: alexical)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

This test got added in bug 1413989. Doug, please investigate the issue. Thank you in advance.
Flags: needinfo?(dothayer)
Assignee: nobody → dothayer
Status: NEW → ASSIGNED
Flags: needinfo?(dothayer)
Comment on attachment 8934322 [details]
Bug 1415911 - Fix intermittent test_MigrationUtils_timedRetry failure

https://reviewboard.mozilla.org/r/205248/#review211068

I'm pretty confused by this. Because:

https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-beta&job_id=147790347&lineNumber=2625

```
[task 2017-11-27T11:04:16.017Z] 11:04:16     INFO -  browser/components/migration/tests/unit/test_MigrationUtils_timedRetry.js | Starting testgetRowsFromDBWithoutLocksRetries
[task 2017-11-27T11:04:16.018Z] 11:04:16     INFO -  (xpcshell/head.js) | test testgetRowsFromDBWithoutLocksRetries pending (2)
[task 2017-11-27T11:04:16.018Z] 11:04:16     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2017-11-27T11:04:16.019Z] 11:04:16     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "Error(s) encountered during statement execution: no such table: moz_temp_table" {file: "resource://gre/modules/Sqlite.jsm" line: 810}]
[task 2017-11-27T11:04:16.020Z] 11:04:16     INFO -  handleCompletion@resource://gre/modules/Sqlite.jsm:810:25
[task 2017-11-27T11:04:16.021Z] 11:04:16     INFO -  _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:221:3
[task 2017-11-27T11:04:16.021Z] 11:04:16     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:543:5
[task 2017-11-27T11:04:16.022Z] 11:04:16     INFO -  @-e:1:1
[task 2017-11-27T11:04:16.023Z] 11:04:16     INFO -  "
[task 2017-11-27T11:04:16.023Z] 11:04:16     INFO -  (xpcshell/head.js) | test run_next_test 2 pending (2)
[task 2017-11-27T11:04:16.024Z] 11:04:16     INFO -  (xpcshell/head.js) | test testgetRowsFromDBWithoutLocksRetries finished (2)
[task 2017-11-27T11:04:16.025Z] 11:04:16     INFO -  PID 9245 | JavaScript error: resource://gre/modules/Sqlite.jsm, line 810: Error: Error(s) encountered during statement execution: disk I/O error
[task 2017-11-27T11:04:16.025Z] 11:04:16     INFO -  (xpcshell/head.js) | test run_next_test 2 finished (1)
[task 2017-11-27T11:04:16.026Z] 11:04:16     INFO -  exiting test
[task 2017-11-27T11:04:16.027Z] 11:04:16     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "Error: Error(s) encountered during statement execution: disk I/O error" {file: "resource://gre/modules/Sqlite.jsm" line: 810}]"
[task 2017-11-27T11:04:16.028Z] 11:04:16  WARNING -  TEST-UNEXPECTED-FAIL | browser/components/migration/tests/unit/test_MigrationUtils_timedRetry.js | testgetRowsFromDBWithoutLocksRetries - [testgetRowsFromDBWithoutLocksRetries : 253] A promise chain failed to handle a rejection: Error(s) encountered during statement execution: disk I/O error - stack: null
[task 2017-11-27T11:04:16.029Z] 11:04:16     INFO -  Rejection date: Mon Nov 27 2017 11:04:15 GMT+0000 (UTC) - false == true
[task 2017-11-27T11:04:16.029Z] 11:04:16     INFO -  resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:253
[task 2017-11-27T11:04:16.030Z] 11:04:16     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:544
[task 2017-11-27T11:04:16.031Z] 11:04:16     INFO -  -e:null:1
[task 2017-11-27T11:04:16.031Z] 11:04:16     INFO -  exiting test
[task 2017-11-27T11:04:16.032Z] 11:04:16     INFO -  <<<<<<<
```

The stack for both the first and second error is actually from running the test, given that in https://dxr.mozilla.org/mozilla-central/rev/5be384bcf00191f97d32b4ac3ecd1b85ec7b18e1/testing/xpcshell/head.js#534-552 we're running the main tests. The cleanup functions don't get run until later (lines 580-ish and later).

So I'm confused about how this would fix the failure. As in, I understand the hypothesis this patch is built on is that the OS.File.remove() call runs before we stop trying to access/close the db -- but I don't see how that would produce the stacks above. Then again, I don't see much better hypotheses...

::: browser/components/migration/tests/unit/test_MigrationUtils_timedRetry.js:14
(Diff revision 1)
>  add_task(async function setup() {
>    tmpFile.append("TestDB");
>    dbConn = await Sqlite.openConnection({ path: tmpFile.path });
>  
> -  do_register_cleanup(() => {
> -    dbConn.close();
> +  do_register_cleanup(async () => {
> +    await dbConn.close();

Note that the error complains about a promise rejecting and not being caught, and this `await` statement would make the cleanup function reject if `dbConn.close()` rejected, which presumably would trigger the same issue? If there was an error here that shouldn't cause the test to fail, we'd need to use `.catch()` or a try...catch block to catch it.

::: browser/components/migration/tests/unit/test_MigrationUtils_timedRetry.js:15
(Diff revision 1)
>    tmpFile.append("TestDB");
>    dbConn = await Sqlite.openConnection({ path: tmpFile.path });
>  
> -  do_register_cleanup(() => {
> -    dbConn.close();
> +  do_register_cleanup(async () => {
> +    await dbConn.close();
>      OS.File.remove(tmpFile.path);

Should we await the File.remove() as well?
Attachment #8934322 - Flags: review?(gijskruitbosch+bugs) → review+
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: