Closed Bug 1720271 Opened 5 years ago Closed 3 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | devtools/client/framework/browser-toolbox/test/browser_browser_toolbox_debugger.js (finished) | application timed out after 370 seconds with no output

Categories

(DevTools :: Framework, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED DUPLICATE of bug 1767783

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=345049819&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/KrZIbT9yRz-U9OfosP3wzA/runs/0/artifacts/public/logs/live_backing.log


[task 2021-07-13T05:33:52.000Z] 05:33:52     INFO - TEST-OK | devtools/client/framework/browser-toolbox/test/browser_browser_toolbox_debugger.js | took 2792ms
[task 2021-07-13T05:33:52.008Z] 05:33:52     INFO - checking window state
[task 2021-07-13T05:33:52.008Z] 05:33:52     INFO - GECKO(2136) | must wait for focus
[task 2021-07-13T05:40:02.027Z] 05:40:02     INFO - Buffered messages finished
[task 2021-07-13T05:40:02.028Z] 05:40:02    ERROR - TEST-UNEXPECTED-TIMEOUT | devtools/client/framework/browser-toolbox/test/browser_browser_toolbox_debugger.js (finished) | application timed out after 370 seconds with no output
[task 2021-07-13T05:40:02.028Z] 05:40:02    ERROR - Force-terminating active process(es).
[task 2021-07-13T05:40:02.029Z] 05:40:02     INFO - Determining child pids from psutil...
[task 2021-07-13T05:40:02.031Z] 05:40:02     INFO - [2137, 2138, 2139, 2140, 2147]
[task 2021-07-13T05:40:02.031Z] 05:40:02     INFO - ==> process 2136 launched child process 2137
[task 2021-07-13T05:40:02.031Z] 05:40:02     INFO - ==> process 2136 launched child process 2138
[task 2021-07-13T05:40:02.032Z] 05:40:02     INFO - ==> process 2136 launched child process 2139
[task 2021-07-13T05:40:02.032Z] 05:40:02     INFO - ==> process 2136 launched child process 2140
[task 2021-07-13T05:40:02.032Z] 05:40:02     INFO - ==> process 2136 launched child process 2147
[task 2021-07-13T05:40:02.033Z] 05:40:02     INFO - Found child pids: {2147, 2137, 2138, 2139, 2140}
[task 2021-07-13T05:40:02.033Z] 05:40:02     INFO - Killing process: 2147
[task 2021-07-13T05:40:02.033Z] 05:40:02     INFO - TEST-INFO | started process screencapture
[task 2021-07-13T05:40:02.147Z] 05:40:02     INFO - TEST-INFO | screencapture: exit 0
[task 2021-07-13T05:40:02.147Z] 05:40:02     INFO - Killing process: 2137
[task 2021-07-13T05:40:02.147Z] 05:40:02     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-07-13T05:40:02.148Z] 05:40:02     INFO - Killing process: 2138
[task 2021-07-13T05:40:02.148Z] 05:40:02     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-07-13T05:40:02.148Z] 05:40:02     INFO - Killing process: 2139
[task 2021-07-13T05:40:02.149Z] 05:40:02     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-07-13T05:40:02.149Z] 05:40:02     INFO - Killing process: 2140
[task 2021-07-13T05:40:02.150Z] 05:40:02     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-07-13T05:40:02.999Z] 05:40:02     INFO - psutil found pid 2139 dead
[task 2021-07-13T05:40:03.000Z] 05:40:03     INFO - psutil found pid 2147 dead
[task 2021-07-13T05:40:03.000Z] 05:40:03     INFO - psutil found pid 2137 dead
[task 2021-07-13T05:40:03.001Z] 05:40:03     INFO - psutil found pid 2140 dead
[task 2021-07-13T05:40:03.001Z] 05:40:03     INFO - psutil found pid 2138 dead
[task 2021-07-13T05:40:03.001Z] 05:40:03     INFO - Killing process: 2136
[task 2021-07-13T05:40:03.002Z] 05:40:03     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-07-13T05:40:03.137Z] 05:40:03     INFO - psutil found pid 2136 dead
[task 2021-07-13T05:40:03.138Z] 05:40:03     INFO - TEST-INFO | Main app process: exit 0
[task 2021-07-13T05:40:03.138Z] 05:40:03     INFO - runtests.py | Application ran for: 0:06:18.579697
[task 2021-07-13T05:40:03.139Z] 05:40:03     INFO - zombiecheck | Reading PID log: /var/folders/54/8r5nfdcs0q7415rh7wc7wd_4000014/T/tmpd0fuprzupidlog
[task 2021-07-13T05:40:03.139Z] 05:40:03     INFO - ==> process 2136 launched child process 2137
[task 2021-07-13T05:40:03.139Z] 05:40:03     INFO - ==> process 2136 launched child process 2138
[task 2021-07-13T05:40:03.140Z] 05:40:03     INFO - ==> process 2136 launched child process 2139
[task 2021-07-13T05:40:03.140Z] 05:40:03     INFO - ==> process 2136 launched child process 2140
[task 2021-07-13T05:40:03.140Z] 05:40:03     INFO - ==> process 2136 launched child process 2147
[task 2021-07-13T05:40:03.141Z] 05:40:03     INFO - ==> process 2136 launched child process 2374
[task 2021-07-13T05:40:03.141Z] 05:40:03     INFO - zombiecheck | Checking for orphan process with PID: 2147
[task 2021-07-13T05:40:03.141Z] 05:40:03     INFO - zombiecheck | Checking for orphan process with PID: 2374
[task 2021-07-13T05:40:03.142Z] 05:40:03     INFO - zombiecheck | Checking for orphan process with PID: 2137
[task 2021-07-13T05:40:03.142Z] 05:40:03     INFO - zombiecheck | Checking for orphan process with PID: 2138
[task 2021-07-13T05:40:03.142Z] 05:40:03     INFO - zombiecheck | Checking for orphan process with PID: 2139
[task 2021-07-13T05:40:03.143Z] 05:40:03     INFO - zombiecheck | Checking for orphan process with PID: 2140
[task 2021-07-13T05:40:03.143Z] 05:40:03     INFO - mozcrash Downloading symbols from: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/cxHSdKELTf6h90ZjtfoO5w/artifacts/public/build/target.crashreporter-symbols.zip
[task 2021-07-13T05:40:06.707Z] 05:40:06     INFO - mozcrash Copy/paste: /opt/worker/tasks/task_162615284306718/fetches/minidump_stackwalk/minidump_stackwalk /var/folders/54/8r5nfdcs0q7415rh7wc7wd_4000014/T/tmpvlb_v4f4.mozrunner/minidumps/FD22F204-16E0-4979-8FC6-2CC62972E06E.dmp /var/folders/54/8r5nfdcs0q7415rh7wc7wd_4000014/T/tmp2ov6amtj
[task 2021-07-13T05:40:11.302Z] 05:40:11     INFO - mozcrash Saved minidump as /opt/worker/tasks/task_162615284306718/build/blobber_upload_dir/FD22F204-16E0-4979-8FC6-2CC62972E06E.dmp
[task 2021-07-13T05:40:11.302Z] 05:40:11     INFO - mozcrash Saved app info as /opt/worker/tasks/task_162615284306718/build/blobber_upload_dir/FD22F204-16E0-4979-8FC6-2CC62972E06E.extra
[task 2021-07-13T05:40:11.384Z] 05:40:11     INFO - PROCESS-CRASH | Main app process exited normally | application crashed [@ google_breakpad::ReceivePort::WaitForMessage(google_breakpad::MachReceiveMessage*, unsigned int)]
[task 2021-07-13T05:40:11.384Z] 05:40:11     INFO - Crash dump filename: /var/folders/54/8r5nfdcs0q7415rh7wc7wd_4000014/T/tmpvlb_v4f4.mozrunner/minidumps/FD22F204-16E0-4979-8FC6-2CC62972E06E.dmp
[task 2021-07-13T05:40:11.384Z] 05:40:11     INFO - Operating system: Mac OS X
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO -                   10.15.7 19H524
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO - CPU: amd64
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO -      family 6 model 158 stepping 10
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO -      12 CPUs
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO - 
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO - GPU: UNKNOWN
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO - Crash reason:  EXC_SOFTWARE / SIGABRT
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO - Crash address: 0x7fff70b85dfa
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO - Process uptime: 378 seconds
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO - 
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO - Thread 0 (crashed) - MainThread 0  libsystem_kernel.dylib!mach_msg_trap + 0xa
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO -     rax = 0x000000000100001f   rdx = 0x0000000000000000
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO -     rcx = 0x00007ffeed6add28   rbx = 0x0000000000000102
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO -     rsi = 0x0000000000000102   rdi = 0x00007ffeed6addf0
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO -     rbp = 0x00007ffeed6add80   rsp = 0x00007ffeed6add28
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO -      r8 = 0x0000000000001f07    r9 = 0x0000000000001388
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO -     r10 = 0x000000000000041c   r11 = 0x0000000000000202
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO -     r12 = 0x0000000000000102   r13 = 0x000000000000041c
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO -     r14 = 0x00007ffeed6addf0   r15 = 0x0000000000000000
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO -     rip = 0x00007fff70b85dfa
[task 2021-07-13T05:40:11.385Z] 05:40:11     INFO -     Found by: given as instruction pointer in context
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -  1  XUL!google_breakpad::ReceivePort::WaitForMessage(google_breakpad::MachReceiveMessage*, unsigned int) [MachIPC.mm:98cbaebbfa009242597f557ddde4a8837f4ab8fb : 249 + 0x12]
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -     rbp = 0x00007ffeed6adda0   rsp = 0x00007ffeed6add90
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -     rip = 0x000000010c9ae482
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -     Found by: previous frame's frame pointer
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -  2  XUL!google_breakpad::CrashGenerationClient::RequestDumpForException(int, int, long long, unsigned int, unsigned int) [crash_generation_client.cc:98cbaebbfa009242597f557ddde4a8837f4ab8fb : 70 + 0xd]
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -     rbp = 0x00007ffeed6ae660   rsp = 0x00007ffeed6addb0
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -     rip = 0x000000010c9a60cd
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -     Found by: call frame info
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -  3  XUL!google_breakpad::ExceptionHandler::WriteMinidumpWithException(int, int, long long, __darwin_ucontext*, unsigned int, unsigned int, bool, bool) [exception_handler.cc:98cbaebbfa009242597f557ddde4a8837f4ab8fb : 464 + 0x1f]
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -     rbx = 0x00007ffeed6aed30   rbp = 0x00007ffeed6ae750
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -     rsp = 0x00007ffeed6ae670   r12 = 0x0000000000000000
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -     r14 = 0x00007fff70c49425   r15 = 0x0000000000000000
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -     rip = 0x000000010c9a8362
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -     Found by: call frame info
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -  4  XUL!google_breakpad::ExceptionHandler::SignalHandler(int, __siginfo*, void*) [exception_handler.cc:98cbaebbfa009242597f557ddde4a8837f4ab8fb : 707 + 0x2a]
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -     rbx = 0x0000000102900000   rbp = 0x00007ffeed6ae790
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -     rsp = 0x00007ffeed6ae760   r12 = 0x0000000000000001
[task 2021-07-13T05:40:11.386Z] 05:40:11     INFO -     r14 = 0x0000000100000001   r15 = 0x0000000000000000
[task 2021-07-13T05:40:11.387Z] 05:40:11     INFO -     rip = 0x000000010c9a864a
[task 2021-07-13T05:40:11.387Z] 05:40:11     INFO -     Found by: call frame info
[task 2021-07-13T05:40:11.387Z] 05:40:11     INFO -  5  libsystem_platform.dylib!_sigtramp + 0x1d
[task 2021-07-13T05:40:11.387Z] 05:40:11     INFO -     rbx = 0x0000000102900000   rbp = 0x00007ffeed6ae7a0
[task 2021-07-13T05:40:11.387Z] 05:40:11     INFO -     rsp = 0x00007ffeed6ae7a0   r12 = 0x0000000000000001
[task 2021-07-13T05:40:11.387Z] 05:40:11     INFO -     r14 = 0x000000000000ffff   r15 = 0x0000000000000000
[task 2021-07-13T05:40:11.387Z] 05:40:11     INFO -     rip = 0x00007fff70c3d5fd
[task 2021-07-13T05:40:11.387Z] 05:40:11     INFO -     Found by: call frame info
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
Status: REOPENED → RESOLVED
Closed: 4 years ago → 4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago → 4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago → 4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago → 3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago → 3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago → 3 years ago
Duplicate of bug: 1767783
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.