1593757 - Intermittent /mediacapture-streams/MediaStream-MediaElement-srcObject.https.html | Tests that a media element with an assigned MediaStream does not start advancing currentTime until potentially playing - assert_equals: currentTime...

Status: RESOLVED DUPLICATE of bug 1577505

(Core :: Audio/Video: MediaStreamGraph, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: dluca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=274410766&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/bkog-TAXTb-oaiFA8vURjQ/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/bkog-TAXTb-oaiFA8vURjQ/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

---

INFO - TEST-PASS | /mediacapture-streams/MediaStream-MediaElement-srcObject.https.html | Tests that a media element with an assigned MediaStream starts its timeline at 0 regardless of when the MediaStream was created 
[task 2019-11-04T15:52:04.811Z] 15:52:04     INFO - TEST-PASS | /mediacapture-streams/MediaStream-MediaElement-srcObject.https.html | Tests that a media element with an assigned MediaStream does not advance currentTime while paused 
[task 2019-11-04T15:52:04.811Z] 15:52:04     INFO - TEST-UNEXPECTED-FAIL | /mediacapture-streams/MediaStream-MediaElement-srcObject.https.html | Tests that a media element with an assigned MediaStream does not start advancing currentTime until potentially playing - assert_equals: currentTime has not advanced yet expected 0 but got 0.011609977324263039
[task 2019-11-04T15:52:04.811Z] 15:52:04     INFO - @https://web-platform.test:8443/mediacapture-streams/MediaStream-MediaElement-srcObject.https.html:302:16
[task 2019-11-04T15:52:04.811Z] 15:52:04     INFO - async*Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:1908:25
[task 2019-11-04T15:52:04.811Z] 15:52:04     INFO - promise_test/tests.promise_tests</<@https://web-platform.test:8443/resources/testharness.js:591:36
[task 2019-11-04T15:52:04.811Z] 15:52:04     INFO - promise_test/tests.promise_tests<@https://web-platform.test:8443/resources/testharness.js:590:20
[task 2019-11-04T15:52:04.811Z] 15:52:04     INFO - promise callback*promise_test@https://web-platform.test:8443/resources/testharness.js:589:51
[task 2019-11-04T15:52:04.811Z] 15:52:04     INFO - @https://web-platform.test:8443/mediacapture-streams/MediaStream-MediaElement-srcObject.https.html:278:13
[task 2019-11-04T15:52:04.812Z] 15:52:04     INFO - .
[task 2019-11-04T15:52:04.812Z] 15:52:04     INFO - TEST-OK | /mediacapture-streams/MediaStream-MediaElement-srcObject.https.html | took 3980ms
[task 2019-11-04T15:52:04.812Z] 15:52:04     INFO - No more tests
[task 2019-11-04T15:52:04.821Z] 15:52:04     INFO - PID 5314 | 1572882724816	Marionette	INFO	Stopped listening on port 44952
[task 2019-11-04T15:52:05.575Z] 15:52:05     INFO - Browser exited with return code 0
[task 2019-11-04T15:52:05.575Z] 15:52:05     INFO - PROCESS LEAKS None
[task 2019-11-04T15:52:05.577Z] 15:52:05     INFO - Closing logging queue
[task 2019-11-04T15:52:05.577Z] 15:52:05     INFO - queue closed
[task 2019-11-04T15:52:05.577Z] 15:52:05     INFO - PROCESS LEAKS None
[task 2019-11-04T15:52:05.579Z] 15:52:05     INFO - Got 1 unexpected results
[task 2019-11-04T15:52:05.579Z] 15:52:05     INFO - SUITE-END | took 9s
[task 2019-11-04T15:52:05.656Z] 15:52:05     INFO - Closing logging queue
[task 2019-11-04T15:52:05.656Z] 15:52:05     INFO - queue closed
[task 2019-11-04T15:52:05.663Z] 15:52:05     INFO - ## All results ##
[task 2019-11-04T15:52:05.664Z] 15:52:05     INFO - 
[task 2019-11-04T15:52:05.664Z] 15:52:05     INFO - ### /mediacapture-streams/MediaStream-MediaElement-srcObject.https.html ###
[task 2019-11-04T15:52:05.665Z] 15:52:05     INFO - |                                                              Subtest                                                              |         Results          |                                          Messages                                         |
[task 2019-11-04T15:52:05.666Z] 15:52:05     INFO - |-----------------------------------------------------------------------------------------------------------------------------------|--------------------------|-------------------------------------------------------------------------------------------|
[task 2019-11-04T15:52:05.666Z] 15:52:05     INFO - |                                                                                                                                   | OK                       |                                                                                           |
[task 2019-11-04T15:52:05.666Z] 15:52:05     INFO - | `Tests that a MediaStream can be assigned to a video element with srcObject`                                                      | PASS                     |                                                                                           |
[task 2019-11-04T15:52:05.667Z] 15:52:05     INFO - | `Tests that a MediaStream assigned to a video element is not seekable`                                                            | PASS                     |                                                                                           |
[task 2019-11-04T15:52:05.668Z] 15:52:05     INFO - | `Tests that a MediaStream assigned to a video element is in readyState HAVE_NOTHING initially`                                    | PASS                     |                                                                                           |
[task 2019-11-04T15:52:05.668Z] 15:52:05     INFO - | `Tests that a MediaStream assigned to a video element has expected duration`                                                      | PASS                     |                                                                                           |
[task 2019-11-04T15:52:05.669Z] 15:52:05     INFO - | `Tests that a video element with a MediaStream assigned is not preloaded`                                                         | PASS                     |                                                                                           |
[task 2019-11-04T15:52:05.669Z] 15:52:05     INFO - | `Tests that a video element with a MediaStream assigned ignores playbackRate attributes (defaultPlaybackRate is identical)`       | PASS                     |                                                                                           |
[task 2019-11-04T15:52:05.670Z] 15:52:05     INFO - | `Tests that a video element with a MediaStream assigned ignores playbackRate attributes (defaultPlaybackRate is different)`       | PASS                     |                                                                                           |
[task 2019-11-04T15:52:05.670Z] 15:52:05     INFO - | `Tests that a media element with an assigned MediaStream reports the played attribute as expected`                                | PASS                     |                                                                                           |
[task 2019-11-04T15:52:05.671Z] 15:52:05     INFO - | `Tests that a media element with an assigned MediaStream reports the currentTime attribute as expected`                           | PASS                     |                                                                                           |
[task 2019-11-04T15:52:05.672Z] 15:52:05     INFO - | `Tests that a media element with an assigned MediaStream starts its timeline at 0 regardless of when the MediaStream was created` | PASS                     |                                                                                           |
[task 2019-11-04T15:52:05.672Z] 15:52:05     INFO - | `Tests that a media element with an assigned MediaStream does not advance currentTime while paused`                               | PASS                     |                                                                                           |
[task 2019-11-04T15:52:05.672Z] 15:52:05     INFO - | `Tests that a media element with an assigned MediaStream does not start advancing currentTime until potentially playing`          | **FAIL: 1/5, PASS: 4/5** | `assert_equals: currentTime has not advanced yet expected 0 but got 0.011609977324263039` |
[task 2019-11-04T15:52:05.673Z] 15:52:05     INFO - | `Tests that the loop attribute has no effect on a media element with an assigned MediaStream`                                     | PASS                     |                                                                                           |
[task 2019-11-04T15:52:05.673Z] 15:52:05     INFO - 
[task 2019-11-04T15:52:05.673Z] 15:52:05     INFO - ## Unstable results ##
[task 2019-11-04T15:52:05.673Z] 15:52:05     INFO - 
[task 2019-11-04T15:52:05.675Z] 15:52:05     INFO - |                                  Test                                 |                                                         Subtest                                                          |         Results          |                                          Messages                                         |
[task 2019-11-04T15:52:05.675Z] 15:52:05     INFO - |-----------------------------------------------------------------------|--------------------------------------------------------------------------------------------------------------------------|--------------------------|-------------------------------------------------------------------------------------------|
[task 2019-11-04T15:52:05.675Z] 15:52:05     INFO - | `/mediacapture-streams/MediaStream-MediaElement-srcObject.https.html` | `Tests that a media element with an assigned MediaStream does not start advancing currentTime until potentially playing` | **FAIL: 1/5, PASS: 4/5** | `assert_equals: currentTime has not advanced yet expected 0 but got 0.011609977324263039` |
[task 2019-11-04T15:52:05.675Z] 15:52:05     INFO - 
[task 2019-11-04T15:52:05.676Z] 15:52:05     INFO - ::: Running tests in a loop 10 times : PASS
[task 2019-11-04T15:52:05.676Z] 15:52:05     INFO - ::: Running tests in a loop with restarts 5 times : PASS
[task 2019-11-04T15:52:05.676Z] 15:52:05     INFO - ::: Running tests in a loop 10 times with flags chaos_mode_flags=3 : PASS
[task 2019-11-04T15:52:05.678Z] 15:52:05     INFO - ::: Running tests in a loop with restarts 5 times with flags chaos_mode_flags=3 : FAIL
[task 2019-11-04T15:52:05.678Z] 15:52:05     INFO - :::
[task 2019-11-04T15:52:05.678Z] 15:52:05    ERROR - ::: Test verification FAIL
[task 2019-11-04T15:52:05.678Z] 15:52:05     INFO - :::
[task 2019-11-04T15:52:05.988Z] 15:52:05    ERROR - Return code: 1
[task 2019-11-04T15:52:05.989Z] 15:52:05    ERROR - Got 1 unexpected statuses
[task 2019-11-04T15:52:05.989Z] 15:52:05    ERROR - # TBPL FAILURE #
[task 2019-11-04T15:52:05.989Z] 15:52:05  WARNING - setting return code to 2
[task 2019-11-04T15:52:05.989Z] 15:52:05    ERROR - TinderboxPrint: Per-test run of .../MediaStream-MediaElement-srcObject.https.html<br/>: FAILURE
[task 2019-11-04T15:52:05.990Z] 15:52:05     INFO - Running post-action listener: _package_coverage_data
[task 2019-11-04T15:52:05.990Z] 15:52:05     INFO - Running post-action listener: _resource_record_post_action
[task 2019-11-04T15:52:05.990Z] 15:52:05     INFO - Running post-action listener: process_java_coverage_data
[task 2019-11-04T15:52:05.990Z] 15:52:05     INFO - Running post-action listener: stop_device
[task 2019-11-04T15:52:05.990Z] 15:52:05     INFO - [mozharness: 2019-11-04 15:52:05.990594Z] Finished run-tests step (success)
[task 2019-11-04T15:52:05.990Z] 15:52:05     INFO - Running post-run listener: _resource_record_post_run
[task 2019-11-04T15:52:06.123Z] 15:52:06     INFO - Total resource usage - Wall time: 197s; CPU: 8.0%; Read bytes: 352256; Write bytes: 1506406400; Read time: 0; Write time: 379216
[task 2019-11-04T15:52:06.123Z] 15:52:06     INFO - TinderboxPrint: CPU usage<br/>7.7%
[task 2019-11-04T15:52:06.123Z] 15:52:06     INFO - TinderboxPrint: I/O read bytes / time<br/>352,256 / 0
[task 2019-11-04T15:52:06.123Z] 15:52:06     INFO - TinderboxPrint: I/O write bytes / time<br/>1,506,406,400 / 379,216
[task 2019-11-04T15:52:06.123Z] 15:52:06     INFO - TinderboxPrint: CPU idle<br/>1,440.0 (92.0%)
[task 2019-11-04T15:52:06.124Z] 15:52:06     INFO - TinderboxPrint: CPU nice<br/>31.9 (2.0%)
[task 2019-11-04T15:52:06.124Z] 15:52:06     INFO - TinderboxPrint: CPU system<br/>23.8 (1.5%)
[task 2019-11-04T15:52:06.124Z] 15:52:06     INFO - TinderboxPrint: CPU user<br/>64.1 (4.1%)
[task 2019-11-04T15:52:06.124Z] 15:52:06     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2019-11-04T15:52:06.124Z] 15:52:06     INFO - pull - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2019-11-04T15:52:06.124Z] 15:52:06     INFO - verify-device - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2019-11-04T15:52:06.125Z] 15:52:06     INFO - install - Wall time: 11s; CPU: 13.0%; Read bytes: 0; Write bytes: 91856896; Read time: 0; Write time: 130484
[task 2019-11-04T15:52:06.128Z] 15:52:06     INFO - run-tests - Wall time: 187s; CPU: 7.0%; Read bytes: 352256; Write bytes: 1320964096; Read time: 0; Write time: 232584
[task 2019-11-04T15:52:06.214Z] 15:52:06  WARNING - returning nonzero exit status 2

