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

task 2020-02-17T09:58:50.933Z] 09:58:50 INFO - TEST-START | browser/base/content/test/webrtc/browser_devices_get_user_media.js
[task 2020-02-17T10:05:00.991Z] 10:05:00 INFO - Buffered messages logged at 09:58:50
[task 2020-02-17T10:05:00.992Z] 10:05:00 INFO - Entering test bound test
[task 2020-02-17T10:05:00.992Z] 10:05:00 INFO - Buffered messages finished
[task 2020-02-17T10:05:00.993Z] 10:05:00 ERROR - TEST-UNEXPECTED-TIMEOUT | browser/base/content/test/webrtc/browser_devices_get_user_media.js | application timed out after 370 seconds with no output
[task 2020-02-17T10:05:00.994Z] 10:05:00 ERROR - Force-terminating active process(es).
[task 2020-02-17T10:05:00.994Z] 10:05:00 INFO - Determining child pids from psutil...
[task 2020-02-17T10:05:00.995Z] 10:05:00 INFO - [8707, 8731, 8788]
[task 2020-02-17T10:05:00.995Z] 10:05:00 INFO - ==> process 8654 launched child process 8680
[task 2020-02-17T10:05:00.995Z] 10:05:00 INFO - ==> process 8654 launched child process 8707
[task 2020-02-17T10:05:00.995Z] 10:05:00 INFO - ==> process 8654 launched child process 8731
[task 2020-02-17T10:05:00.996Z] 10:05:00 INFO - ==> process 8654 launched child process 8788
[task 2020-02-17T10:05:00.996Z] 10:05:00 INFO - Found child pids: set([8731, 8680, 8707, 8788])
[task 2020-02-17T10:05:00.996Z] 10:05:00 INFO - Failed to get child procs
[task 2020-02-17T10:05:00.996Z] 10:05:00 INFO - Killing process: 8731
[task 2020-02-17T10:05:00.997Z] 10:05:00 INFO - TEST-INFO | started process screentopng
[task 2020-02-17T10:05:01.260Z] 10:05:01 INFO - TEST-INFO | screentopng: exit 0
[task 2020-02-17T10:05:01.260Z] 10:05:01 INFO - Killing process: 8680
[task 2020-02-17T10:05:01.262Z] 10:05:01 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-02-17T10:05:01.264Z] 10:05:01 INFO - Can't trigger Breakpad, process no longer exists
[task 2020-02-17T10:05:01.265Z] 10:05:01 INFO - Killing process: 8707
[task 2020-02-17T10:05:01.265Z] 10:05:01 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-02-17T10:05:01.266Z] 10:05:01 INFO - Killing process: 8788
[task 2020-02-17T10:05:01.266Z] 10:05:01 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-02-17T10:05:01.267Z] 10:05:01 INFO - Killing process: 8654
[task 2020-02-17T10:05:01.267Z] 10:05:01 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-02-17T10:05:01.405Z] 10:05:01 INFO - psutil found pid 8654 dead
[task 2020-02-17T10:05:01.453Z] 10:05:01 WARNING - runtests.py | Failed to get app exit code - running/crashed?
[task 2020-02-17T10:05:01.453Z] 10:05:01 INFO - TEST-INFO | Main app process: exit 0
[task 2020-02-17T10:05:01.453Z] 10:05:01 INFO - runtests.py | Application ran for: 0:06:24.377318
[task 2020-02-17T10:05:01.454Z] 10:05:01 INFO - zombiecheck | Reading PID log: /tmp/tmpgSKxs4pidlog
[task 2020-02-17T10:05:01.454Z] 10:05:01 INFO - ==> process 8654 launched child process 8680
[task 2020-02-17T10:05:01.454Z] 10:05:01 INFO - ==> process 8654 launched child process 8707
[task 2020-02-17T10:05:01.454Z] 10:05:01 INFO - ==> process 8654 launched child process 8731
[task 2020-02-17T10:05:01.455Z] 10:05:01 INFO - ==> process 8654 launched child process 8788
[task 2020-02-17T10:05:01.455Z] 10:05:01 INFO - zombiecheck | Checking for orphan process with PID: 8680
[task 2020-02-17T10:05:01.455Z] 10:05:01 INFO - zombiecheck | Checking for orphan process with PID: 8731
[task 2020-02-17T10:05:01.455Z] 10:05:01 INFO - zombiecheck | Checking for orphan process with PID: 8707
[task 2020-02-17T10:05:01.456Z] 10:05:01 INFO - zombiecheck | Checking for orphan process with PID: 8788
[task 2020-02-17T10:05:01.456Z] 10:05:01 INFO - mozcrash Downloading symbols from: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/aoxy8r-tSkK_cSlQ9eVtmA/artifacts/public/build/target.crashreporter-symbols.zip
[task 2020-02-17T10:05:07.130Z] 10:05:07 INFO - mozcrash Copy/paste: /builds/worker/fetches/minidump_stackwalk/minidump_stackwalk /tmp/tmpOs9lVO.mozrunner/minidumps/3fb7f698-eb9e-f03c-9f69-4300f204bd1d.dmp /tmp/tmpoPm0kM
[task 2020-02-17T10:05:12.521Z] 10:05:12 INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/3fb7f698-eb9e-f03c-9f69-4300f204bd1d.dmp

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=294957520&repo=autoland&lineNumber=1477

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=302103199&repo=autoland&lineNumber=3330

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=308841967&repo=autoland&lineNumber=2846

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=356592985&repo=autoland&lineNumber=3286

