Intermittent TEST-UNEXPECTED-TIMEOUT | devtools/client/storage/test/browser_storage_fission_indexeddb.js | application timed out after 370 seconds with no output
Categories
(DevTools :: Storage Inspector, defect, P5)
Tracking
(firefox-esr78 unaffected, firefox-esr91 disabled, firefox88 unaffected, firefox89 unaffected, firefox90 disabled, firefox91 disabled, firefox92 disabled, firefox93 fixed)
Tracking | Status | |
---|---|---|
firefox-esr78 | --- | unaffected |
firefox-esr91 | --- | disabled |
firefox88 | --- | unaffected |
firefox89 | --- | unaffected |
firefox90 | --- | disabled |
firefox91 | --- | disabled |
firefox92 | --- | disabled |
firefox93 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: ladybenko)
References
(Regression)
Details
(Keywords: intermittent-failure, regression, Whiteboard: [stockwell needswork:owner])
Attachments
(1 file)
(deleted),
text/x-phabricator-request
|
Details |
Filed by: nerli [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=337173856&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZaLVOhINQTO5oSTmkiqslg/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://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZaLVOhINQTO5oSTmkiqslg/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1
[task 2021-04-20T16:09:44.542Z] 16:09:44 ERROR - TEST-UNEXPECTED-TIMEOUT | devtools/client/storage/test/browser_storage_fission_indexeddb.js | application timed out after 370 seconds with no output
[task 2021-04-20T16:09:44.542Z] 16:09:44 ERROR - Force-terminating active process(es).
[task 2021-04-20T16:09:44.542Z] 16:09:44 INFO - Determining child pids from psutil...
[task 2021-04-20T16:09:44.542Z] 16:09:44 INFO - [1478, 1470, 1471, 1479]
[task 2021-04-20T16:09:44.542Z] 16:09:44 INFO - ==> process 1469 launched child process 1470
[task 2021-04-20T16:09:44.543Z] 16:09:44 INFO - ==> process 1469 launched child process 1471
[task 2021-04-20T16:09:44.543Z] 16:09:44 INFO - ==> process 1469 launched child process 1478
[task 2021-04-20T16:09:44.543Z] 16:09:44 INFO - ==> process 1469 launched child process 1479
[task 2021-04-20T16:09:44.543Z] 16:09:44 INFO - Found child pids: set([1479, 1470, 1478, 1471])
[task 2021-04-20T16:09:44.543Z] 16:09:44 INFO - Killing process: 1479
[task 2021-04-20T16:09:44.543Z] 16:09:44 INFO - TEST-INFO | started process screencapture
[task 2021-04-20T16:09:44.648Z] 16:09:44 INFO - TEST-INFO | screencapture: exit 0
[task 2021-04-20T16:09:44.648Z] 16:09:44 INFO - Killing process: 1470
[task 2021-04-20T16:09:44.648Z] 16:09:44 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-20T16:09:44.649Z] 16:09:44 INFO - Killing process: 1478
[task 2021-04-20T16:09:44.649Z] 16:09:44 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-20T16:09:44.649Z] 16:09:44 INFO - Killing process: 1471
[task 2021-04-20T16:09:44.649Z] 16:09:44 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-20T16:09:46.541Z] 16:09:46 INFO - psutil found pid 1478 dead
[task 2021-04-20T16:09:46.541Z] 16:09:46 INFO - psutil found pid 1479 dead
[task 2021-04-20T16:09:46.541Z] 16:09:46 INFO - psutil found pid 1471 dead
[task 2021-04-20T16:09:46.542Z] 16:09:46 INFO - psutil found pid 1470 dead
[task 2021-04-20T16:09:46.542Z] 16:09:46 INFO - Killing process: 1469
[task 2021-04-20T16:09:46.542Z] 16:09:46 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-20T16:09:46.656Z] 16:09:46 INFO - psutil found pid 1469 dead
[task 2021-04-20T16:09:46.687Z] 16:09:46 WARNING - runtests.py | Failed to get app exit code - running/crashed?
[task 2021-04-20T16:09:46.687Z] 16:09:46 INFO - TEST-INFO | Main app process: exit 0
[task 2021-04-20T16:09:46.687Z] 16:09:46 INFO - runtests.py | Application ran for: 0:07:57.377873
[task 2021-04-20T16:09:46.687Z] 16:09:46 INFO - zombiecheck | Reading PID log: /var/folders/hy/4prvwgbx2cs7jfv1cdf10p_m000017/T/tmp_djPsXpidlog
[task 2021-04-20T16:09:46.688Z] 16:09:46 INFO - ==> process 1469 launched child process 1470
[task 2021-04-20T16:09:46.688Z] 16:09:46 INFO - ==> process 1469 launched child process 1471
[task 2021-04-20T16:09:46.688Z] 16:09:46 INFO - ==> process 1469 launched child process 1478
[task 2021-04-20T16:09:46.688Z] 16:09:46 INFO - ==> process 1469 launched child process 1479
[task 2021-04-20T16:09:46.689Z] 16:09:46 INFO - ==> process 1469 launched child process 1541
[task 2021-04-20T16:09:46.689Z] 16:09:46 INFO - ==> process 1469 launched child process 1545
[task 2021-04-20T16:09:46.689Z] 16:09:46 INFO - zombiecheck | Checking for orphan process with PID: 1541
[task 2021-04-20T16:09:46.689Z] 16:09:46 INFO - zombiecheck | Checking for orphan process with PID: 1478
[task 2021-04-20T16:09:46.689Z] 16:09:46 INFO - zombiecheck | Checking for orphan process with PID: 1479
[task 2021-04-20T16:09:46.689Z] 16:09:46 INFO - zombiecheck | Checking for orphan process with PID: 1545
[task 2021-04-20T16:09:46.690Z] 16:09:46 INFO - zombiecheck | Checking for orphan process with PID: 1470
[task 2021-04-20T16:09:46.690Z] 16:09:46 INFO - zombiecheck | Checking for orphan process with PID: 1471
[task 2021-04-20T16:09:46.690Z] 16:09:46 INFO - mozcrash Downloading symbols from: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/NssaDOM9RKGenRBFWDs7VA/artifacts/public/build/target.crashreporter-symbols.zip
[task 2021-04-20T16:09:49.111Z] 16:09:49 INFO - mozcrash Copy/paste: /Users/cltbld/tasks/task_1618934222/fetches/minidump_stackwalk/minidump_stackwalk /var/folders/hy/4prvwgbx2cs7jfv1cdf10p_m000017/T/tmp9HQlB8.mozrunner/minidumps/FD03A9AF-84C7-4228-A537-202D69F32D84.dmp /var/folders/hy/4prvwgbx2cs7jfv1cdf10p_m000017/T/tmprW6sgp
[task 2021-04-20T16:09:52.466Z] 16:09:52 INFO - mozcrash Saved minidump as /Users/cltbld/tasks/task_1618934222/build/blobber_upload_dir/FD03A9AF-84C7-4228-A537-202D69F32D84.dmp
[task 2021-04-20T16:09:52.467Z] 16:09:52 INFO - mozcrash Saved app info as /Users/cltbld/tasks/task_1618934222/build/blobber_upload_dir/FD03A9AF-84C7-4228-A537-202D69F32D84.extra
[task 2021-04-20T16:09:52.532Z] 16:09:52 INFO - PROCESS-CRASH | Main app process exited normally | application crashed [@ mach_msg_trap + 0xa]
[task 2021-04-20T16:09:52.532Z] 16:09:52 INFO - Crash dump filename: /var/folders/hy/4prvwgbx2cs7jfv1cdf10p_m000017/T/tmp9HQlB8.mozrunner/minidumps/FD03A9AF-84C7-4228-A537-202D69F32D84.dmp
[task 2021-04-20T16:09:52.532Z] 16:09:52 INFO - Operating system: Mac OS X
[task 2021-04-20T16:09:52.532Z] 16:09:52 INFO - 10.14.5 18F132
[task 2021-04-20T16:09:52.532Z] 16:09:52 INFO - CPU: amd64
[task 2021-04-20T16:09:52.532Z] 16:09:52 INFO - family 6 model 69 stepping 1
[task 2021-04-20T16:09:52.532Z] 16:09:52 INFO - 4 CPUs
[task 2021-04-20T16:09:52.532Z] 16:09:52 INFO -
[task 2021-04-20T16:09:52.532Z] 16:09:52 INFO - GPU: UNKNOWN
[task 2021-04-20T16:09:52.532Z] 16:09:52 INFO -
[task 2021-04-20T16:09:52.532Z] 16:09:52 INFO - Crash reason: EXC_SOFTWARE / SIGABRT
[task 2021-04-20T16:09:52.533Z] 16:09:52 INFO - Crash address: 0x7fff6817922a
[task 2021-04-20T16:09:52.533Z] 16:09:52 INFO - Process uptime: 475 seconds
[task 2021-04-20T16:09:52.533Z] 16:09:52 INFO -
[task 2021-04-20T16:09:52.533Z] 16:09:52 INFO - Thread 0 (crashed)
[task 2021-04-20T16:09:52.533Z] 16:09:52 INFO - 0 libsystem_kernel.dylib!mach_msg_trap + 0xa
[task 2021-04-20T16:09:52.533Z] 16:09:52 INFO - rax = 0x000000000100001f rdx = 0x0000000000000000
[task 2021-04-20T16:09:52.533Z] 16:09:52 INFO - rcx = 0x00007ffeecbdd138 rbx = 0x0000000000000102
[task 2021-04-20T16:09:52.533Z] 16:09:52 INFO - rsi = 0x0000000000000102 rdi = 0x00007ffeecbdd1f0
[task 2021-04-20T16:09:52.533Z] 16:09:52 INFO - rbp = 0x00007ffeecbdd190 rsp = 0x00007ffeecbdd138
[task 2021-04-20T16:09:52.533Z] 16:09:52 INFO - r8 = 0x0000000000003817 r9 = 0x0000000000001388
[task 2021-04-20T16:09:52.533Z] 16:09:52 INFO - r10 = 0x000000000000041c r11 = 0x0000000000000202
[task 2021-04-20T16:09:52.533Z] 16:09:52 INFO - r12 = 0x0000000000000102 r13 = 0x000000000000041c
[task 2021-04-20T16:09:52.533Z] 16:09:52 INFO - r14 = 0x00007ffeecbdd1f0 r15 = 0x0000000000000000
[task 2021-04-20T16:09:52.534Z] 16:09:52 INFO - rip = 0x00007fff6817922a
[task 2021-04-20T16:09:52.534Z] 16:09:52 INFO - Found by: given as instruction pointer in context
[task 2021-04-20T16:09:52.534Z] 16:09:52 INFO - 1 XUL!google_breakpad::ReceivePort::WaitForMessage(google_breakpad::MachReceiveMessage*, unsigned int) [MachIPC.mm:64467b7c9c64938cca9fd14b756520226ae67119 : 249 + 0x18]
[task 2021-04-20T16:09:52.534Z] 16:09:52 INFO - rbp = 0x00007ffeecbdd1b0 rsp = 0x00007ffeecbdd1a0
[task 2021-04-20T16:09:52.534Z] 16:09:52 INFO - rip = 0x0000000107ee39ea
[task 2021-04-20T16:09:52.534Z] 16:09:52 INFO - Found by: previous frame's frame pointer
[task 2021-04-20T16:09:52.534Z] 16:09:52 INFO - 2 XUL!google_breakpad::CrashGenerationClient::RequestDumpForException(int, int, int, unsigned int, unsigned int) [crash_generation_client.cc:64467b7c9c64938cca9fd14b756520226ae67119 : 70 + 0xd]
[task 2021-04-20T16:09:52.534Z] 16:09:52 INFO - rbp = 0x00007ffeecbdda60 rsp = 0x00007ffeecbdd1c0
[task 2021-04-20T16:09:52.534Z] 16:09:52 INFO - rip = 0x0000000107ed9772
[task 2021-04-20T16:09:52.534Z] 16:09:52 INFO - Found by: previous frame's frame pointer
[task 2021-04-20T16:09:52.534Z] 16:09:52 INFO - 3 XUL!google_breakpad::ExceptionHandler::WriteMinidumpWithException(int, int, int, __darwin_ucontext*, unsigned int, unsigned int, bool, bool) [exception_handler.cc:64467b7c9c64938cca9fd14b756520226ae67119 : 403 + 0x1c]
[task 2021-04-20T16:09:52.534Z] 16:09:52 INFO - rbp = 0x00007ffeecbddb50 rsp = 0x00007ffeecbdda70
[task 2021-04-20T16:09:52.534Z] 16:09:52 INFO - rip = 0x0000000107edc5da
[task 2021-04-20T16:09:52.535Z] 16:09:52 INFO - Found by: previous frame's frame pointer
[task 2021-04-20T16:09:52.535Z] 16:09:52 INFO - 4 XUL!google_breakpad::ExceptionHandler::SignalHandler(int, __siginfo*, void*) [exception_handler.cc:64467b7c9c64938cca9fd14b756520226ae67119 : 658 + 0x27]
[task 2021-04-20T16:09:52.535Z] 16:09:52 INFO - rbp = 0x00007ffeecbddb90 rsp = 0x00007ffeecbddb60
[task 2021-04-20T16:09:52.535Z] 16:09:52 INFO - rip = 0x0000000107edcd47
[task 2021-04-20T16:09:52.535Z] 16:09:52 INFO - Found by: previous frame's frame pointer
[task 2021-04-20T16:09:52.535Z] 16:09:52 INFO - 5 libsystem_platform.dylib!_sigtramp + 0x1d
[task 2021-04-20T16:09:52.535Z] 16:09:52 INFO - rbp = 0x00007ffeecbddba0 rsp = 0x00007ffeecbddba0
[task 2021-04-20T16:09:52.535Z] 16:09:52 INFO - rip = 0x00007fff6822fb5d
[task 2021-04-20T16:09:52.535Z] 16:09:52 INFO - Found by: previous frame's frame pointer
[task 2021-04-20T16:09:52.535Z] 16:09:52 INFO - 6 0x7ffeecbde170
[task 2021-04-20T16:09:52.535Z] 16:09:52 INFO - rbp = 0x00007ffeecbddba0 rsp = 0x00007ffeecbddba8
[task 2021-04-20T16:09:52.535Z] 16:09:52 INFO - rip = 0x00007ffeecbde170
[task 2021-04-20T16:09:52.536Z] 16:09:52 INFO - Found by: call frame info
[task 2021-04-20T16:09:52.536Z] 16:09:52 INFO -
[task 2021-04-20T16:09:52.536Z] 16:09:52 INFO - Thread 1
[task 2021-04-20T16:09:52.536Z] 16:09:52 INFO - 0 libsystem_kernel.dylib!mach_msg_trap + 0xa
[task 2021-04-20T16:09:52.536Z] 16:09:52 INFO - rax = 0x000000000100001f rdx = 0x0000000000000000
[task 2021-04-20T16:09:52.536Z] 16:09:52 INFO - rcx = 0x000070000be70be8 rbx = 0x0000000000000006
[task 2021-04-20T16:09:52.536Z] 16:09:52 INFO - rsi = 0x0000000000000006 rdi = 0x000070000be70c90
[task 2021-04-20T16:09:52.536Z] 16:09:52 INFO - rbp = 0x000070000be70c40 rsp = 0x000070000be70be8
[task 2021-04-20T16:09:52.536Z] 16:09:52 INFO - r8 = 0x0000000000005403 r9 = 0x0000000000000000
[task 2021-04-20T16:09:52.536Z] 16:09:52 INFO - r10 = 0x000000000000024c r11 = 0x0000000000000206
[task 2021-04-20T16:09:52.536Z] 16:09:52 INFO - r12 = 0x0000000000000006 r13 = 0x000000000000024c
[task 2021-04-20T16:09:52.536Z] 16:09:52 INFO - r14 = 0x000070000be70c90 r15 = 0x0000000000000000
[task 2021-04-20T16:09:52.536Z] 16:09:52 INFO - rip = 0x00007fff6817922a
[task 2021-04-20T16:09:52.536Z] 16:09:52 INFO - Found by: given as instruction pointer in context
[task 2021-04-20T16:09:52.537Z] 16:09:52 INFO - 1 XUL!google_breakpad::ExceptionHandler::WaitForMessage(void*) [exception_handler.cc:64467b7c9c64938cca9fd14b756520226ae67119 : 524 + 0x1d]
[task 2021-04-20T16:09:52.537Z] 16:09:52 INFO - rbp = 0x000070000be70f10 rsp = 0x000070000be70c50
[task 2021-04-20T16:09:52.537Z] 16:09:52 INFO - rip = 0x0000000107edc865
[task 2021-04-20T16:09:52.537Z] 16:09:52 INFO - Found by: previous frame's frame pointer
[task 2021-04-20T16:09:52.537Z] 16:09:52 INFO - 2 libsystem_pthread.dylib!_pthread_body + 0x7e
[task 2021-04-20T16:09:52.537Z] 16:09:52 INFO - rbp = 0x000070000be70f30 rsp = 0x000070000be70f20
[task 2021-04-20T16:09:52.537Z] 16:09:52 INFO - rip = 0x00007fff682382eb
[task 2021-04-20T16:09:52.537Z] 16:09:52 INFO - Found by: previous frame's frame pointer
[task 2021-04-20T16:09:52.537Z] 16:09:52 INFO - 3 libsystem_pthread.dylib!_pthread_start + 0x42
[task 2021-04-20T16:09:52.537Z] 16:09:52 INFO - rbp = 0x000070000be70f50 rsp = 0x000070000be70f40
[task 2021-04-20T16:09:52.537Z] 16:09:52 INFO - rip = 0x00007fff6823b249
[task 2021-04-20T16:09:52.537Z] 16:09:52 INFO - Found by: previous frame's frame pointer
[task 2021-04-20T16:09:52.538Z] 16:09:52 INFO - 4 libsystem_pthread.dylib!thread_start + 0xd
[task 2021-04-20T16:09:52.538Z] 16:09:52 INFO - rbp = 0x000070000be70f78 rsp = 0x000070000be70f60
[task 2021-04-20T16:09:52.538Z] 16:09:52 INFO - rip = 0x00007fff6823740d
[task 2021-04-20T16:09:52.538Z] 16:09:52 INFO - Found by: previous frame's frame pointer
[task 2021-04-20T16:09:52.538Z] 16:09:52 INFO - 5 XUL + 0x3ffb7e0
[task 2021-04-20T16:09:52.538Z] 16:09:52 INFO - rsp = 0x000070000be71090 rip = 0x0000000107edc7e0
[task 2021-04-20T16:09:52.538Z] 16:09:52 INFO - Found by: stack scanning
[task 2021-04-20T16:09:52.538Z] 16:09:52 INFO - ```
Comment 1•4 years ago
|
||
Set release status flags based on info from the regressing bug 1666532
Comment hidden (Intermittent Failures Robot) |
Comment 3•3 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Comment 4•3 years ago
|
||
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=348326600&repo=autoland&lineNumber=10545
Comment hidden (Intermittent Failures Robot) |
Comment 6•3 years ago
|
||
There have been 43 total failures in the last 7 days (recent failure log).
Affected platforms are:
- linux1804-64-asan-qr
- linux1804-64-qr
Belén, could you please take a look?
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 8•3 years ago
|
||
The indexedDB fission test was sometimes timing out in the registered clean up function, when it was trying to remove the DB with a dom api call. This patch bails out this clearing if it takes too long. Try push https://treeherder.mozilla.org/jobs?repo=try&revision=403faa4e321d613fe5b056006c31eacda62f878a
Updated•3 years ago
|
Comment 9•3 years ago
|
||
bugherder |
Updated•3 years ago
|
Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Description
•