1605948 - Intermittent browser/extensions/doh-rollout/test/unit/test_localStorageMigration.js | application crashed [@ mozilla::dom::IDBTransaction::OnRequestFinished(bool)]

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

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

---

[task 2019-12-25T18:23:30.250Z] 18:23:30 INFO - TEST-START | devtools/client/memory/test/unit/test_utils-get-snapshot-totals.js
[task 2019-12-25T18:23:30.345Z] 18:23:30 INFO - mozcrash Saved minidump as Z:\task_1577297822\build\blobber_upload_dir\e427c315-f4e6-4c0b-822f-115c8393b07f.dmp
[task 2019-12-25T18:23:30.345Z] 18:23:30 WARNING - PROCESS-CRASH | browser/extensions/doh-rollout/test/unit/test_localStorageMigration.js | application crashed [@ mozilla::dom::IDBTransaction::OnRequestFinished(bool)]
[task 2019-12-25T18:23:30.345Z] 18:23:30 INFO - Crash dump filename: c:\users\task_1577297822\appdata\local\temp\xpc-other-a0zeqz\e427c315-f4e6-4c0b-822f-115c8393b07f.dmp
[task 2019-12-25T18:23:30.346Z] 18:23:30 INFO - Operating system: Windows NT
[task 2019-12-25T18:23:30.346Z] 18:23:30 INFO - 10.0.17134
[task 2019-12-25T18:23:30.346Z] 18:23:30 INFO - CPU: amd64
[task 2019-12-25T18:23:30.346Z] 18:23:30 INFO - family 6 model 85 stepping 4
[task 2019-12-25T18:23:30.346Z] 18:23:30 INFO - 8 CPUs
[task 2019-12-25T18:23:30.346Z] 18:23:30 INFO - GPU: UNKNOWN
[task 2019-12-25T18:23:30.346Z] 18:23:30 INFO - Crash reason: EXCEPTION_BREAKPOINT
[task 2019-12-25T18:23:30.347Z] 18:23:30 INFO - Crash address: 0x7ffd92f8a03b
[task 2019-12-25T18:23:30.347Z] 18:23:30 INFO - Assertion: Unknown assertion type 0x00000000
[task 2019-12-25T18:23:30.347Z] 18:23:30 INFO - Process uptime: 7 seconds
[task 2019-12-25T18:23:30.347Z] 18:23:30 INFO - Thread 0 (crashed)
[task 2019-12-25T18:23:30.348Z] 18:23:30 INFO - 0 xul.dll!mozilla::dom::IDBTransaction::OnRequestFinished(bool) [IDBTransaction.cpp:ca49196116bbeff33885ddb142d73c66a0b92da4 : 345 + 0x0]
[task 2019-12-25T18:23:30.348Z] 18:23:30 INFO - rax = 0x00007ffd97f464db rdx = 0x00007ffdcf04a640
[task 2019-12-25T18:23:30.348Z] 18:23:30 INFO - rcx = 0x00007ffdba4a8f08 rbx = 0x0000000097f43000
[task 2019-12-25T18:23:30.348Z] 18:23:30 INFO - rsi = 0x000001bf7388f3a0 rdi = 0x00000005fc1ff1c8
[task 2019-12-25T18:23:30.349Z] 18:23:30 INFO - rbp = 0x0000000000000000 rsp = 0x00000005fc1ff0a0
[task 2019-12-25T18:23:30.349Z] 18:23:30 INFO - r8 = 0x00000005fc1f91f8 r9 = 0x00000005fc1fa810
[task 2019-12-25T18:23:30.349Z] 18:23:30 INFO - r10 = 0x0000000000000000 r11 = 0x00000005fc1fa720
[task 2019-12-25T18:23:30.349Z] 18:23:30 INFO - r12 = 0x000001bf73867da8 r13 = 0x0000000000000000
[task 2019-12-25T18:23:30.349Z] 18:23:30 INFO - r14 = 0x0000000000000003 r15 = 0x000001bf73867d70
[task 2019-12-25T18:23:30.349Z] 18:23:30 INFO - rip = 0x00007ffd92f8a03b
[task 2019-12-25T18:23:30.350Z] 18:23:30 INFO - Found by: given as instruction pointer in context
[task 2019-12-25T18:23:30.350Z] 18:23:30 INFO - 1 xul.dll!mozilla::dom::indexedDB::BackgroundRequestChild::ActorDestroy(mozilla::ipc::IProtocol::ActorDestroyReason) [ActorsChild.cpp:ca49196116bbeff33885ddb142d73c66a0b92da4 : 2816 + 0xc]
[task 2019-12-25T18:23:30.350Z] 18:23:30 INFO - rbx = 0x0000000097f43000 rbp = 0x0000000000000000
[task 2019-12-25T18:23:30.350Z] 18:23:30 INFO - rsp = 0x00000005fc1ff130 r12 = 0x000001bf73867da8
[task 2019-12-25T18:23:30.350Z] 18:23:30 INFO - r13 = 0x0000000000000000 r14 = 0x0000000000000003
[task 2019-12-25T18:23:30.350Z] 18:23:30 INFO - r15 = 0x000001bf73867d70 rip = 0x00007ffd92f89caf
[task 2019-12-25T18:23:30.351Z] 18:23:30 INFO - Found by: call frame info
[task 2019-12-25T18:23:30.351Z] 18:23:30 INFO - 2 xul.dll!mozilla::ipc::IProtocol::DestroySubtree(mozilla::ipc::IProtocol::ActorDestroyReason) [ProtocolUtils.cpp:ca49196116bbeff33885ddb142d73c66a0b92da4 : 572 + 0xc]
[task 2019-12-25T18:23:30.351Z] 18:23:30 INFO - rbx = 0x0000000097f43000 rbp = 0x0000000000000000
[task 2019-12-25T18:23:30.351Z] 18:23:30 INFO - rsp = 0x00000005fc1ff1a0 r12 = 0x000001bf73867da8
[task 2019-12-25T18:23:30.351Z] 18:23:30 INFO - r13 = 0x0000000000000000 r14 = 0x0000000000000003
[task 2019-12-25T18:23:30.351Z] 18:23:30 INFO - r15 = 0x000001bf73867d70 rip = 0x00007ffd8fac68ff
[task 2019-12-25T18:23:30.351Z] 18:23:30 INFO - Found by: call frame info
[task 2019-12-25T18:23:30.351Z] 18:23:30 INFO - 3 xul.dll!mozilla::ipc::IProtocol::DestroySubtree(mozilla::ipc::IProtocol::ActorDestroyReason) [ProtocolUtils.cpp:ca49196116bbeff33885ddb142d73c66a0b92da4 : 560 + 0x7]
[task 2019-12-25T18:23:30.351Z] 18:23:30 INFO - rbx = 0x0000000097f43000 rbp = 0x0000000000000000