Update:

There have been 39 failures since the bug has been reopened:

• 5 failures on Linux 18.04 x64 WebRender asan opt
• 15 failures on Linux 18.04 x64 WebRender opt
• 19 failures on Linux 18.04 x64 WebRender Shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=357061578&repo=mozilla-central&lineNumber=4179

[task 2021-11-04T22:22:43.361Z] 22:22:43     INFO - TEST-PASS | browser/base/content/test/webrtc/browser_devices_get_user_media.js | expected audio to be shared - {"audio":true} deepEqual {"audio":true} - 
[task 2021-11-04T22:22:43.362Z] 22:22:43     INFO - closing the stream
[task 2021-11-04T22:22:43.363Z] 22:22:43     INFO - Buffered messages finished
[task 2021-11-04T22:22:43.364Z] 22:22:43    ERROR - TEST-UNEXPECTED-TIMEOUT | browser/base/content/test/webrtc/browser_devices_get_user_media.js | application timed out after 370 seconds with no output
[task 2021-11-04T22:22:43.365Z] 22:22:43    ERROR - Force-terminating active process(es).
[task 2021-11-04T22:22:43.365Z] 22:22:43     INFO - Determining child pids from psutil...
[task 2021-11-04T22:22:43.370Z] 22:22:43     INFO - [2772, 2789, 2837, 2876, 2895, 2933]
[task 2021-11-04T22:22:43.370Z] 22:22:43     INFO - ==> process 2697 launched child process 2713
[task 2021-11-04T22:22:43.371Z] 22:22:43     INFO - ==> process 2697 launched child process 2772
[task 2021-11-04T22:22:43.371Z] 22:22:43     INFO - ==> process 2697 launched child process 2789
[task 2021-11-04T22:22:43.372Z] 22:22:43     INFO - ==> process 2697 launched child process 2837
[task 2021-11-04T22:22:43.373Z] 22:22:43     INFO - ==> process 2697 launched child process 2876
[task 2021-11-04T22:22:43.373Z] 22:22:43     INFO - ==> process 2697 launched child process 2895
[task 2021-11-04T22:22:43.374Z] 22:22:43     INFO - ==> process 2697 launched child process 2933
[task 2021-11-04T22:22:43.374Z] 22:22:43     INFO - Found child pids: {2789, 2895, 2772, 2837, 2933, 2713, 2876}
[task 2021-11-04T22:22:43.375Z] 22:22:43     INFO - Failed to get child procs
[task 2021-11-04T22:22:43.375Z] 22:22:43     INFO - Killing process: 2789
[task 2021-11-04T22:22:43.375Z] 22:22:43     INFO - TEST-INFO | started process screentopng
[task 2021-11-04T22:22:43.602Z] 22:22:43     INFO - TEST-INFO | screentopng: exit 0

Michael, as the owner of this component, could you help us assign this to someone?
Thank you.

This is most likely a duplicate of Bug 1738787, which currently working on. I'll hold off making that connection official until I can get a fix landed and we'll see if this bug resolves.

There have been 51 failures in the last 7 days:

• 3 failures on linux1804-64-asan-qr opt
• 28 failures on linux1804-64-qr opt
• 20 failures on linux1804-64-shippable-qr opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=358676374&repo=mozilla-central&lineNumber=3853

Hi Michael, can we land the disabling patch or should the patch in 1738787 get landed?

Sorry - I haven't gotten through my backlog from Thanksgiving yet. I'll land the patch in 1738787 later today or tomorrow. Let's see if that does indeed help.

Michael, the failure rate hasn't changed since the patches in Bug 1738787 landed, could you please take another look?

Update:
There have been 41 failures within the last 7 days, more than half of them are after the patch in Bug 1738787 landed:
• 1 failures on Linux 18.04 x64 WebRender asan opt
• 20 failures on Linux 18.04 x64 WebRender opt
• 20 failures on Linux 18.04 x64 WebRender Shippable opt
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=360190987&repo=mozilla-central&lineNumber=4251

