Closed Bug 1594029 Opened 5 years ago Closed 2 years ago

Intermittent dom/media/test/test_streams_element_capture_reset.html | Got 0.25541950113378686, expected at least 0.266; checking vout.currentTime at first 'ended' event

Categories

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

Product:
Core
Component:
Audio/Video: Playback
Type:
defect

Tracking

()

Status:
RESOLVED DUPLICATE of bug 1776955
Tracking Flags:
Tracking Status
firefox82 --- affected

People

(Reporter: intermittent-bug-filer, Unassigned, NeedInfo)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell disabled][stockwell unknown])

Attachments

(2 files)

Bug 1594029 - disable test_streams_element_capture_reset.html for frequent failures r=#intermittent-reviewers
47 bytes, text/x-phabricator-request
Details | Review
Bug 1594029 - Update media element capture_reset test to expect wall-clock durations. r?bryce
47 bytes, text/x-phabricator-request
Details | Review

Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=274622580&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/UUjrAVU_QBSQxxOWH6Ce7A/runs/0/artifacts/public/logs/live_backing.log

[task 2019-11-05T14:07:12.002Z] 14:07:12 INFO - TEST-OK | dom/media/test/test_streams_capture_origin.html | took 495ms
[task 2019-11-05T14:07:12.018Z] 14:07:12 INFO - TEST-START | dom/media/test/test_streams_element_capture_playback.html
[task 2019-11-05T14:07:12.380Z] 14:07:12 INFO - GECKO(2240) | MEMORY STAT | vsize 2723MB | residentFast 207MB | heapAllocated 36MB
[task 2019-11-05T14:07:12.381Z] 14:07:12 INFO - TEST-OK | dom/media/test/test_streams_element_capture_playback.html | took 370ms
[task 2019-11-05T14:07:12.403Z] 14:07:12 INFO - TEST-START | dom/media/test/test_streams_element_capture_reset.html
[task 2019-11-05T14:07:12.805Z] 14:07:12 INFO - TEST-INFO | started process screentopng
[task 2019-11-05T14:07:13.349Z] 14:07:13 INFO - TEST-INFO | screentopng: exit 0
[task 2019-11-05T14:07:13.349Z] 14:07:13 INFO - Buffered messages logged at 14:07:12
[task 2019-11-05T14:07:13.351Z] 14:07:13 INFO - TEST-PASS | dom/media/test/test_streams_element_capture_reset.html | A valid string reason is expected
[task 2019-11-05T14:07:13.351Z] 14:07:13 INFO - TEST-PASS | dom/media/test/test_streams_element_capture_reset.html | Reason cannot be empty
[task 2019-11-05T14:07:13.352Z] 14:07:13 INFO - 320x240.ogv GOT EVENT playing currentTime=0 paused=false ended=false readyState=4
[task 2019-11-05T14:07:13.353Z] 14:07:13 INFO - 320x240.ogv GOT EVENT timeupdate currentTime=0.033333 paused=false ended=false readyState=4
[task 2019-11-05T14:07:13.354Z] 14:07:13 INFO - Buffered messages finished
[task 2019-11-05T14:07:13.354Z] 14:07:13 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_streams_element_capture_reset.html | Got 0.25541950113378686, expected at least 0.266; checking vout.currentTime at first 'ended' event
[task 2019-11-05T14:07:13.355Z] 14:07:13 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2019-11-05T14:07:13.356Z] 14:07:13 INFO - isGreaterThanOrEqualEps@dom/media/test/test_streams_element_capture_reset.html:41:5
[task 2019-11-05T14:07:13.356Z] 14:07:13 INFO - ended@dom/media/test/test_streams_element_capture_reset.html:86:28
[task 2019-11-05T14:07:13.357Z] 14:07:13 INFO - EventListener.handleEvent*startTest@dom/media/test/test_streams_element_capture_reset.html:100:19
[task 2019-11-05T14:07:13.358Z] 14:07:13 INFO - @dom/media/test/test_streams_element_capture_reset.html:127:12
[task 2019-11-05T14:07:13.359Z] 14:07:13 INFO - TEST-PASS | dom/media/test/test_streams_element_capture_reset.html | Got 0.266664, expected at least 0.266; checking v.currentTime at first 'ended' event
[task 2019-11-05T14:07:13.359Z] 14:07:13 INFO - TEST-PASS | dom/media/test/test_streams_element_capture_reset.html | checking vout has not ended
[task 2019-11-05T14:07:13.360Z] 14:07:13 INFO - TEST-PASS | dom/media/test/test_streams_element_capture_reset.html | checking vout_untilended has actually ended

Assignee: nobody → btara
Status: NEW → ASSIGNED
Keywords: leave-open
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
Pushed by rmaries@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/806f2bed2faf
disable test_streams_element_capture_reset.html for frequent failures r=jmaher

Bryce the disable patch was made since this was a problem and is currently disabled.

Flags: needinfo?(bvandyk)

:jib, do you have any ideas about these failures?

Flags: needinfo?(bvandyk) → needinfo?(jib)

In the last 7 days there have been 20 occurrences on macosx1014-64 and windows10-64, build types debug and opt.

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

Bryce, could you, please, direct this to someone who can take a look?

Flags: needinfo?(bvandyk)
Whiteboard: [stockwell disabled] → [stockwell disabled][stockwell needswork:owner]

Andreas, do you have any insight into what's going on here?

Flags: needinfo?(bvandyk) → needinfo?(apehrson)

Of the 36 failures marked on try in the 7 days linked from comment 51, I see 2 that are indeed this bug, and 34 that are erroneously marked. Most of those 34 are not even mochitest-media ...

I don't think this is worth my time right now. The rate will go down next week.

Flags: needinfo?(apehrson)

Andreas, comment 51 was ~ 7 days old when you replied.

Looking at the filter now:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2020-08-30&endday=2020-09-06&tree=trunk&bug=1594029

This link shows mochitest-media (test suite or treeherder description contains mochitest-media).
All the failures (62 at this moment) are on Central and Autoland.

Could you, please, re-asses ?

Flags: needinfo?(apehrson)
Assignee: btara → apehrson
Flags: needinfo?(apehrson)

I caught this in rr, so then it was fairly simple.

The first frame that we render from 320x240.ogv that this test uses starts at t=0.133000s, and the last frame ends at t=0.266664s. Thus the wall-clock duration it takes to play this video is 0.133664s, while we are expecting 0.266s in the test. I'll update expectations here.

Pushed by pehrsons@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/08acb79d050e
Update media element capture_reset test to expect wall-clock durations. r=bryce

I always manage to miss the leave-open flag on bugs that have been going a while.

Status: ASSIGNED → RESOLVED
Closed: 4 years ago
status-firefox82: --- → fixed
Keywords: leave-open
Resolution: --- → FIXED
Assignee: apehrson → nobody
Status: REOPENED → RESOLVED
Closed: 4 years ago → 2 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: