1398678 - Firefox has much longer seek latency than Chrome does when playing Twitch video

Status: NEW

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

Description

[JW Wang [:jwwang] [:jw_wang]]

repro steps:

1. play 'https://www.twitch.tv/videos/173757028'
2. seek to a random position that is far away from the current position.
3. observe how long the seeking takes.

result:
FF is much slower in seeking than Chrome.

some other notes:
1. Twitch serves MSE streams for this video.
2. The logs show that seek is rejected with WAITING_FOR_DATA several times:

2017-09-11 06:23:27.287584 UTC - [MediaPlayback #1]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected reason=WAITING_FOR_DATA type=1
2017-09-11 06:23:39.219573 UTC - [MediaPlayback #2]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected wait promise resolved type=1
2017-09-11 06:23:39.226126 UTC - [MediaPlayback #1]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected reason=WAITING_FOR_DATA type=1
2017-09-11 06:23:39.338294 UTC - [MediaPlayback #1]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected wait promise resolved type=1
2017-09-11 06:23:39.342093 UTC - [MediaPlayback #1]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected reason=WAITING_FOR_DATA type=1
2017-09-11 06:23:41.165112 UTC - [MediaPlayback #2]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected wait promise resolved type=1
2017-09-11 06:23:41.167877 UTC - [MediaPlayback #1]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected reason=WAITING_FOR_DATA type=1
2017-09-11 06:23:41.178444 UTC - [MediaPlayback #2]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected wait promise resolved type=1
2017-09-11 06:23:41.182908 UTC - [MediaPlayback #1]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected reason=WAITING_FOR_DATA type=1
2017-09-11 06:23:41.956715 UTC - [MediaPlayback #3]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected wait promise resolved type=1
2017-09-11 06:23:41.960573 UTC - [MediaPlayback #1]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected reason=WAITING_FOR_DATA type=1
2017-09-11 06:23:41.971743 UTC - [MediaPlayback #2]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected wait promise resolved type=1
2017-09-11 06:23:41.974665 UTC - [MediaPlayback #1]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected reason=WAITING_FOR_DATA type=1
2017-09-11 06:23:43.989391 UTC - [MediaPlayback #1]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected wait promise resolved type=1
2017-09-11 06:23:43.992150 UTC - [MediaPlayback #1]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected reason=WAITING_FOR_DATA type=1
2017-09-11 06:23:44.006468 UTC - [MediaPlayback #2]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected wait promise resolved type=1
2017-09-11 06:23:44.011888 UTC - [MediaPlayback #1]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected reason=WAITING_FOR_DATA type=1
2017-09-11 06:23:44.522063 UTC - [MediaPlayback #2]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected wait promise resolved type=1
2017-09-11 06:23:44.525508 UTC - [MediaPlayback #1]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected reason=WAITING_FOR_DATA type=1
2017-09-11 06:23:44.536945 UTC - [MediaPlayback #2]: D/MediaDecoder Decoder=0x7f1ddceba110 state=SEEKING OnSeekRejected wait promise resolved type=1

Comment 1

[JW Wang [:jwwang] [:jw_wang]]

Note I can repro this issue only on Linux.

Comment 2

[Jean-Yves Avenard [:jya]]

the WAITING_FOR_DATA states is entirely dependent on what their JS player is doing.

sounds like after seeking, twitch doesn't load the required data at the right location.

The MediaDecoder log however are useless to determine what is happening.

The MediaDemuxer:5,MediaSourceSamples:5,MediaSource:5 is what you need.

twitch had issues properly tagging their keyframes, it could be that they think they are giving us a keyframe (which would allow us to seek), but really they aren't.

the log options above would show if that was the problem.

Comment 3

[JW Wang [:jwwang] [:jw_wang]]

Attachment: logs.txt.child-1

logs between seek begins and seek ends.

Comment 4

[Jean-Yves Avenard [:jya]]

Oh my, this is terrible.
Must contact twitch to tell them how poorly muxed their content is...
There are gaps between every single samples, this is going to make buffered range use a massive amount of memory :(
As each sample makes for a separated range.

Comment 5

[Chris Peterson [:cpeterson]]

(In reply to Jean-Yves Avenard [:jya] from comment #4)
> Must contact twitch to tell them how poorly muxed their content is...

I emailed our Twitch dev contacts and CC'd you.

Why don't the sample gaps cause a problem in Chrome?

Comment 6

[Jean-Yves Avenard [:jya]]

Oh, the gaps aren't what's causing the seek issue. I haven't investigated that part yet.

The gaps cause to have one range per sample, so you end up working with arrays with a huge amount of intervals. The search into such array (required to know where to insert any new samples) is in O(N), removal is in O(2N) etc...

Comment 7

[Jean-Yves Avenard [:jya]]

(In reply to Chris Peterson [:cpeterson] from comment #5)
> Why don't the sample gaps cause a problem in Chrome?

Chrome incorrectly report the buffered range as they don't use the right timestamps (edge is the same): Chrome said this bug will be fixed very soon.
You would see the same issue with Safari.

Comment 8

[Jean-Yves Avenard [:jya]]

going to take a look today.

Twitch is a popular site, and the stream formatting here is very poor. see if we can do something about it.

Comment 9

[Jean-Yves Avenard [:jya]]

I can no longer reproduce the issue now.

While I do see gaps in the data, those are rare, nothing to worry about and they are ignored automatically as they are < 500ms.

It does look however that the segments are arriving out of order, which sometimes is what is causing the gaps.

Seeking is also very fast, typically under 1s here...

JW, do you still have the issue?

Otherwise, it could be because Twitch changed something in their encoding

Comment 10

[JW Wang [:jwwang] [:jw_wang]]

The issue is still present when I am watching: https://www.twitch.tv/videos/173757028.

Comment 11

[Alastor Wu [:alwu]]

I can still reproduce this issue on latest Nightly. On Firefox, seeking takes around 1~1.5s, but on Chrome, it takes around 0.5s.

Comment 12

[Alastor Wu [:alwu]]

Hmm no, I tested it again today by running a simple code, and I found after performing a lot of times of seeking, the time difference in Chrome and Firefox doesn't have a significant difference.

(Over seeking 20+ times) On Nightly, the average is 475.045 ms. On Release, the average is 485.071. On Chrome, the averag is 452.83. The test url I used is the one in comment 10.