1573341 - Intermittent Last test finished | application crashed [@ mozilla::dom::indexedDB::(anonymous namespace)::QuotaClient::ShutdownTimedOut()]

Status: RESOLVED INCOMPLETE

(Core :: Storage: Quota Manager, defect, P3)

Description

[Treeherder Bug Filer]

Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=261211407&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/Fdct7fmxQ3igBjmgqdq1DQ/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/Fdct7fmxQ3igBjmgqdq1DQ/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

---

[task 2019-08-12T23:40:17.419Z] 23:40:17 INFO - REFTEST TEST-START | file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/css-transitions/style-change-during-transition.html == file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/css-transitions/style-change-during-transition-ref.html
[task 2019-08-12T23:40:17.420Z] 23:40:17 INFO - REFTEST TEST-LOAD | file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/css-transitions/style-change-during-transition.html | 11 / 12 (91%)
[task 2019-08-12T23:40:17.946Z] 23:40:17 INFO - REFTEST TEST-LOAD | file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/css-transitions/style-change-during-transition-ref.html | 11 / 12 (91%)
[task 2019-08-12T23:40:18.007Z] 23:40:18 INFO - REFTEST TEST-PASS | file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/css-transitions/style-change-during-transition.html == file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/css-transitions/style-change-during-transition-ref.html | image comparison, max difference: 0, number of differing pixels: 0
[task 2019-08-12T23:40:18.008Z] 23:40:18 INFO - REFTEST TEST-END | file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/css-transitions/style-change-during-transition.html == file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/css-transitions/style-change-during-transition-ref.html
[task 2019-08-12T23:40:18.015Z] 23:40:18 INFO - REFTEST INFO | Slowest test took 698ms (file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/css-transitions/stacking-context-transform-wins-over-important-style.html)
[task 2019-08-12T23:40:18.015Z] 23:40:18 INFO - REFTEST INFO | Total canvas count = 2
[task 2019-08-12T23:40:18.015Z] 23:40:18 INFO - JavaScript error: resource://activity-stream/lib/ActivityStreamPrefs.jsm, line 27: NS_ERROR_ILLEGAL_VALUE: Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIPrefBranch.removeObserver]
[task 2019-08-12T23:40:18.076Z] 23:40:18 INFO - JavaScript error: resource://services-settings/RemoteSettingsClient.jsm, line 149: Error: Unknown callback
[task 2019-08-12T23:40:29.777Z] 23:40:29 INFO - JavaScript error: resource://services-common/kinto-offline-client.js, line 579: Error: IndexedDB getLastModified() A request was aborted, for example through a call to IDBTransaction.abort.
[task 2019-08-12T23:41:15.408Z] 23:41:15 INFO - JavaScript error: resource://services-common/kinto-offline-client.js, line 579: Error: IndexedDB getLastModified() The operation failed for reasons unrelated to the database itself and not covered by any other error code.
[task 2019-08-12T23:41:18.655Z] 23:41:18 INFO - ExceptionHandler::GenerateDump cloned child 3210
[task 2019-08-12T23:41:18.655Z] 23:41:18 INFO - ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2019-08-12T23:41:18.656Z] 23:41:18 INFO - ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2019-08-12T23:41:20.108Z] 23:41:20 ERROR - TEST-UNEXPECTED-FAIL | Last test finished | application terminated with exit code 11
[task 2019-08-12T23:41:20.108Z] 23:41:20 INFO - REFTEST INFO | Downloading symbols from: https://queue.taskcluster.net/v1/task/UpYOcKzxRD-J-eQ1fDq8NA/artifacts/public/build/target.crashreporter-symbols.zip
[task 2019-08-12T23:41:23.028Z] 23:41:23 INFO - REFTEST INFO | Copy/paste: /builds/worker/workspace/build/linux64-minidump_stackwalk /tmp/tmpmlwlq0.mozrunner/minidumps/6b3f98e4-9073-f65a-a25c-3b442f5e840a.dmp /tmp/tmpA28MjN
[task 2019-08-12T23:41:27.280Z] 23:41:27 INFO - REFTEST INFO | Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/6b3f98e4-9073-f65a-a25c-3b442f5e840a.dmp
[task 2019-08-12T23:41:27.281Z] 23:41:27 INFO - REFTEST INFO | Saved app info as /builds/worker/workspace/build/blobber_upload_dir/6b3f98e4-9073-f65a-a25c-3b442f5e840a.extra
[task 2019-08-12T23:41:27.369Z] 23:41:27 INFO - REFTEST PROCESS-CRASH | Last test finished | application crashed [@ mozilla::dom::indexedDB::(anonymous namespace)::QuotaClient::ShutdownTimedOut()]
[task 2019-08-12T23:41:27.369Z] 23:41:27 INFO - Crash dump filename: /tmp/tmpmlwlq0.mozrunner/minidumps/6b3f98e4-9073-f65a-a25c-3b442f5e840a.dmp
[task 2019-08-12T23:41:27.369Z] 23:41:27 INFO - Operating system: Linux
[task 2019-08-12T23:41:27.369Z] 23:41:27 INFO - 0.0.0 Linux 4.4.0-1014-aws #14taskcluster1-Ubuntu SMP Tue Apr 3 10:27:00 UTC 2018 x86_64
[task 2019-08-12T23:41:27.369Z] 23:41:27 INFO - CPU: amd64
[task 2019-08-12T23:41:27.369Z] 23:41:27 INFO - family 6 model 85 stepping 4
[task 2019-08-12T23:41:27.369Z] 23:41:27 INFO - 1 CPU
[task 2019-08-12T23:41:27.369Z] 23:41:27 INFO -
[task 2019-08-12T23:41:27.369Z] 23:41:27 INFO - GPU: UNKNOWN
[task 2019-08-12T23:41:27.369Z] 23:41:27 INFO -
[task 2019-08-12T23:41:27.369Z] 23:41:27 INFO - Crash reason: SIGSEGV /SEGV_MAPERR
[task 2019-08-12T23:41:27.369Z] 23:41:27 INFO - Crash address: 0x0
[task 2019-08-12T23:41:27.370Z] 23:41:27 INFO - Process uptime: not available
[task 2019-08-12T23:41:27.370Z] 23:41:27 INFO -
[task 2019-08-12T23:41:27.370Z] 23:41:27 INFO - Thread 12 (crashed)
[task 2019-08-12T23:41:27.370Z] 23:41:27 INFO - 0 libxul.so!mozilla::dom::indexedDB::(anonymous namespace)::QuotaClient::ShutdownTimedOut() [ActorsParent.cpp:1ca06cd3e226f80adf2b1b8837ed9a475fa90baa : 16359 + 0x11]
[task 2019-08-12T23:41:27.370Z] 23:41:27 INFO - rax = 0x00007faf37526afc rdx = 0x00007faf427b0430
[task 2019-08-12T23:41:27.370Z] 23:41:27 INFO - rcx = 0x00005600a12e4c40 rbx = 0x0000000000000000
[task 2019-08-12T23:41:27.370Z] 23:41:27 INFO - rsi = 0x0000000000000000 rdi = 0x00007faf1737bd8c
[task 2019-08-12T23:41:27.370Z] 23:41:27 INFO - rbp = 0x00007faf298fca20 rsp = 0x00007faf298fc900
[task 2019-08-12T23:41:27.370Z] 23:41:27 INFO - r8 = 0x0000000000000000 r9 = 0x0000000000000000
[task 2019-08-12T23:41:27.370Z] 23:41:27 INFO - r10 = 0x0000000000000034 r11 = 0x0000000000000035
[task 2019-08-12T23:41:27.371Z] 23:41:27 INFO - r12 = 0x00007faf298fc9d8 r13 = 0x00007faf1cd39400
[task 2019-08-12T23:41:27.371Z] 23:41:27 INFO - r14 = 0x00007faf36761c2f r15 = 0x00007faf298fc9b0
[task 2019-08-12T23:41:27.371Z] 23:41:27 INFO - rip = 0x00007faf34023fd3
[task 2019-08-12T23:41:27.371Z] 23:41:27 INFO - Found by: given as instruction pointer in context
[task 2019-08-12T23:41:27.371Z] 23:41:27 INFO - 1 libxul.so!mozilla::dom::indexedDB::(anonymous namespace)::QuotaClient::ShutdownWorkThreads()::$_3::operator()(nsITimer*, void*) const [ActorsParent.cpp:1ca06cd3e226f80adf2b1b8837ed9a475fa90baa : 16250 + 0x9]
[task 2019-08-12T23:41:27.371Z] 23:41:27 INFO - rbx = 0x0000000000000001 rbp = 0x00007faf298fca30
[task 2019-08-12T23:41:27.371Z] 23:41:27 INFO - rsp = 0x00007faf298fca30 r12 = 0x00002ad2559d4814
[task 2019-08-12T23:41:27.371Z] 23:41:27 INFO - r13 = 0x00007faf1730adc0 r14 = 0x00007faf1730adf8
[task 2019-08-12T23:41:27.371Z] 23:41:27 INFO - r15 = 0x7fffffffffffffff rip = 0x00007faf34023a69
[task 2019-08-12T23:41:27.371Z] 23:41:27 INFO - Found by: call frame info
[task 2019-08-12T23:41:27.371Z] 23:41:27 INFO - 2 libxul.so!mozilla::dom::indexedDB::(anonymous namespace)::QuotaClient::ShutdownWorkThreads()::$_3::__invoke(nsITimer*, void*) [ActorsParent.cpp:1ca06cd3e226f80adf2b1b8837ed9a475fa90baa : 16250 + 0xc]
[task 2019-08-12T23:41:27.372Z] 23:41:27 INFO - rbx = 0x0000000000000001 rbp = 0x00007faf298fca40
[task 2019-08-12T23:41:27.372Z] 23:41:27 INFO - rsp = 0x00007faf298fca40 r12 = 0x00002ad2559d4814
[task 2019-08-12T23:41:27.372Z] 23:41:27 INFO - r13 = 0x00007faf1730adc0 r14 = 0x00007faf1730adf8
[task 2019-08-12T23:41:27.372Z] 23:41:27 INFO - r15 = 0x7fffffffffffffff rip = 0x00007faf34023a5c
[task 2019-08-12T23:41:27.372Z] 23:41:27 INFO - Found by: call frame info
[task 2019-08-12T23:41:27.372Z] 23:41:27 INFO - 3 libxul.so!nsTimerImpl::Fire(int) [nsTimerImpl.cpp:1ca06cd3e226f80adf2b1b8837ed9a475fa90baa : 561 + 0xb]

