Closed
Bug 1432025
Opened 7 years ago
Closed 6 years ago
Intermittent TEST-UNEXPECTED-TIMEOUT | dom/media/tests/mochitest/test_peerConnection_transceivers.html | application timed out after 370 seconds with no output
Categories
(Core :: WebRTC, defect, P2)
Core
WebRTC
Tracking
()
RESOLVED
FIXED
People
(Reporter: intermittent-bug-filer, Assigned: aiakab)
References
(Depends on 1 open bug)
Details
(Keywords: intermittent-failure, Whiteboard: [stockwell disabled])
Attachments
(2 files)
(deleted),
patch
|
jmaher
:
review+
|
Details | Diff | Splinter Review |
(deleted),
patch
|
jmaher
:
review+
|
Details | Diff | Splinter Review |
Filed by: apavel [at] mozilla.com
https://treeherder.mozilla.org/logviewer.html#?job_id=157607000&repo=autoland
https://queue.taskcluster.net/v1/task/eAt8CottSLONb78jAISAFg/runs/0/artifacts/public/logs/live_backing.log
[task 2018-01-21T11:54:53.473Z] 11:54:53 INFO - Call getUserMedia for {"audio":{"autoGainControl":false,"echoCancellation":false,"noiseSuppression":false},"video":true}
[task 2018-01-21T11:54:53.474Z] 11:54:53 INFO - Buffered messages logged at 11:48:27
[task 2018-01-21T11:54:53.475Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | One audio track shall be present
[task 2018-01-21T11:54:53.476Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | Track kind should be audio
[task 2018-01-21T11:54:53.477Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | Track id should be defined
[task 2018-01-21T11:54:53.478Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | Track should not be muted
[task 2018-01-21T11:54:53.479Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | One video track shall be present
[task 2018-01-21T11:54:53.480Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | Track kind should be video
[task 2018-01-21T11:54:53.481Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | Track id should be defined
[task 2018-01-21T11:54:53.482Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | Track should not be muted
[task 2018-01-21T11:54:53.483Z] 11:54:53 INFO - Waiting for ICE connected...
[task 2018-01-21T11:54:53.484Z] 11:54:53 INFO - Adding ICE candidate: {"candidate":"candidate:0 1 UDP 2122252543 172.17.0.4 36323 typ host","sdpMid":"sdparta_0","sdpMLineIndex":0}
[task 2018-01-21T11:54:53.485Z] 11:54:53 INFO - Adding ICE candidate: {"candidate":"candidate:1 1 TCP 2105524479 172.17.0.4 9 typ host tcptype active","sdpMid":"sdparta_0","sdpMLineIndex":0}
[task 2018-01-21T11:54:53.486Z] 11:54:53 INFO - Adding ICE candidate: {"candidate":"candidate:0 2 UDP 2122252542 172.17.0.4 50431 typ host","sdpMid":"sdparta_0","sdpMLineIndex":0}
[task 2018-01-21T11:54:53.487Z] 11:54:53 INFO - Adding ICE candidate: {"candidate":"candidate:1 2 TCP 2105524478 172.17.0.4 9 typ host tcptype active","sdpMid":"sdparta_0","sdpMLineIndex":0}
[task 2018-01-21T11:54:53.488Z] 11:54:53 INFO - Adding ICE candidate: null
[task 2018-01-21T11:54:53.489Z] 11:54:53 INFO - Adding ICE candidate: {"candidate":"candidate:0 1 UDP 2122252543 172.17.0.4 53959 typ host","sdpMid":"sdparta_0","sdpMLineIndex":0}
[task 2018-01-21T11:54:53.490Z] 11:54:53 INFO - Adding ICE candidate: {"candidate":"candidate:1 1 TCP 2105524479 172.17.0.4 9 typ host tcptype active","sdpMid":"sdparta_0","sdpMLineIndex":0}
[task 2018-01-21T11:54:53.491Z] 11:54:53 INFO - Buffered messages logged at 11:48:28
[task 2018-01-21T11:54:53.491Z] 11:54:53 INFO - Adding ICE candidate: null
[task 2018-01-21T11:54:53.493Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | ICE connected
[task 2018-01-21T11:54:53.494Z] 11:54:53 INFO - Waiting for ICE connected...
[task 2018-01-21T11:54:53.495Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | ICE connected
[task 2018-01-21T11:54:53.495Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | track should not be muted after onunmute
[task 2018-01-21T11:54:53.496Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | track should not be muted after onunmute
[task 2018-01-21T11:54:53.497Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | track should not be muted after onunmute
[task 2018-01-21T11:54:53.498Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | track should not be muted after onunmute
[task 2018-01-21T11:54:53.499Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | track should be muted after onmute
[task 2018-01-21T11:54:53.500Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | track should be muted after onmute
[task 2018-01-21T11:54:53.501Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | track should be muted after onmute
[task 2018-01-21T11:54:53.502Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | track should be muted after onmute
[task 2018-01-21T11:54:53.503Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | track should not be muted after onunmute
[task 2018-01-21T11:54:53.504Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | track should not be muted after onunmute
[task 2018-01-21T11:54:53.505Z] 11:54:53 INFO - Adding ICE candidate: null
[task 2018-01-21T11:54:53.506Z] 11:54:53 INFO - Adding ICE candidate: null
[task 2018-01-21T11:54:53.507Z] 11:54:53 INFO - Adding ICE candidate: null
[task 2018-01-21T11:54:53.508Z] 11:54:53 INFO - Adding ICE candidate: null
[task 2018-01-21T11:54:53.509Z] 11:54:53 INFO - Adding ICE candidate: null
[task 2018-01-21T11:54:53.509Z] 11:54:53 INFO - Buffered messages logged at 11:48:29
[task 2018-01-21T11:54:53.510Z] 11:54:53 INFO - Adding ICE candidate: null
[task 2018-01-21T11:54:53.511Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | track should not be muted after onunmute
[task 2018-01-21T11:54:53.512Z] 11:54:53 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_transceivers.html | track should not be muted after onunmute
[task 2018-01-21T11:54:53.513Z] 11:54:53 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_transceivers.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2018-01-21T11:54:53.514Z] 11:54:53 INFO - Buffered messages finished
[task 2018-01-21T11:54:53.515Z] 11:54:53 ERROR - TEST-UNEXPECTED-TIMEOUT | dom/media/tests/mochitest/test_peerConnection_transceivers.html | application timed out after 370 seconds with no output
[task 2018-01-21T11:54:53.516Z] 11:54:53 ERROR - Force-terminating active process(es).
[task 2018-01-21T11:54:53.517Z] 11:54:53 INFO - Determining child pids from psutil...
[task 2018-01-21T11:54:53.518Z] 11:54:53 INFO - [3261]
[task 2018-01-21T11:54:53.519Z] 11:54:53 INFO - ==> process 3159 launched child process 3182
[task 2018-01-21T11:54:53.520Z] 11:54:53 INFO - ==> process 3159 launched child process 3210
[task 2018-01-21T11:54:53.521Z] 11:54:53 INFO - ==> process 3159 launched child process 3261
[task 2018-01-21T11:54:53.522Z] 11:54:53 INFO - ==> process 3159 launched child process 4158
[task 2018-01-21T11:54:53.523Z] 11:54:53 INFO - ==> process 3159 launched child process 4578
[task 2018-01-21T11:54:53.523Z] 11:54:53 INFO - ==> process 3159 launched child process 5019
[task 2018-01-21T11:54:53.524Z] 11:54:53 INFO - ==> process 3159 launched child process 5497
[task 2018-01-21T11:54:53.526Z] 11:54:53 INFO - Found child pids: set([4578, 3210, 3182, 5497, 5019, 3261, 4158])
[task 2018-01-21T11:54:53.527Z] 11:54:53 INFO - Failed to get child procs
[task 2018-01-21T11:54:53.528Z] 11:54:53 INFO - Killing process: 4578
[task 2018-01-21T11:54:53.529Z] 11:54:53 INFO - TEST-INFO | started process screentopng
[task 2018-01-21T11:54:53.682Z] 11:54:53 INFO - TEST-INFO | screentopng: exit 0
[task 2018-01-21T11:54:53.683Z] 11:54:53 INFO - Can't trigger Breakpad, process no longer exists
[task 2018-01-21T11:54:53.685Z] 11:54:53 INFO - Killing process: 3210
[task 2018-01-21T11:54:53.689Z] 11:54:53 INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-01-21T11:54:53.690Z] 11:54:53 INFO - Can't trigger Breakpad, process no longer exists
[task 2018-01-21T11:54:53.691Z] 11:54:53 INFO - Killing process: 3182
[task 2018-01-21T11:54:53.692Z] 11:54:53 INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-01-21T11:54:53.693Z] 11:54:53 INFO - Can't trigger Breakpad, process no longer exists
[task 2018-01-21T11:54:53.694Z] 11:54:53 INFO - Killing process: 5497
[task 2018-01-21T11:54:53.695Z] 11:54:53 INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-01-21T11:54:53.696Z] 11:54:53 INFO - Can't trigger Breakpad, process no longer exists
[task 2018-01-21T11:54:53.697Z] 11:54:53 INFO - Killing process: 5019
[task 2018-01-21T11:54:53.698Z] 11:54:53 INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-01-21T11:54:53.699Z] 11:54:53 INFO - Can't trigger Breakpad, process no longer exists
[task 2018-01-21T11:54:53.700Z] 11:54:53 INFO - Killing process: 3261
[task 2018-01-21T11:54:53.701Z] 11:54:53 INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-01-21T11:54:53.702Z] 11:54:53 INFO - Killing process: 4158
[task 2018-01-21T11:54:53.704Z] 11:54:53 INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-01-21T11:54:53.705Z] 11:54:53 INFO - Can't trigger Breakpad, process no longer exists
[task 2018-01-21T11:54:53.707Z] 11:54:53 INFO - Killing process: 3159
[task 2018-01-21T11:54:53.709Z] 11:54:53 INFO - Not taking screenshot here: see the one that was previously logged
[task 2018-01-21T11:54:53.935Z] 11:54:53 INFO - psutil found pid 3159 dead
[task 2018-01-21T11:54:54.085Z] 11:54:54 WARNING - runtests.py | Failed to get app exit code - running/crashed?
[task 2018-01-21T11:54:54.087Z] 11:54:54 INFO - TEST-INFO | Main app process: exit 0
[task 2018-01-21T11:54:54.088Z] 11:54:54 INFO - runtests.py | Application ran for: 0:19:39.144087
[task 2018-01-21T11:54:54.089Z] 11:54:54 INFO - zombiecheck | Reading PID log: /tmp/tmpXa3Ftqpidlog
[task 2018-01-21T11:54:54.091Z] 11:54:54 INFO - ==> process 3159 launched child process 3182
[task 2018-01-21T11:54:54.093Z] 11:54:54 INFO - ==> process 3159 launched child process 3210
[task 2018-01-21T11:54:54.093Z] 11:54:54 INFO - ==> process 3159 launched child process 3261
[task 2018-01-21T11:54:54.094Z] 11:54:54 INFO - ==> process 3159 launched child process 4158
[task 2018-01-21T11:54:54.094Z] 11:54:54 INFO - ==> process 3159 launched child process 4578
[task 2018-01-21T11:54:54.094Z] 11:54:54 INFO - ==> process 3159 launched child process 5019
[task 2018-01-21T11:54:54.095Z] 11:54:54 INFO - ==> process 3159 launched child process 5497
[task 2018-01-21T11:54:54.095Z] 11:54:54 INFO - zombiecheck | Checking for orphan process with PID: 4578
[task 2018-01-21T11:54:54.095Z] 11:54:54 INFO - zombiecheck | Checking for orphan process with PID: 3210
[task 2018-01-21T11:54:54.095Z] 11:54:54 INFO - zombiecheck | Checking for orphan process with PID: 3182
[task 2018-01-21T11:54:54.096Z] 11:54:54 INFO - zombiecheck | Checking for orphan process with PID: 5497
[task 2018-01-21T11:54:54.096Z] 11:54:54 INFO - zombiecheck | Checking for orphan process with PID: 5019
[task 2018-01-21T11:54:54.096Z] 11:54:54 INFO - zombiecheck | Checking for orphan process with PID: 3261
[task 2018-01-21T11:54:54.097Z] 11:54:54 INFO - zombiecheck | Checking for orphan process with PID: 4158
[task 2018-01-21T11:54:54.097Z] 11:54:54 INFO - mozcrash Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmpUOcupg.mozrunner/minidumps/55c6f926-fa54-cd5e-cafd-00056bb7794e.dmp /builds/worker/workspace/build/symbols
[task 2018-01-21T11:55:03.102Z] 11:55:03 INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/55c6f926-fa54-cd5e-cafd-00056bb7794e.dmp
[task 2018-01-21T11:55:03.103Z] 11:55:03 INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/55c6f926-fa54-cd5e-cafd-00056bb7794e.extra
[task 2018-01-21T11:55:03.165Z] 11:55:03 INFO - PROCESS-CRASH | Main app process exited normally | application crashed [@ linux-gate.so + 0xcd9]
[task 2018-01-21T11:55:03.166Z] 11:55:03 INFO - Crash dump filename: /tmp/tmpUOcupg.mozrunner/minidumps/55c6f926-fa54-cd5e-cafd-00056bb7794e.dmp
[task 2018-01-21T11:55:03.167Z] 11:55:03 INFO - Operating system: Linux
[task 2018-01-21T11:55:03.168Z] 11:55:03 INFO - 0.0.0 Linux 4.4.0-98-generic #121~14.04.1-Ubuntu SMP Wed Oct 11 11:54:55 UTC 2017 x86_64
[task 2018-01-21T11:55:03.168Z] 11:55:03 INFO - CPU: x86
[task 2018-01-21T11:55:03.169Z] 11:55:03 INFO - GenuineIntel family 6 model 62 stepping 4
[task 2018-01-21T11:55:03.170Z] 11:55:03 INFO - 2 CPUs
[task 2018-01-21T11:55:03.171Z] 11:55:03 INFO -
[task 2018-01-21T11:55:03.172Z] 11:55:03 INFO - GPU: UNKNOWN
[task 2018-01-21T11:55:03.173Z] 11:55:03 INFO -
[task 2018-01-21T11:55:03.174Z] 11:55:03 INFO - Crash reason: SIGABRT
[task 2018-01-21T11:55:03.175Z] 11:55:03 INFO - Crash address: 0x3c6
[task 2018-01-21T11:55:03.176Z] 11:55:03 INFO - Process uptime: not available
[task 2018-01-21T11:55:03.177Z] 11:55:03 INFO -
[task 2018-01-21T11:55:03.177Z] 11:55:03 INFO - Thread 0 (crashed)
[task 2018-01-21T11:55:03.179Z] 11:55:03 INFO - 0 linux-gate.so + 0xcd9
[task 2018-01-21T11:55:03.180Z] 11:55:03 INFO - eip = 0xf76ffcd9 esp = 0xff922a84 ebp = 0xff922af8 ebx = 0xe42c3aa0
[task 2018-01-21T11:55:03.181Z] 11:55:03 INFO - esi = 0xf71437b0 edi = 0xe42c3aa0 eax = 0xfffffffc ecx = 0x00000004
[task 2018-01-21T11:55:03.182Z] 11:55:03 INFO - edx = 0xffffffff efl = 0x00000296
[task 2018-01-21T11:55:03.183Z] 11:55:03 INFO - Found by: given as instruction pointer in context
[task 2018-01-21T11:55:03.183Z] 11:55:03 INFO - 1 libglib-2.0.so.0.4800.2 + 0x4711c
[task 2018-01-21T11:55:03.184Z] 11:55:03 INFO - eip = 0xf5da811c esp = 0xff922b00 ebp = 0x00000004
[task 2018-01-21T11:55:03.185Z] 11:55:03 INFO - Found by: previous frame's frame pointer
[task 2018-01-21T11:55:03.186Z] 11:55:03 INFO - 2 libglib-2.0.so.0.4800.2 + 0x8cfec
[task 2018-01-21T11:55:03.187Z] 11:55:03 INFO - eip = 0xf5dedfec esp = 0xff922b10 ebp = 0x00000004
[task 2018-01-21T11:55:03.188Z] 11:55:03 INFO - Found by: stack scanning
[task 2018-01-21T11:55:03.189Z] 11:55:03 INFO - 3 libxul.so!IsFrameContentNodeInNamespace [nsNativeThemeGTK.cpp:9fe69ff0762d : 115 + 0x4]
[task 2018-01-21T11:55:03.190Z] 11:55:03 INFO - eip = 0xf131a943 esp = 0xff922b14 ebp = 0x00000004
[task 2018-01-21T11:55:03.190Z] 11:55:03 INFO - Found by: stack scanning
[task 2018-01-21T11:55:03.191Z] 11:55:03 INFO - 4 libglib-2.0.so.0.4800.2 + 0x1285b0
[task 2018-01-21T11:55:03.192Z] 11:55:03 INFO - eip = 0xf5e895b0 esp = 0xff922b24 ebp = 0x00000004
[task 2018-01-21T11:55:03.193Z] 11:55:03 INFO - Found by: stack scanning
[task 2018-01-21T11:55:03.194Z] 11:55:03 INFO - 5 libglib-2.0.so.0.4800.2 + 0x46f8d
[task 2018-01-21T11:55:03.195Z] 11:55:03 INFO - eip = 0xf5da7f8d esp = 0xff922b3c ebp = 0xff922b58
[task 2018-01-21T11:55:03.196Z] 11:55:03 INFO - Found by: stack scanning
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•7 years ago
|
Depends on: gUM_timeout
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 9•7 years ago
|
||
This has gotten extremely bad sometime around the 1st or 2nd.
I see lots of failures like the following:
[task 2018-03-03T16:32:19.138Z] 16:32:19 INFO - PROCESS-CRASH | Main app process exited normally | application crashed [@ mozilla::Atomic<bool, (mozilla::MemoryOrdering)2u, void>::operator bool]
Comment hidden (Intermittent Failures Robot) |
Comment 11•7 years ago
|
||
Seems permanently orange for me on Linux x64 QuantumRender debug: https://treeherder.mozilla.org/#/jobs?repo=try&revision=b1dbb3f07cc7311b186e642aa8a8e1774088f8a6&selectedJob=166630581
Logs show PROCESS-CRASH messages like the one in comment 9.
Resetting the priority to get this reconsidered -- something has changed.
Priority: P5 → --
Comment 12•7 years ago
|
||
Raising priority. Byron has been looking at intermittent failures lately and is active on this bug, but I'll leave a needinfo just in case :)
Rank: 15
Flags: needinfo?(docfaraday)
Priority: -- → P2
Comment 13•7 years ago
|
||
Bug 1443803 seems to be a regression due to bug 1440040 according to pehrsons. I am looking into it right now, but this is deep in unfamiliar code for me.
Flags: needinfo?(docfaraday)
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 19•7 years ago
|
||
Created a disable patch in case it is needed.
Assignee: nobody → aiakab
Attachment #8958021 -
Flags: review?(jmaher)
Comment 20•7 years ago
|
||
Comment on attachment 8958021 [details] [diff] [review]
Disabled on Linux jsdcov platform
Review of attachment 8958021 [details] [diff] [review]:
-----------------------------------------------------------------
please adjust the comment, this says | on Linux jsdcov platform|, and it should be | on Linux debug platform|
Attachment #8958021 -
Flags: review?(jmaher) → review+
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 23•7 years ago
|
||
Updated the patch, corrected the message.
Attachment #8958813 -
Flags: review?(jmaher)
Updated•7 years ago
|
Attachment #8958813 -
Flags: review?(jmaher) → review+
Updated•7 years ago
|
Keywords: checkin-needed,
leave-open
Comment 24•7 years ago
|
||
Pushed by aiakab@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/700bfd08642d
disabling test_peerConnection_transceivers.html on Linux debug platform r=jmaher
Keywords: checkin-needed
Comment 25•7 years ago
|
||
bugherder |
Comment hidden (Intermittent Failures Robot) |
Updated•7 years ago
|
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 31•6 years ago
|
||
The leave-open keyword is there and there is no activity for 6 months.
:aiakab, maybe it's time to close this bug?
Flags: needinfo?(aiakab)
Updated•6 years ago
|
Flags: needinfo?(aiakab)
Updated•6 years ago
|
Keywords: leave-open
You need to log in
before you can comment on or make changes to this bug.
Description
•