Closed
Bug 1727060
Opened 4 years ago
Closed 4 years ago
Intermittent TEST-UNEXPECTED-TIMEOUT | /video-rvfc/request-video-frame-callback.html | Test video.rVFC does not stop when switching sources. - Test timed out
Categories
(Testing :: web-platform-tests, defect, P5)
Testing
web-platform-tests
Tracking
(Not tracked)
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: smolnar [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=349229475&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/INQixbsoTdiLktX-pTCDnA/runs/0/artifacts/public/logs/live_backing.log
INFO - TEST-START | /video-rvfc/request-video-frame-callback.html
[task 2021-08-23T10:11:25.403Z] 10:11:25 INFO - Closing window 5f323a69-f53f-4775-805d-f64e0cefafbd
[task 2021-08-23T10:11:57.531Z] 10:11:57 INFO - PID 9789 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-08-23T10:11:57.546Z] 10:11:57 INFO - PID 9789 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-08-23T10:11:57.546Z] 10:11:57 INFO - PID 9789 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-08-23T10:11:57.546Z] 10:11:57 INFO - PID 9789 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-08-23T10:11:57.634Z] 10:11:57 INFO - PID 9789 | Timecard created 1629713455.141118
<...>
INFO - TEST-FAIL | /video-rvfc/request-video-frame-callback.html | Test we can register a video.rVFC callback. - video.requestVideoFrameCallback is not a function
[task 2021-08-23T10:11:57.699Z] 10:11:57 INFO - @http://web-platform.test:8000/video-rvfc/request-video-frame-callback.html:25:20
[task 2021-08-23T10:11:57.699Z] 10:11:57 INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:2087:25
[task 2021-08-23T10:11:57.699Z] 10:11:57 INFO - async_test@http://web-platform.test:8000/resources/testharness.js:594:34
[task 2021-08-23T10:11:57.699Z] 10:11:57 INFO - @http://web-platform.test:8000/video-rvfc/request-video-frame-callback.html:21:11
[task 2021-08-23T10:11:57.699Z] 10:11:57 INFO - TEST-FAIL | /video-rvfc/request-video-frame-callback.html | Test video.rVFC callbacks run before window.rAF callbacks. - video.requestVideoFrameCallback is not a function
[task 2021-08-23T10:11:57.699Z] 10:11:57 INFO - @http://web-platform.test:8000/video-rvfc/request-video-frame-callback.html:44:11
[task 2021-08-23T10:11:57.699Z] 10:11:57 INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:2087:25
[task 2021-08-23T10:11:57.699Z] 10:11:57 INFO - async_test@http://web-platform.test:8000/resources/testharness.js:594:34
[task 2021-08-23T10:11:57.699Z] 10:11:57 INFO - @http://web-platform.test:8000/video-rvfc/request-video-frame-callback.html:40:11
[task 2021-08-23T10:11:57.699Z] 10:11:57 INFO - TEST-FAIL | /video-rvfc/request-video-frame-callback.html | Test we can cancel a video.rVFC request. - video.requestVideoFrameCallback is not a function
[task 2021-08-23T10:11:57.699Z] 10:11:57 INFO - @http://web-platform.test:8000/video-rvfc/request-video-frame-callback.html:64:20
[task 2021-08-23T10:11:57.699Z] 10:11:57 INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:2087:25
[task 2021-08-23T10:11:57.699Z] 10:11:57 INFO - async_test@http://web-platform.test:8000/resources/testharness.js:594:34
[task 2021-08-23T10:11:57.699Z] 10:11:57 INFO - @http://web-platform.test:8000/video-rvfc/request-video-frame-callback.html:60:11
[task 2021-08-23T10:11:57.699Z] 10:11:57 INFO - TEST-FAIL | /video-rvfc/request-video-frame-callback.html | Test invalid calls to the video.rVFC API. - video.cancelVideoFrameCallback is not a function
[task 2021-08-23T10:11:57.700Z] 10:11:57 INFO - @http://web-platform.test:8000/video-rvfc/request-video-frame-callback.html:98:11
[task 2021-08-23T10:11:57.700Z] 10:11:57 INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:2087:25
[task 2021-08-23T10:11:57.700Z] 10:11:57 INFO - test@http://web-platform.test:8000/resources/testharness.js:557:30
[task 2021-08-23T10:11:57.700Z] 10:11:57 INFO - @http://web-platform.test:8000/video-rvfc/request-video-frame-callback.html:85:5
[task 2021-08-23T10:11:57.700Z] 10:11:57 INFO - TEST-UNEXPECTED-TIMEOUT | /video-rvfc/request-video-frame-callback.html | Test video.rVFC does not stop when switching sources. - Test timed out
[task 2021-08-23T10:11:57.700Z] 10:11:57 INFO - TEST-INFO | expected FAIL
[task 2021-08-23T10:11:57.701Z] 10:11:57 INFO - TEST-UNEXPECTED-TIMEOUT | /video-rvfc/request-video-frame-callback.html | expected OK
[task 2021-08-23T10:11:57.701Z] 10:11:57 INFO - TEST-INFO took 32308ms
[task 2021-08-23T10:11:57.701Z] 10:11:57 INFO - Restarting browser for new test group
[task 2021-08-23T10:11:57.707Z] 10:11:57 INFO - PID 9789 | 0.869707 | 0.002655 | Add Ice Candidate | PeerConnectionImpl.cpp:1529 | AddIceCandidate
[task 2021-08-23T10:11:57.707Z] 10:11:57 INFO - PID 9789 | 0.873908 | 0.004201 | Look up mDNS name | PeerConnectionImpl.cpp:1817 | StampTimecard
[task 2021-08-23T10:11:57.708Z] 10:11:57 INFO - PID 9789 | 0.877003 | 0.003095 | Add Ice Candidate | PeerConnectionImpl.cpp:1529 | AddIceCandidate
[task 2021-08-23T10:11:57.709Z] 10:11:57 INFO - PID 9789 | 0.878123 | 0.001120 | Done looking up mDNS name | PeerConnectionImpl.cpp:1817 | StampTimecard
[task 2021-08-23T10:11:57.709Z] 10:11:57 INFO - PID 9789 | 0.882669 | 0.004546 | Done looking up mDNS name | PeerConnectionImpl.cpp:1817 | StampTimecard
[task 2021-08-23T10:11:57.710Z] 10:11:57 INFO - PID 9789 | 0.886342 | 0.003673 | Done looking up mDNS name | PeerConnectionImpl.cpp:1817 | StampTimecard
[task 2021-08-23T10:11:57.710Z] 10:11:57 INFO - PID 9789 | 0.886502 | 0.000160 | Look up mDNS name | PeerConnectionImpl.cpp:1817 | StampTimecard
[task 2021-08-23T10:11:57.711Z] 10:11:57 INFO - PID 9789 | 0.892715 | 0.006213 | Add Ice Candidate | PeerConnectionImpl.cpp:1529 | AddIceCandidate
[task 2021-08-23T10:11:57.711Z] 10:11:57 INFO - PID 9789 | 0.893504 | 0.000789 | Ice state: checking | PeerConnectionImpl.cpp:2481 | IceConnectionStateChange
[task 2021-08-23T10:11:57.712Z] 10:11:57 INFO - PID 9789 | 0.902059 | 0.008555 | Look up mDNS name | PeerConnectionImpl.cpp:1817 | StampTimecard
[task 2021-08-23T10:11:57.713Z] 10:11:57 INFO - PID 9789 | 0.904186 | 0.002127 | Add Ice Candidate | PeerConnectionImpl.cpp:1529 | AddIceCandidate
[task 2021-08-23T10:11:57.713Z] 10:11:57 INFO - PID 9789 | 0.948822 | 0.044636 | Look up mDNS name | PeerConnectionImpl.cpp:1817 | StampTimecard
INFO - PID 9789 | 0.958956 | 0.010134 | Add Ice Candidate | PeerConnectionImpl.cpp:1529 | AddIceCandidate
[task 2021-08-23T10:11:57.714Z] 10:11:57 INFO - PID 9789 | 0.959925 | 0.000969 | Done looking up mDNS name | PeerConnectionImpl.cpp:1817 | StampTimecard
[task 2021-08-23T10:11:57.715Z] 10:11:57 INFO - PID 9789 | 0.959985 | 0.000060 | Done looking up mDNS name | PeerConnectionImpl.cpp:1817 | StampTimecard
[task 2021-08-23T10:11:57.715Z] 10:11:57 INFO - PID 9789 | 0.980933 | 0.020948 | Ice state: connected | PeerConnectionImpl.cpp:2484 | IceConnectionStateChange
[task 2021-08-23T10:11:57.716Z] 10:11:57 INFO - PID 9789 | 0.986210 | 0.005277 | Done looking up mDNS name | PeerConnectionImpl.cpp:1817 | StampTimecard
[task 2021-08-23T10:11:57.716Z] 10:11:57 INFO - PID 9789 | 0.986384 | 0.000174 | Look up mDNS name | PeerConnectionImpl.cpp:1817 | StampTimecard
[task 2021-08-23T10:11:57.717Z] 10:11:57 INFO - PID 9789 | 0.987803 | 0.001419 | Add Ice Candidate | PeerConnectionImpl.cpp:1529 | AddIceCandidate
[task 2021-08-23T10:11:57.717Z] 10:11:57 INFO - PID 9789 | 1.015987 | 0.028184 | Look up mDNS name | PeerConnectionImpl.cpp:1817 | StampTimecard
[task 2021-08-23T10:11:57.718Z] 10:11:57 INFO - PID 9789 | 1.018802 | 0.002815 | Add Ice Candidate | PeerConnectionImpl.cpp:1529 | AddIceCandidate
[task 2021-08-23T10:11:57.719Z] 10:11:57 INFO - PID 9789 | 1.020169 | 0.001367 | Done looking up mDNS name | PeerConnectionImpl.cpp:1817 | StampTimecard
[task 2021-08-23T10:11:57.719Z] 10:11:57 INFO - PID 9789 | 1.022140 | 0.001971 | Done looking up mDNS name | PeerConnectionImpl.cpp:1817 | StampTimecard
[task 2021-08-23T10:11:57.720Z] 10:11:57 INFO - PID 9789 | 1.022306 | 0.000166 | Look up mDNS name | PeerConnectionImpl.cpp:1817 | StampTimecard
[task 2021-08-23T10:11:57.720Z] 10:11:57 INFO - PID 9789 | 1.024260 | 0.001954 | Add Ice Candidate | PeerConnectionImpl.cpp:1529 | AddIceCandidate
[task 2021-08-23T10:11:57.721Z] 10:11:57 INFO - PID 9789 | 62.451908 | 61.427648 | Destructor Invoked | PeerConnectionImpl.cpp:341 | ~PeerConnectionImpl
[task 2021-08-23T10:11:57.721Z] 10:11:57 INFO - PID 9789 | [Child 10208: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:362: PeerConnectionCtx is already gone. Ignoring...
[task 2021-08-23T10:11:57.722Z] 10:11:57 INFO - PID 9789 | [Child 10208: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:366: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for {794fa77a-05df-4963-b536-fa78f30cf5d5}
[task 2021-08-23T10:11:57.723Z] 10:11:57 INFO - PID 9789 | 1629713517691 Marionette INFO Stopped listening on port 50947
[task 2021-08-23T10:11:57.784Z] 10:11:57 INFO - PID 9789 | [Child 10208: Main Thread]: E/signaling [main|MediaTransportHandler] MediaTransportHandler.cpp:685: Unable to dispatch to STS: why has the XPCOM shutdown handler not been invoked?
[task 2021-08-23T10:11:57.784Z] 10:11:57 INFO - PID 9789 | [Child 10208: Main Thread]: E/signaling [main|MediaTransportHandler] MediaTransportHandler.cpp:685: Unable to dispatch to STS: why has the XPCOM shutdown handler not been invoked?
[task 2021-08-23T10:11:58.601Z] 10:11:58 INFO - PID 9789 | JavaScript error: resource:///modules/Interactions.jsm, line 230: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIUserIdleService.removeIdleObserver]
[task 2021-08-23T10:11:58.603Z] 10:11:58 INFO - PID 9789 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-08-23T10:11:58.645Z] 10:11:58 INFO - PID 9789 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-08-23T10:11:58.736Z] 10:11:58 INFO - PID 9789 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-08-23T10:11:58.736Z] 10:11:58 INFO - PID 9789 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-08-23T10:11:58.736Z] 10:11:58 INFO - PID 9789 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-08-23T10:12:04.677Z] 10:12:04 INFO - PID 9789 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-08-23T10:12:07.269Z] 10:12:07 INFO - Browser exited with return code 0
[task 2021-08-23T10:12:07.272Z] 10:12:07 INFO - Closing logging queue
[task 2021-08-23T10:12:07.272Z] 10:12:07 INFO - queue closed
[task 2021-08-23T10:12:07.284Z] 10:12:07 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2021-08-23T10:12:07.284Z] 10:12:07 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox --marionette about:blank -profile /tmp/tmpjmdp9xkk
[task 2021-08-23T10:12:07.295Z] 10:12:07 INFO - PID 9988 | 1629713429915 Marionette INFO Marionette enabled
[task 2021-08-23T10:12:07.296Z] 10:12:07 INFO - PID 9988 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/tmpw8_rcl8n/search.json.mozlz4", (void 0)))
[task 2021-08-23T10:12:07.296Z] 10:12:07 INFO - PID 9988 | 1629713463276 Marionette INFO Listening on port 56006
[task 2021-08-23T10:12:07.296Z] 10:12:07 INFO - Starting runner
[task 2021-08-23T10:12:09.344Z] 10:12:09 INFO - TEST-START | /web-animations/timing-model/time-transformations/transformed-progress.html
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•4 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•