Comment 1

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

The errors in the log are consistent with kinto.js' use of IndexedDB not handling transaction aborts, although it's not immediately obvious how this is translating into a QuotaManager failure. IndexedDB.jsm recently had a similar logic problem fixed in bug 1542181 in patch https://phabricator.services.mozilla.com/D36822 and I've filed https://github.com/Kinto/kinto.js/issues/1043 on having kinto.js port that patch.

For now, I think it makes sense to keep an eye on this intermittent and revisit when the kinto.js fix has landed in tree.

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• linux64-qr: 1

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

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• try: 1

Platform breakdown:

• linux64-qr: 1

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

Comment 4

[Intermittent Failures Robot]

240 failures in 1095 pushes (0.219 failures/push) were associated with this bug yesterday.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• try: 240

Platform breakdown:

• gecko-decision: 2
• lint: 9
• linux64: 1
• linux1804-64: 125
• linux1804-64-qr: 103

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1573341&startday=2020-03-03&endday=2020-03-03&tree=all

Comment 5

[Cosmin Sabou [:CosminS]]

(In reply to Intermittent Failures Robot from comment #4)

240 failures in 1095 pushes (0.219 failures/push) were associated with this bug yesterday.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• try: 240

Platform breakdown:

• gecko-decision: 2
• lint: 9
• linux64: 1
• linux1804-64: 125
• linux1804-64-qr: 103

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1573341&startday=2020-03-03&endday=2020-03-03&tree=all

These were all on try on the same push that looks to be a mass classification: https://treeherder.mozilla.org/#/jobs?repo=try&selectedJob=291400533&revision=09feaea62b803a0724c835cd97a3198919cbc6a1

Comment 6

[Intermittent Failures Robot]

240 failures in 5483 pushes (0.044 failures/push) were associated with this bug in the last 7 days.

This is the #3 most frequent failure this week.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• try: 240

Platform breakdown:

• gecko-decision: 2
• lint: 9
• linux64: 1
• linux1804-64: 125
• linux1804-64-qr: 103

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1573341&startday=2020-03-02&endday=2020-03-08&tree=all

Comment 7

[Narcis Beleuzu [:NarcisB]]

Removed the [stockwell disable-recommended] due to Comment 5

Comment 8

[Jens Stutte [:jstutte]]

QuotaManager related shutdown issues moved to bug 1588498.