Comment 1

[Dorel Luca [:dluca]]

Likely started on this push:
https://treeherder.mozilla.org/#/jobs?repo=autoland&group_state=expanded&resultStatus=testfailed%2Cbusted%2Cexception&classifiedState=unclassified&revision=a81df2957c097309ea213774fe83adfa629b0a6f

Comment 2

[Intermittent Failures Robot]

48 failures in 4850 pushes (0.01 failures/push) were associated with this bug in the last 7 days.

This is the #37 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 27
• mozilla-central: 12
• mozilla-inbound: 5
• try: 4

Platform breakdown:

• linux64: 14
• linux64-shippable: 14
• android-em-7-0-x86_64: 4
• linux32-shippable: 8
• windows10-64: 2
• linux64-qr: 1
• windows10-64-ccov: 2
• macosx1014-64: 2
• linux64-shippable-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1593757&startday=2019-11-04&endday=2019-11-10&tree=all

Comment 3

[Oana Pop-Rus]

There are 43 total failures in the last 7 days on:

*debug: macosx1014-64, windows10-64
*opt: linux64-shippable
*asan: linux64

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

Comment 4

[Intermittent Failures Robot]

18 failures in 4207 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 14
• mozilla-central: 2
• try: 2

Platform breakdown:

• android-em-7-0-x86_64: 1
• linux64-shippable: 5
• linux64: 4
• linux32-shippable: 3
• windows10-64-qr: 1
• macosx1014-64: 3
• windows10-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1593757&startday=2019-11-11&endday=2019-11-17&tree=all

Comment 5

[Andreas Pehrson [:pehrsons]]

This has been fixed by a followup push to bug 1577505.