Comment 1

[Intermittent Failures Robot]

1 failures in 1365 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1605948&startday=2019-12-23&endday=2019-12-29&tree=all

Comment 2

[Andrew Sutherland [:asuth] (he/him)]

It looks like what is happening here is that the loss of the IPC channel is tearing down the tree, which means that the call to OnRequestFinished is happening with an unexpected readystate which makes the assertion sad.

This is an unusual situation because:

• This is a shutdown of PBackground in a child process. This only happens in debug builds (the process self-terminates in opt builds and PBackground never gets shutdown in the child.)
• Normally we'd expect the global to be torn down and for that to cleanup the IDB objects. But this is an xpcshell test, so the normal globals under test won't experience such a shutdown.

Marking this as P3 for now because this isn't something we expect at runtime, but there's a good chance that we'll see a number of intermittents spread across different tests, so we will want to resolve this.

Comment 3

[Intermittent Failures Robot]

1 failures in 1862 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• windows7-32: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1605948&startday=2019-12-30&endday=2020-01-05&tree=all

Comment 4

[Simon Giesecke [:sg] [he/him]]

I have been trying to reproduce this under Linux locally, with rr in chaos mode, but had no success so far. There have been only two intermittent failures so far, both of which are under Windows, but I can't really see that this should be platform-specific. I agree this would be great to fix to avoid random test failures, but without being able to reproduce it and to know in which state we are, I can't do anything specific about it in a meaningful way. Just changing the assertion to a no-op in case the condition is true does not seem to be the right thing to do. The dump unfortunately doesn't contain sufficient information resp. I am missing the debug symbols.

Comment 5

[(inactive) Nihanth Subramanya [:nhnt11]]

The DoH heuristics code was ported into a JS component, and several mechanics reworked. The tests live in a new directory and have all been re-enabled, and I'd like to track any new intermittents in new bugs. Closing all open intermittent test failure bugs associated with the old extension.