Closed Bug 1441509 Opened 6 years ago Closed 6 years ago

Intermittent dom/media/test/test_seamless_looping.html | Could not find a peak: -Infinity db at 440Hz

Categories

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

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

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla61
Tracking Flags:
Tracking Status
firefox60 --- fixed
firefox61 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: padenot)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

Bug 1441509 - Start performing the analysis in test_seamless_looping.html after the second loop, to let things stabilize.
59 bytes, text/x-review-board-request
karlt
: review+
Details 
Filed by: ccoroiu [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=164583438&repo=autoland

https://queue.taskcluster.net/v1/task/UmayLzFNRQ-BU1Kei-CBJw/runs/0/artifacts/public/logs/live_backing.log

11:33:59     INFO -  41 INFO TEST-START | dom/media/test/test_seamless_looping.html
11:34:00     INFO -  TEST-INFO | started process screenshot
11:34:00     INFO -  TEST-INFO | screenshot: exit 0
11:34:00    ERROR -  42 INFO TEST-UNEXPECTED-FAIL | dom/media/test/test_seamless_looping.html | Could not find a peak: -Infinity db at 440Hz
11:34:00     INFO -      doAnalysis@dom/media/test/test_seamless_looping.html:24:5
11:34:00     INFO -      analysisCallback@dom/media/test/test_seamless_looping.html:128:9
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      window.onload@dom/media/test/test_seamless_looping.html:147:5
11:34:00     INFO -  43 INFO TEST-PASS | dom/media/test/test_seamless_looping.html | Found unexpected high frequency content: -Infinitydb at 1760Hz
11:34:00     INFO -  Not taking screenshot here: see the one that was previously logged
11:34:00    ERROR -  44 INFO TEST-UNEXPECTED-FAIL | dom/media/test/test_seamless_looping.html | Could not find a peak: -Infinity db at 440Hz
11:34:00     INFO -      doAnalysis@dom/media/test/test_seamless_looping.html:24:5
11:34:00     INFO -      analysisCallback@dom/media/test/test_seamless_looping.html:128:9
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      FrameRequestCallback*analysisCallback@dom/media/test/test_seamless_looping.html:143:7
11:34:00     INFO -      window.onload@dom/media/test/test_seamless_looping.html:147:5
11:34:00     INFO -  45 INFO TEST-PASS | dom/media/test/test_seamless_looping.html | Found unexpected high frequency content: -Infinitydb at 1760Hz
11:34:00     INFO -  46 INFO TEST-PASS | dom/media/test/test_seamless_looping.html | Could not find a peak: -16.664318084716797 db at 440Hz
11:34:00     INFO -  Not taking screenshot here: see the one that was previously logged
11:34:00    ERROR -  47 INFO TEST-UNEXPECTED-FAIL | dom/media/test/test_seamless_looping.html | Found unexpected high frequency content: -48.911495208740234db at 1760Hz
Kartikaya, the second mda chunk for Linux Quantumrender fails frequently and the failures often change with the push, see https://treeherder.mozilla.org/#/jobs?repo=autoland&tochange=5889cac267e270e4762fe579e8bec0b4b0920532&fromchange=18dd09f4f5ba3a2d1f0f11ae8fa192b5805b728c&filter-searchStr=linux%20quantumrender%20mda&selectedJob=166521006

Can you redirect this to the person in charge of video with Quantumrender, please?
Flags: needinfo?(bugmail)
Seems like most of the failures are on this test (test_seamless_looping) which has been intermittently failing on all platforms since it was added ~1 month ago. See also bug 1436826 and bug 1442399.

Paul, since you added the test, can you take a look? It looks like the test is buggy and for whatever reason it fails more frequently on linux64-qr.
Flags: needinfo?(bugmail) → needinfo?(padenot)
Karl, this fixes it for me on try. I can see locally, when I load my machine (using the `stress` command), that it takes a couple iterations to "stabilize" and then the transform is always clean. It think we might be seeing an under-run in between the `HTMLMediaElement` and Web Audio: the `HTMLMediaElement` is low on decoded data, the MSG pulls silence instead. Of course this creates a discontinuity and the analysis picks it up (as it should).

Mayeb the QR builds use the CPU a bit more, and the same happens for the windows7-32 we see failing above ?
Comment on attachment 8960252 [details]
Bug 1441509 - Start performing the analysis in test_seamless_looping.html after the second loop, to let things stabilize.

https://reviewboard.mozilla.org/r/229010/#review235336

I'm a bit skeptical about whether changing a delay from 1 second to 2 seconds will be helpful, but the change is otherwise harmless and so I don't see a problem with trying it if we have no better ideas.

::: dom/media/test/test_seamless_looping.html:126
(Diff revision 1)
>        // There is an unrelated click at start, skip it.
> -      if (loopCount != 0) {
> +      if (loopCount > 1) {

The comment no longer aligns with the test.
Can you add a comment please to explain the difference?
Attachment #8960252 - Flags: review?(karlt) → review+
(In reply to Paul Adenot (:padenot) from comment #8)
> Karl, this fixes it for me on try.

I haven't been able to find any changes to this test on try.
https://hg.mozilla.org/try/log/a4b4d8938c87/dom/media/test/test_seamless_looping.html

> I can see locally, when I load my machine
> (using the `stress` command), that it takes a couple iterations to
> "stabilize" and then the transform is always clean. It think we might be
> seeing an under-run in between the `HTMLMediaElement` and Web Audio: the
> `HTMLMediaElement` is low on decoded data, the MSG pulls silence instead. Of
> course this creates a discontinuity and the analysis picks it up (as it
> should).

I guess that an underrun on seeking is possible.
The report in comment 0 seems to have the test failing with silence in the
first analysis.  An underrun would need to be so long that none of the end of
the output from the previous loop remained in the analyser buffer.
Possible.

I can't think of an explanation for the subsequent loop to behave differently,
except perhaps clean-up from a previous test.

> Mayeb the QR builds use the CPU a bit more, and the same happens for the
> windows7-32 we see failing above ?

Debug builds don't seem to be represented, which may suggest this is not just
a CPU shortage.

I don't see anything in the test that ensures that the graph thread has
processed 2048 samples before fetching the first FFT.  We'd need need a delay
of almost 1 second in starting the graph for that to be a problem.  I don't
know how likely that is, but it would be easy to rule out by adding a test
that currentTime > 2048 samples before running the analysis.

None of this explains Bug 1442399, which seems to be failing on similar
platforms due to the audio element stalling altogether after some output.
(In reply to Karl Tomlinson (:karlt) from comment #10)
> None of this explains Bug 1442399, which seems to be failing on similar
> platforms due to the audio element stalling altogether after some output.

I was assuming the audio element was stalling because the seeked event had
not fired, but the consistency in the anaylser results suggests that the
MSG has stalled.
Blocks: 1436826
Pushed by paul@paul.cx:
https://hg.mozilla.org/integration/autoland/rev/7c500fbf0725
Start performing the analysis in test_seamless_looping.html after the second loop, to let things stabilize. r=karlt
https://hg.mozilla.org/mozilla-central/rev/7c500fbf0725
Status: NEW → RESOLVED
Closed: 6 years ago
status-firefox61: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla61
Assignee: nobody → padenot
status-firefox60: --- → affected
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: