Closed Bug 1750920 Opened 3 years ago Closed 2 years ago

Intermittent TEST-UNEXPECTED-TIMEOUT | dom/messagechannel/tests/test_messageChannelWithMessageManager.xhtml | application timed out after 370 seconds with no output | Force-terminating active process(es).

Categories

(Core :: DOM: postMessage, defect, P5)

defect

Tracking

()

RESOLVED DUPLICATE of bug 1781435

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure)

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


[task 2022-01-19T06:52:31.181Z] 06:52:31     INFO - TEST-START | dom/messagechannel/tests/test_messageChannelWithMessageManager.xhtml
[task 2022-01-19T06:52:31.186Z] 06:52:31     INFO - GECKO(3721) | [Parent 3721, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/chrome/nsChromeRegistry.cpp:180
[task 2022-01-19T06:52:31.187Z] 06:52:31     INFO - GECKO(3721) | [Parent 3721, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/dom/security/nsCSPService.cpp:191
[task 2022-01-19T06:52:31.291Z] 06:52:31     INFO - GECKO(3721) | [Parent 3721, Main Thread] WARNING: NS_ENSURE_TRUE(rootFrame) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp:4235
[task 2022-01-19T06:52:31.345Z] 06:52:31     INFO - GECKO(3721) | [Parent 3721, Main Thread] WARNING: NS_ENSURE_TRUE(root) failed: file /builds/worker/checkouts/gecko/layout/base/nsDocumentViewer.cpp:2619
[task 2022-01-19T06:52:31.387Z] 06:52:31     INFO - GECKO(3721) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp2j558m2g.mozrunner/runtests_leaks_tab_pid3835.log
[task 2022-01-19T06:52:31.388Z] 06:52:31     INFO - GECKO(3721) | [3835, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:254
[task 2022-01-19T06:52:31.402Z] 06:52:31     INFO - GECKO(3721) | [Child 3835, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:693
[task 2022-01-19T06:52:31.424Z] 06:52:31     INFO - GECKO(3721) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2022-01-19T06:52:31.425Z] 06:52:31     INFO - GECKO(3721) | [Child 3835, Main Thread] WARNING: Could not get the program name for a cubeb stream.: 'NS_SUCCEEDED(rv)', file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:413
[task 2022-01-19T06:58:41.427Z] 06:58:41     INFO - Buffered messages finished
[task 2022-01-19T06:58:41.427Z] 06:58:41    ERROR - TEST-UNEXPECTED-TIMEOUT | dom/messagechannel/tests/test_messageChannelWithMessageManager.xhtml | application timed out after 370 seconds with no output
[task 2022-01-19T06:58:41.428Z] 06:58:41    ERROR - Force-terminating active process(es).
[task 2022-01-19T06:58:41.428Z] 06:58:41     INFO - Determining child pids from psutil...
[task 2022-01-19T06:58:41.432Z] 06:58:41     INFO - [3835]
[task 2022-01-19T06:58:41.433Z] 06:58:41     INFO - ==> process 3721 launched child process 3740
[task 2022-01-19T06:58:41.434Z] 06:58:41     INFO - ==> process 3721 launched child process 3835
[task 2022-01-19T06:58:41.435Z] 06:58:41     INFO - Found child pids: {3835, 3740}
[task 2022-01-19T06:58:41.436Z] 06:58:41     INFO - Failed to get child procs
[task 2022-01-19T06:58:41.437Z] 06:58:41     INFO - Killing process: 3835
[task 2022-01-19T06:58:41.438Z] 06:58:41     INFO - TEST-INFO | started process screentopng
[task 2022-01-19T06:58:41.581Z] 06:58:41     INFO - TEST-INFO | screentopng: exit 0
[task 2022-01-19T06:58:41.582Z] 06:58:41     INFO - Killing process: 3740
[task 2022-01-19T06:58:41.583Z] 06:58:41     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-01-19T06:58:41.585Z] 06:58:41     INFO - Can't trigger Breakpad, process no longer exists
[task 2022-01-19T06:58:41.586Z] 06:58:41     INFO - Killing process: 3721
[task 2022-01-19T06:58:41.587Z] 06:58:41     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-01-19T06:58:41.727Z] 06:58:41     INFO - psutil found pid 3721 dead
[task 2022-01-19T06:58:41.735Z] 06:58:41     INFO - TEST-INFO | Main app process: exit 0
[task 2022-01-19T06:58:41.736Z] 06:58:41     INFO - runtests.py | Application ran for: 0:06:19.121363
[task 2022-01-19T06:58:41.736Z] 06:58:41     INFO - zombiecheck | Reading PID log: /tmp/tmp5_guaq_qpidlog
[task 2022-01-19T06:58:41.736Z] 06:58:41     INFO - ==> process 3721 launched child process 3740
[task 2022-01-19T06:58:41.737Z] 06:58:41     INFO - ==> process 3721 launched child process 3835
[task 2022-01-19T06:58:41.737Z] 06:58:41     INFO - zombiecheck | Checking for orphan process with PID: 3835
[task 2022-01-19T06:58:41.738Z] 06:58:41     INFO - zombiecheck | Checking for orphan process with PID: 3740
[task 2022-01-19T06:58:41.748Z] 06:58:41     INFO - mozcrash Copy/paste: /builds/worker/fetches/minidump_stackwalk/minidump_stackwalk --symbols-url=https://symbols.mozilla.org/ --human /tmp/tmp2j558m2g.mozrunner/minidumps/6b00329d-9728-5d92-a01f-ec7eadd5f163.dmp /builds/worker/workspace/build/symbols
[task 2022-01-19T06:58:41.811Z] 06:58:41     INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/6b00329d-9728-5d92-a01f-ec7eadd5f163.dmp
[task 2022-01-19T06:58:41.811Z] 06:58:41     INFO - PROCESS-CRASH | Main app process exited normally | application crashed [None]
[task 2022-01-19T06:58:41.811Z] 06:58:41     INFO - Crash dump filename: /tmp/tmp2j558m2g.mozrunner/minidumps/6b00329d-9728-5d92-a01f-ec7eadd5f163.dmp
[task 2022-01-19T06:58:41.811Z] 06:58:41     INFO - stderr from minidump_stackwalk:
[task 2022-01-19T06:58:41.812Z] 06:58:41     INFO - [ERROR] Error processing dump: The system information stream was not found
[task 2022-01-19T06:58:41.818Z] 06:58:41     INFO - mozcrash Copy/paste: /builds/worker/fetches/minidump_stackwalk/minidump_stackwalk --symbols-url=https://symbols.mozilla.org/ --human /tmp/tmp2j558m2g.mozrunner/minidumps/0d096ffd-3a5e-9bd9-350f-6a2674720771.dmp /builds/worker/workspace/build/symbols
[task 2022-01-19T06:58:45.520Z] 06:58:45     INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/0d096ffd-3a5e-9bd9-350f-6a2674720771.dmp
[task 2022-01-19T06:58:45.521Z] 06:58:45     INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/0d096ffd-3a5e-9bd9-350f-6a2674720771.extra
[task 2022-01-19T06:58:45.813Z] 06:58:45     INFO - PROCESS-CRASH | Main app process exited normally | application crashed [@ __pthread_cond_wait]
[task 2022-01-19T06:58:45.813Z] 06:58:45     INFO - Crash dump filename: /tmp/tmp2j558m2g.mozrunner/minidumps/0d096ffd-3a5e-9bd9-350f-6a2674720771.dmp
[task 2022-01-19T06:58:45.814Z] 06:58:45     INFO - Operating system: Linux
[task 2022-01-19T06:58:45.814Z] 06:58:45     INFO -                   0.0.0 Linux 4.4.0-1014-aws #14taskcluster1-Ubuntu SMP Tue Apr 3 10:27:00 UTC 2018 x86_64
[task 2022-01-19T06:58:45.814Z] 06:58:45     INFO - CPU: amd64
[task 2022-01-19T06:58:45.815Z] 06:58:45     INFO -      family 6 model 85 stepping 4
[task 2022-01-19T06:58:45.815Z] 06:58:45     INFO -      2 CPUs
[task 2022-01-19T06:58:45.816Z] 06:58:45     INFO - Linux Ubuntu 18.04 - bionic (Ubuntu 18.04.6 LTS)
[task 2022-01-19T06:58:45.816Z] 06:58:45     INFO - 
[task 2022-01-19T06:58:45.816Z] 06:58:45     INFO - Crash reason:  SIGABRT / 0x00000000
[task 2022-01-19T06:58:45.817Z] 06:58:45     INFO - Crash address: 0x3e8000005d5
[task 2022-01-19T06:58:45.817Z] 06:58:45     INFO - Process uptime: not available
[task 2022-01-19T06:58:45.818Z] 06:58:45     INFO - 
[task 2022-01-19T06:58:45.818Z] 06:58:45     INFO - Thread 0  (crashed)
[task 2022-01-19T06:58:45.818Z] 06:58:45     INFO -  0  libpthread.so.0!__pthread_cond_wait [pthread_cond_wait.c : 655 + 0xfb]
[task 2022-01-19T06:58:45.818Z] 06:58:45     INFO -     rax = 0xfffffffffffffffc   rdx = 0x0000000000000000
[task 2022-01-19T06:58:45.819Z] 06:58:45     INFO -     rcx = 0x00007f9dd025d9f3   rbx = 0x00007f9dcf173ea0
[task 2022-01-19T06:58:45.819Z] 06:58:45     INFO -     rsi = 0x0000000000000080   rdi = 0x00007f9dcf173ec8
[task 2022-01-19T06:58:45.820Z] 06:58:45     INFO -     rbp = 0x00007f9dcf173ec4   rsp = 0x00007fff4f90e770
[task 2022-01-19T06:58:45.820Z] 06:58:45     INFO -      r8 = 0x0000000000000000    r9 = 0x0000000000000000
[task 2022-01-19T06:58:45.820Z] 06:58:45     INFO -     r10 = 0x0000000000000000   r11 = 0x0000000000000246
[task 2022-01-19T06:58:45.820Z] 06:58:45     INFO -     r12 = 0x00007f9dcf173ec8   r13 = 0x0000000000000000
[task 2022-01-19T06:58:45.820Z] 06:58:45     INFO -     r14 = 0x00007f9dcf173e38   r15 = 0x0000000000000000
[task 2022-01-19T06:58:45.821Z] 06:58:45     INFO -     rip = 0x00007f9dd025d9f3
[task 2022-01-19T06:58:45.821Z] 06:58:45     INFO -     Found by: given as instruction pointer in context
<...>
[task 2022-01-19T06:58:46.915Z] 06:58:46     INFO - 0x7f9dd0677000 - 0x7f9dd0677fff  memfd:mozilla-ipc (deleted)  ???
[task 2022-01-19T06:58:46.915Z] 06:58:46     INFO - 0x7f9dd0678000 - 0x7f9dd0686fff  liblgpllibs.so  ???
[task 2022-01-19T06:58:46.915Z] 06:58:46     INFO - 0x7f9dd0687000 - 0x7f9dd068cfff  libplds4.so  ???
[task 2022-01-19T06:58:46.916Z] 06:58:46     INFO - 0x7f9dd068d000 - 0x7f9dd0693fff  libplc4.so  ???
[task 2022-01-19T06:58:46.916Z] 06:58:46     INFO - 0x7fff4f9f2000 - 0x7fff4f9f3fff  linux-gate.so  ???
[task 2022-01-19T06:58:46.916Z] 06:58:46     INFO - 
[task 2022-01-19T06:58:46.916Z] 06:58:46     INFO - Unloaded modules:
[task 2022-01-19T06:58:46.916Z] 06:58:46     INFO - 
[task 2022-01-19T06:58:46.916Z] 06:58:46     INFO - Unimplemented streams encountered:
[task 2022-01-19T06:58:46.916Z] 06:58:46     INFO - Stream 0x47670006 LinuxCmdLine (Google Extension) @ 0x000c6378
[task 2022-01-19T06:58:46.916Z] 06:58:46     INFO - Stream 0x47670008 LinuxAuxv (Google Extension) @ 0x000c7940
[task 2022-01-19T06:58:46.916Z] 06:58:46     INFO - Stream 0x4767000a LinuxDsoDebug (Google Extension) @ 0x000e9d98
[task 2022-01-19T06:58:46.917Z] 06:58:46     INFO - Stopping web server
[task 2022-01-19T06:58:46.917Z] 06:58:46     INFO - Server shut down.
[task 2022-01-19T06:58:46.917Z] 06:58:46     INFO - Web server killed.
[task 2022-01-19T06:58:46.917Z] 06:58:46     INFO - Stopping web socket server
[task 2022-01-19T06:58:46.917Z] 06:58:46     INFO - Stopping ssltunnel
[task 2022-01-19T06:58:46.917Z] 06:58:46     INFO - leakcheck | Processing log file /tmp/tmp2j558m2g.mozrunner/runtests_leaks.log
[task 2022-01-19T06:58:46.917Z] 06:58:46     INFO - TEST-INFO | leakcheck | default process: leak threshold set at 0 bytes
[task 2022-01-19T06:58:46.917Z] 06:58:46     INFO - TEST-INFO | leakcheck | tab process: leak threshold set at 0 bytes
[task 2022-01-19T06:58:46.917Z] 06:58:46     INFO - TEST-INFO | leakcheck | gmplugin process: leak threshold set at 20000 bytes
[task 2022-01-19T06:58:46.917Z] 06:58:46     INFO - TEST-INFO | leakcheck | gpu process: leak threshold set at 0 bytes
[task 2022-01-19T06:58:46.917Z] 06:58:46     INFO - TEST-INFO | leakcheck | vr process: leak threshold set at 0 bytes
[task 2022-01-19T06:58:46.918Z] 06:58:46     INFO - TEST-INFO | leakcheck | rdd process: leak threshold set at 0 bytes
[task 2022-01-19T06:58:46.918Z] 06:58:46     INFO - TEST-INFO | leakcheck | socket process: leak threshold set at 0 bytes
[task 2022-01-19T06:58:46.918Z] 06:58:46     INFO - TEST-INFO | leakcheck | sandboxbroker process: leak threshold set at 0 bytes
[task 2022-01-19T06:58:46.918Z] 06:58:46     INFO - TEST-INFO | leakcheck | forkserver process: leak threshold set at 0 bytes
[task 2022-01-19T06:58:46.918Z] 06:58:46     INFO - TEST-INFO | leakcheck | utility process: leak threshold set at 0 bytes
[task 2022-01-19T06:58:46.918Z] 06:58:46     INFO - leakcheck | Processing leak log file /tmp/tmp2j558m2g.mozrunner/runtests_leaks_tab_pid3835.log
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.