[task 2021-12-04T23:42:49.862Z] 23:42:49     INFO - TEST-PASS | browser/base/content/test/webrtc/browser_devices_get_user_media.js | expected video and audio to be shared - {"video":true,"audio":true} deepEqual {"video":true,"audio":true} - 
[task 2021-12-04T23:42:49.863Z] 23:42:49     INFO - closing the stream
[task 2021-12-04T23:42:49.863Z] 23:42:49     INFO - Buffered messages finished
[task 2021-12-04T23:42:49.864Z] 23:42:49    ERROR - TEST-UNEXPECTED-TIMEOUT | browser/base/content/test/webrtc/browser_devices_get_user_media.js | application timed out after 370 seconds with no output
[task 2021-12-04T23:42:49.865Z] 23:42:49    ERROR - Force-terminating active process(es).
[task 2021-12-04T23:42:49.866Z] 23:42:49     INFO - Determining child pids from psutil...
[task 2021-12-04T23:42:49.866Z] 23:42:49     INFO - [4739, 4760, 4853, 4895, 4928]
[task 2021-12-04T23:42:49.867Z] 23:42:49     INFO - ==> process 4667 launched child process 4687
[task 2021-12-04T23:42:49.867Z] 23:42:49     INFO - ==> process 4667 launched child process 4739
[task 2021-12-04T23:42:49.868Z] 23:42:49     INFO - ==> process 4667 launched child process 4760
[task 2021-12-04T23:42:49.869Z] 23:42:49     INFO - ==> process 4667 launched child process 4853
[task 2021-12-04T23:42:49.871Z] 23:42:49     INFO - ==> process 4667 launched child process 4895
[task 2021-12-04T23:42:49.871Z] 23:42:49     INFO - ==> process 4667 launched child process 4928
[task 2021-12-04T23:42:49.872Z] 23:42:49     INFO - Found child pids: {4928, 4739, 4687, 4853, 4760, 4895}
[task 2021-12-04T23:42:49.873Z] 23:42:49     INFO - Failed to get child procs
[task 2021-12-04T23:42:49.873Z] 23:42:49     INFO - Killing process: 4928
[task 2021-12-04T23:42:49.876Z] 23:42:49     INFO - TEST-INFO | started process screentopng
[task 2021-12-04T23:42:50.028Z] 23:42:50     INFO - TEST-INFO | screentopng: exit 0
[task 2021-12-04T23:42:50.029Z] 23:42:50     INFO - Killing process: 4739
[task 2021-12-04T23:42:50.029Z] 23:42:50     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-12-04T23:42:50.029Z] 23:42:50     INFO - Killing process: 4687
[task 2021-12-04T23:42:50.030Z] 23:42:50     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-12-04T23:42:50.030Z] 23:42:50     INFO - Can't trigger Breakpad, process no longer exists
[task 2021-12-04T23:42:50.030Z] 23:42:50     INFO - Killing process: 4853
[task 2021-12-04T23:42:50.031Z] 23:42:50     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-12-04T23:42:50.031Z] 23:42:50     INFO - Killing process: 4760
[task 2021-12-04T23:42:50.031Z] 23:42:50     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-12-04T23:42:50.032Z] 23:42:50     INFO - Killing process: 4895
[task 2021-12-04T23:42:50.032Z] 23:42:50     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-12-04T23:42:50.032Z] 23:42:50     INFO - Killing process: 4667
[task 2021-12-04T23:42:50.033Z] 23:42:50     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-12-04T23:42:50.207Z] 23:42:50     INFO - psutil found pid 4667 dead
[task 2021-12-04T23:42:50.211Z] 23:42:50     INFO - TEST-INFO | Main app process: exit 0
[task 2021-12-04T23:42:50.211Z] 23:42:50     INFO - runtests.py | Application ran for: 0:06:17.243452

https://hg.mozilla.org/mozilla-central/rev/45975f5c5c8e

https://hg.mozilla.org/mozilla-central/rev/f57bb6125986

Andrew, this test was disabled 5 days ago on Linux64 but somehow its still failing on it. Im not sure why, can you please take a look?

Looks like :apavel figured this out, nice one :)

https://hg.mozilla.org/mozilla-central/rev/a850ea7df539

I have a number of fixes to the webrtc frontend tests lined up in various bugs, but this issue remains.

The crashing frame varies wildly but the stack seems consistent:

