The seekbar is incorrectly displaying FLAC's audio progress after loop

VERIFIED FIXED in Firefox 65

Status

()

defect
P2
normal
VERIFIED FIXED
9 months ago
3 months ago

People

(Reporter: emilghitta, Assigned: chunmin)

Tracking

(Depends on 1 bug, Blocks 2 bugs, {regression})

59 Branch
mozilla65
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox-esr52 unaffected, firefox-esr60 wontfix, firefox61 wontfix, firefox62 wontfix, firefox63 wontfix, firefox64- wontfix, firefox65 verified)

Details

Attachments

(4 attachments, 12 obsolete attachments)

578.43 KB, image/gif
Details
46 bytes, text/x-phabricator-request
Details | Review
46 bytes, text/x-phabricator-request
Details | Review
1.14 KB, text/html
Details
Reporter

Description

9 months ago
Posted image flacIssue.gif
[Affected versions]:
Firefox 63.0a1 (BuildId:20180831100058).
Firefox 62.0 (BuildId:20180827144429).
Firefox 61.0.2 (BuildId:20180807170231).
Firefox 60.1.0esr (BuildId:20180621121604).

[Affected platforms]:
Windows 10 64bit.
macOS 10.13.4
Ubuntu 16.04 64bit.

[Steps to reproduce]:
1. Launch Firefox.
2. Access the following link: shorturl.at/lyEG9
3. Activate the loop option.
4. Play the audio.
5. Seek the audio at 2:52 and let it finish.

[Expected result]:
The audio starts over and the seekbar's position is at 0:00.

[Actual result]:
The audio starts over but the seekbar's position is at 0:40.

[Regression range]:
This seems to be a regression.

Last good revision: 8de0513ff33dbd095d218775952a65c55f9cb77b
First bad revision: a612dc93c5989ea0d12123b721940312f7a04cfc

12:24.23 INFO: Pushlog:
https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=8de0513ff33dbd095d218775952a65c55f9cb77b&tochange=a612dc93c5989ea0d12123b721940312f7a04cfc

[Notes]
For further information regarding this issue please observe the attached screencast.
Please note that, sometimes, the seekbar is not jumping back to 0:00 nor 0:40 (remains stuck at the end) but the audio loops successfully.
Reporter

Comment 1

9 months ago
Hi Chun,

I'm not sure, but from the generated pushlog Bug 654787 may have caused this regression.

Can you please have a look?

Thanks!
Blocks: 654787
Flags: needinfo?(cchang)
Priority: -- → P2
Assignee

Comment 2

8 months ago
(In reply to Emil Ghitta, QA [:emilghitta] from comment #0)
Thanks for the testing!

> [Steps to reproduce]:
> 1. Launch Firefox.
> 2. Access the following link: shorturl.at/lyEG9
I can not find any audio element in the link. Can you update it?
> 3. Activate the loop option.
> 4. Play the audio.
> 5. Seek the audio at 2:52 and let it finish.
Flags: needinfo?(cchang) → needinfo?(emil.ghitta)
Reporter

Comment 3

8 months ago
Sure thing Chun. Try: https://goo.gl/tuporf
Flags: needinfo?(emil.ghitta)
Assignee

Comment 4

8 months ago
(In reply to Emil Ghitta, QA [:emilghitta] from comment #3)
> Sure thing Chun. Try: https://goo.gl/tuporf
Thanks the update. Nice catch!
Assignee: nobody → cchang
Assignee

Comment 5

8 months ago
The root cause is that the time data in last audio frame extracted by `FlacTrackDemuxer`[0] is wrong. 

By running `$ MOZ_LOG="MediaDemuxer:5" ./mach run https://goo.gl/tuporf`, we can get the time info of the last audio frame in the `FlacTrackDemuxer`[1]. The log is attached below[2]. In brief, the time of the last audio frame is smaller than its previous one. The time of the second last frame is around 174, but the time of the last audio frame is around 133. 

When looping is on, the time is always adjusted by `ReaderProxy::AdjustByLooping`. `ReaderProxy::AdjustByLooping` uses the time of the last audio frame as the ending time of the stream to adjust the playback position[3]. The correct ending time of the audio is around 174, but we use the incorrect time 133 to calculate it. That's why the time on the playback bar is wrong.

After the looped audio starts, the clock time `T`[4] is over 174. The adjusted time should be calculated by `T = T % 174`. However, we use `T = T % 133` so the playback bar starts from around 40.




[0] https://searchfox.org/mozilla-central/rev/de7676288a78b70d2b9927c79493adbf294faad5/dom/media/flac/FlacDemuxer.cpp#858
[1] https://searchfox.org/mozilla-central/rev/de7676288a78b70d2b9927c79493adbf294faad5/dom/media/flac/FlacDemuxer.cpp#939
[2] Log for `FlacTrackDemuxer`
-------------------------

...

(second last audio frame)

[Child 2618: MediaPDecoder #1]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] GetSamples(1) Begin offset=14934303 mParsedFramesDuration=174.602448 mTotalFrameLen=14673230
[Child 2618: MediaPDecoder #1]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] FindNext() Begin offset=14934303 mParsedFramesDuration=174.602448 mTotalFrameLen=14673230
[Child 2618: MediaPDecoder #1]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] FindNext() End time=174.602448 offset=14934320 mParsedFramesDuration=174.602448 mTotalFrameLen=14673245
[Child 2618: MediaPDecoder #1]: D/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] GetNextFrame() Begin(time=174.602448 offset=14934296 size=15)
[Child 2618: MediaPDecoder #1]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] GetSamples() End mSamples.Length=1 aNumSamples=-1 offset=14934320 mParsedFramesDuration=174.602448 mTotalFrameLen=14673245

(last audio frame)

[Child 2618: MediaPDecoder #1]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] GetSamples(1) Begin offset=14934320 mParsedFramesDuration=174.602448 mTotalFrameLen=14673245
[Child 2618: MediaPDecoder #1]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] FindNext() Begin offset=14934320 mParsedFramesDuration=174.602448 mTotalFrameLen=14673245
[Child 2618: MediaPDecoder #1]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] FindNext() End time=133.305034 offset=14934328 mParsedFramesDuration=174.602448 mTotalFrameLen=14673262
[Child 2618: MediaPDecoder #1]: D/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] GetNextFrame() Begin(time=133.305034 offset=14934311 size=17)
[Child 2618: MediaPDecoder #1]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] GetSamples() End mSamples.Length=1 aNumSamples=-1 offset=14934328 mParsedFramesDuration=174.602448 mTotalFrameLen=14673262

(EOS: end of stream)

[Child 2618: MediaPDecoder #1]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] GetSamples(1) Begin offset=14934328 mParsedFramesDuration=174.602448 mTotalFrameLen=14673262
[Child 2618: MediaPDecoder #1]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] FindNext() Begin offset=14934328 mParsedFramesDuration=174.602448 mTotalFrameLen=14673262
[Child 2618: MediaPDecoder #1]: D/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] GetNextFrame() EOS
[Child 2618: MediaPDecoder #1]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] GetSamples() End mSamples.Length=0 aNumSamples=0 offset=14934328 mParsedFramesDuration=174.602448 mTotalFrameLen=14673262

(start looping)

[Child 2618: MediaPDecoder #2]: D/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] Reset()
[Child 2618: MediaPDecoder #2]: D/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] Reset()
[Child 2618: MediaPDecoder #2]: D/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] FastSeek(0.000000) avgFrameLen=84038.122994 mParsedFramesDuration=174.602448 offset=261066
[Child 2618: MediaPDecoder #2]: D/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] ScanUntil(0.000000 avgFrameLen=84038.122994 mParsedFramesDuration=174.602448 offset=0
[Child 2618: MediaPDecoder #2]: D/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] FastSeek(0.000000) avgFrameLen=84038.122994 mParsedFramesDuration=174.602448 offset=261066
[Child 2618: MediaPDecoder #2]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] GetSamples(1) Begin offset=261066 mParsedFramesDuration=174.602448 mTotalFrameLen=14673262
[Child 2618: MediaPDecoder #2]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] FindNext() Begin offset=261066 mParsedFramesDuration=174.602448 mTotalFrameLen=14673262
[Child 2618: MediaPDecoder #2]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] FindNext() End time=0.000000 offset=264217 mParsedFramesDuration=174.602448 mTotalFrameLen=14673262
[Child 2618: MediaPDecoder #2]: D/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] GetNextFrame() Begin(time=0.000000 offset=261066 size=3145)
[Child 2618: MediaPDecoder #2]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] GetSamples() End mSamples.Length=1 aNumSamples=-1 offset=264217 mParsedFramesDuration=174.602448 mTotalFrameLen=14673262

[Child 2618: MediaPDecoder #1]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] GetSamples(1) Begin offset=264217 mParsedFramesDuration=174.602448 mTotalFrameLen=14673262
[Child 2618: MediaPDecoder #1]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] FindNext() Begin offset=264217 mParsedFramesDuration=174.602448 mTotalFrameLen=14673262
[Child 2618: MediaPDecoder #1]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] FindNext() End time=0.104489 offset=267387 mParsedFramesDuration=174.602448 mTotalFrameLen=14673262
[Child 2618: MediaPDecoder #1]: D/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] GetNextFrame() Begin(time=0.104489 offset=264211 size=3170)
[Child 2618: MediaPDecoder #1]: V/MediaDemuxer FlacTrackDemuxer[0x11c7fb2e0] GetSamples() End mSamples.Length=1 aNumSamples=-1 offset=267387 mParsedFramesDuration=174.602448 mTotalFrameLen=14673262

...

-------------------------

[3] https://searchfox.org/mozilla-central/rev/de7676288a78b70d2b9927c79493adbf294faad5/dom/media/ReaderProxy.cpp#317
[4] https://searchfox.org/mozilla-central/rev/de7676288a78b70d2b9927c79493adbf294faad5/dom/media/MediaDecoderStateMachine.cpp#3547-3551
Assignee

Comment 6

8 months ago
This file is marked `fixed-blocksize`[0] at its header[1] but the blocksize of the last frame is less than its previous one. It's actually *variable*! Not sure if it's common. The sample-index is calculated by `frame-count * blocksize`, where frame-count is a regularly counted in this file from 0 to n. The sample-index of last audio is smaller than its previous one since its blocksize is too small. The time of the media-data is calculated by the sample-index so we get a wrong value.

[0] https://xiph.org/flac/format.html#frame_header_notes
[1] https://searchfox.org/mozilla-central/rev/de7676288a78b70d2b9927c79493adbf294faad5/dom/media/flac/FlacDemuxer.cpp#56,112
Assignee

Comment 7

8 months ago
This patch can solve the problem for this file. Haven't test it on other files yet.
Assignee

Comment 8

8 months ago
(In reply to Chun-Min Chang[:chunmin] from comment #7)
> Created attachment 9008899 [details] [diff] [review]
> Use index of previous frame to calculate the minimal index
> 
> This patch can solve the problem for this file. Haven't test it on other
> files yet.

The index for the samples in a fixed-blocksize stream is calculated by `frames_number(n) * blocksize(n)`. Unfortunately, the blocksize of the last frame might be smaller than its previous one. For example, the last blocksize for one stream with fixed blocksize 100 might be 80. If it has 10 frames(from number 0 to 9), then its last index will be calculated by 9 * 80 = 720. It's real value should be 8*100 + 80 = 880. `frames_number(n) * blocksize(n)` works fine from 0 to 8: 0*100 = 0, 1*100 = 100, 2*100=200, ... etc, but doesn't work for 9.

A safer way to calculate this is by accumulation: 0, 0 + 100 = 100, 100+100 = 200, ..., 700+100=800, 800+80=880. To do this, we need to know the previous index value and accumulate it with current blocksize. However, it doesn't work when seeking. The last index we have is very likely neither the index of previous frame, nor the index of next frame. In that case, we need to re-calculate the index from the info of the raw data by `frames_number(n) * blocksize(n)`. Thus, the approach now is:

index = frames_number(n) * blocksize(n)
if not seeking:
  minimal_index = previous_index + blocksize(n)
  index = max(index, minimal_index)

The minimal_index above is an accumulated index value. It's used to make sure index >= minimal_index. When seeking, the index is calculated by the raw info, as usual. I guess it works for most of the time. But if it's possible to seek to the last frame, then the `index` is still a wrong value.
Assignee

Comment 10

8 months ago
TODO: Correct the 

Still use `mLastAudioEndTime` as `mLoopingOffset` now. If `mLastAudioEndTime` is a wrong value (returned from Demuxer), then we cannot get a correct offset to adjust the AudioData[0]. In that case, the MediaQueue::Duration() will get a wrong value[1]. It will affect the calculation about how many data we need to decode in advance.

[0] https://searchfox.org/mozilla-central/rev/dd965445ec47fbf3cee566eff93b301666bda0e1/dom/media/ReaderProxy.cpp#62-64
[1] https://searchfox.org/mozilla-central/rev/dd965445ec47fbf3cee566eff93b301666bda0e1/dom/media/MediaQueue.h#107
Assignee

Updated

8 months ago
See Also: → 1421505
Comment on attachment 9010751 [details]
Bug 1487797 - Part 2: Make sure the time of audio data are monotonically increasing

Jean-Yves Avenard [:jya] has approved the revision.
Attachment #9010751 - Flags: review+
Attachment #9010751 - Attachment description: Bug 1487797 - Part 2: Make sure the time of audio data are increasing → Bug 1487797 - Part 2: Make sure the time of audio data are monotonically increasing
Attachment #9011085 - Attachment is obsolete: true
Attachment #9010752 - Attachment description: Bug 1487797 - Part 3: Make sure the time of media data in media queue are increasing → Bug 1487797 - Part 3: Make sure the time of media data in media queue are monotonically increasing
Comment on attachment 9010752 [details]
Bug 1487797 - Part 3: Make sure the time of media data in media queue are monotonically increasing

Jean-Yves Avenard [:jya] has approved the revision.
Attachment #9010752 - Flags: review+
Comment on attachment 9010750 [details]
Bug 1487797 - Part 1: Set end-time, instead of start-time, to the last-audio-end-time in ReaderProxy

Jean-Yves Avenard [:jya] has approved the revision.
Attachment #9010750 - Flags: review+
Assignee

Comment 18

8 months ago
I am going to move the part 3 to another bug since it may be out of topic. To make sure the seekbar works while looping, part 1 and 2 should be enough.
Attachment #9010752 - Attachment is obsolete: true
Assignee

Updated

8 months ago
Keywords: checkin-needed

Comment 19

8 months ago
Pushed by aiakab@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/c629e51dda10
Part 1: Set end-time, instead of start-time, to the last-audio-end-time in ReaderProxy r=jya
Keywords: checkin-needed

Comment 20

8 months ago
Pushed by aiakab@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/e9549537063a
Part 2: Make sure the time of audio data are monotonically increasing r=jya

Comment 21

8 months ago
Pushed by aiakab@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/5dcf18a41fc2
"The seekbar is incorrectly displaying FLAC's audio progress after loop" []
https://hg.mozilla.org/integration/mozilla-inbound/rev/38cba148ab07
Part 1: Set end-time instead of start-time to the last-audio-time in ReaderProxy
https://hg.mozilla.org/integration/mozilla-inbound/rev/74ade0131f9f
Part 2: Make sure the duration in ReaderProxy is equal to or larger than the duration in MDSM
https://hg.mozilla.org/mozilla-central/rev/c629e51dda10
https://hg.mozilla.org/mozilla-central/rev/e9549537063a
Status: NEW → RESOLVED
Last Resolved: 8 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla64
Assignee

Comment 24

8 months ago
The pushed patches were WIP patches. They are not the patches reviewed.
According the comment 23, I think the correct patches were landed.
Flags: needinfo?(cchang)
Assignee

Updated

8 months ago
Blocks: 1494762
Assignee

Updated

8 months ago
See Also: → 1496474
Reporter

Updated

8 months ago
Depends on: 1496474

Updated

7 months ago
Depends on: 1497629
Assignee

Updated

7 months ago
Backed out 2 changesets (Bug 1487797) for introducing regressions a=backout

Backout: https://hg.mozilla.org/mozilla-central/rev/b569fad5a51ff187f7a03e584ba3e5910e0f19
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Target Milestone: mozilla64 → ---
Why was this nominated for tracking?
Flags: needinfo?(nerli)
Assignee

Comment 27

7 months ago
Posted patch [WIP] Draft (obsolete) — Splinter Review
- Use bool to track if we are in seeking
- Cancel the data promise requested before firing seeking
- Replace lastAudioEndTime by maxAudioEndTime
- Fallback to normal looping if user seeks to EOS directly

TODO: 
- Add tests
Attachment #9008899 - Attachment is obsolete: true
Attachment #9008959 - Attachment is obsolete: true
Attachment #9008963 - Attachment is obsolete: true
Attachment #9010750 - Attachment is obsolete: true
Attachment #9010751 - Attachment is obsolete: true
Assignee

Comment 30

7 months ago
I found most of the flac files in this website have the same issue. 

http://www.hyperion-records.co.uk/testfiles.asp

The last end time in those files are all smaller than their previous one. Their blocksizes in the last frames are smaller then their previous one, even if it's marked `fixed`. Our calculation for index counts on the blocksize from the frame we parse, but the blocksize is not always true.
(In reply to Julien Cristau [:jcristau] from comment #26)
> Why was this nominated for tracking?

This backout was requested by :jya in the #developers room:
"jya> Aryx: can we backout the change from bug 1487797?
12:08 AM we won't have time to properly fix it for 64 and it introduced regressions"
Flags: needinfo?(nerli)
Assignee

Comment 32

7 months ago
Posted audio test.flac (obsolete) —
Assignee

Comment 33

7 months ago
Posted file test.html (obsolete) —
Assignee

Comment 34

7 months ago
Posted file test.html (obsolete) —
(In reply to Chun-Min Chang[:chunmin] from comment #27)
> TODO: 
> - Add tests
I tried to make a file by ffmpeg. However, the generated files are broken. They are not seekable and lead to decoder errors. Use the source provided by the bug report directly for now.
Attachment #9018410 - Attachment is obsolete: true
Attachment #9018414 - Attachment is obsolete: true
Assignee

Comment 35

7 months ago
Comment on attachment 9017691 [details] [diff] [review]
[WIP] Draft

Move to bug 1496474. Only fix the flac's indexing problem here.
Attachment #9017691 - Attachment is obsolete: true
Sounds like this is for 65 then.
Attachment #9018077 - Attachment description: Bug 1487797: P2. Make sure the sample index of FLAC's frame is mono-increasing. → Bug 1487797: P2. Make sure the sample index of FLAC's frame is monotonically increasing.
Attachment #9018076 - Attachment description: Bug 1487797: P1. Move sample index from FrameHeader to Frame. → Bug 1487797 - P1. Move sample index from FrameHeader to Frame.
Attachment #9018077 - Attachment description: Bug 1487797: P2. Make sure the sample index of FLAC's frame is monotonically increasing. → Bug 1487797 - P2. Make sure the sample index of FLAC's frame is monotonically increasing.
Assignee

Comment 38

7 months ago
Posted file test.html (obsolete) —
Attachment #9018417 - Attachment is obsolete: true
Assignee

Comment 39

7 months ago
Posted file test.html
Attachment #9019752 - Attachment is obsolete: true
Assignee

Updated

7 months ago
Keywords: checkin-needed

Comment 40

7 months ago
Pushed by rvandermeulen@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/e8ea25fee7b2
P1. Move sample index from FrameHeader to Frame. r=jya
https://hg.mozilla.org/integration/autoland/rev/b50e31d758b1
P2. Make sure the sample index of FLAC's frame is monotonically increasing. r=jya
Keywords: checkin-needed

Comment 41

7 months ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/e8ea25fee7b2
https://hg.mozilla.org/mozilla-central/rev/b50e31d758b1
Status: REOPENED → RESOLVED
Last Resolved: 8 months ago7 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla65
Flags: qe-verify+
I reproduced this issue using Fx 63.0a1, build ID: 20180831100058, on Windows 10 x64, Ubuntu 18.04 x64 and macOS x 10.13.

I can confirm this issue is fixed, I verified using Fx 65.0b8, build ID:  20190103150357, on Windows 10 x64, macOS X 10.13 and Ubuntu 18.04 x64.
Status: RESOLVED → VERIFIED
Flags: qe-verify+

Updated

3 months ago
Depends on: 1528265
You need to log in before you can comment on or make changes to this bug.