[task 2023-02-20T12:57:40.495Z] 12:57:40     INFO - Thread 0 firefox-bin (crashed)
[task 2023-02-20T12:57:40.508Z] 12:57:40     INFO -  1  libxul.so!nsWindow::ReleaseGdkWindow()  [nsWindow.cpp:985043f4d1b57b0df23ea812753f2e7b6a80d47d : 5770 + 0x7]
[task 2023-02-20T12:57:40.512Z] 12:57:40     INFO -  2  libxul.so!nsWindow::OnUnrealize() [nsWindow.cpp:985043f4d1b57b0df23ea812753f2e7b6a80d47d : 4124 + 0x7]
[task 2023-02-20T12:57:40.518Z] 12:57:40     INFO -  3  libxul.so!widget_unrealize_cb(_GtkWidget*)  [nsWindow.cpp:985043f4d1b57b0df23ea812753f2e7b6a80d47d : 7887 + 0x7]
[task 2023-02-20T12:57:40.525Z] 12:57:40     INFO -  4  libgobject-2.0.so.0!g_closure_invoke [gclosure.c : 804 + 0x17]
[task 2023-02-20T12:57:40.531Z] 12:57:40     INFO -  5  libgobject-2.0.so.0!signal_emit_unlocked_R [gsignal.c : 3636 + 0x4]
[task 2023-02-20T12:57:40.538Z] 12:57:40     INFO -  6  libgobject-2.0.so.0!g_signal_emit_valist [gsignal.c : 3392 + 0x1d]
[task 2023-02-20T12:57:40.545Z] 12:57:40     INFO -  7  libgobject-2.0.so.0!g_signal_emit [gsignal.c : 3448 + 0x4]
(...)
[task 2023-02-20T12:57:40.571Z] 12:57:40     INFO - 13  libgobject-2.0.so.0!g_closure_invoke [gclosure.c : 804 + 0x17]
[task 2023-02-20T12:57:40.574Z] 12:57:40     INFO - 14  libgobject-2.0.so.0!signal_emit_unlocked_R [gsignal.c : 3674 + 0x7]
[task 2023-02-20T12:57:40.581Z] 12:57:40     INFO - 15  libgobject-2.0.so.0!g_signal_emit_valist [gsignal.c : 3392 + 0x1d]
[task 2023-02-20T12:57:40.584Z] 12:57:40     INFO - 16  libgobject-2.0.so.0!g_signal_emit [gsignal.c : 3448 + 0x4]
(...)
[task 2023-02-20T12:57:40.592Z] 12:57:40     INFO - 20  libgobject-2.0.so.0!g_object_run_dispose [gobject.c : 1102 + 0x8]
[task 2023-02-20T12:57:40.594Z] 12:57:40     INFO - 21  libxul.so!nsWindow::Destroy() [nsWindow.cpp:985043f4d1b57b0df23ea812753f2e7b6a80d47d : 659 + 0xc]
(...)
[task 2023-02-20T12:57:40.603Z] 12:57:40     INFO - 28  libxul.so!mozilla::AppWindow::Destroy() [AppWindow.cpp:985043f4d1b57b0df23ea812753f2e7b6a80d47d : 646 + 0x5]
[task 2023-02-20T12:57:40.604Z] 12:57:40     INFO - 29  libxul.so!nsChromeTreeOwner::Destroy() [nsChromeTreeOwner.cpp:985043f4d1b57b0df23ea812753f2e7b6a80d47d : 257]
[task 2023-02-20T12:57:40.605Z] 12:57:40     INFO - 30  libxul.so!{virtual override thunk({offset(-8)}, nsChromeTreeOwner::Destroy())} [nsChromeTreeOwner.cpp:985043f4d1b57b0df23ea812753f2e7b6a80d47d : 0 + 0xd]
[task 2023-02-20T12:57:40.607Z] 12:57:40     INFO - 31  libxul.so!nsGlobalWindowOuter::ReallyCloseWindow() [nsGlobalWindowOuter.cpp:985043f4d1b57b0df23ea812753f2e7b6a80d47d : 6211 + 0x8]
[task 2023-02-20T12:57:40.608Z] 12:57:40     INFO - 32  libxul.so!nsCloseEvent::Run() [nsGlobalWindowOuter.cpp:985043f4d1b57b0df23ea812753f2e7b6a80d47d : 6012 + 0x4]

Martin, does this tell you anything?

It's a crash in nsWindow::DestroyChildWindows() / get_window_for_gdk_window() where we iterate through embedded child windows and delete them and looks like a child window is already deleted.

This is very rarely used, I think it's used in the testsuite only. May be worth to run with MOZ_LOG="Widget:5 WidgetPopup:5" env variables and log how the windows are deleted to see what's going on.

I can try that locally on Ubuntu 18.04 - how can run such setup here? I don't see such crash when I just run

./mach mochitest browser/base/content/test/webrtc/browser_devices_get_user_media.js
./mach mochitest browser/base/content/test/webrtc

It might be hard to catch locally. I haven't tried myself. But to mimic that try push in comment 62, do this:

hg pull -r a544d51c6334ff121217fce897de2cbc21bb1059 try
hg up tip
./mach build
./mach test browser/base/content/test/webrtc/browser_devices_get_user_media.js --verify

Seems like you're better off with a non-debug config.