I recorded a video when this happens

Deleted: 2016_04_26_10_17_53.mp4 9.0 MB

2016_04_26_10_17_53.mp4 9.0 MB Download

What device / OS version is this? Works on my Nexus 5X.

It happened to me last night on MTC19T N6P. When I tried to show to Min this morning. I can't repro. But he was able to repro on his device.

Last night I also tried Chrome stable M49, can't repro there.

There are something funky.

Just reproed after a few more tries, looks like audio decoding is failing:

00:00:00 00	pipeline_state	kCreated
00:00:00 00	event	WEBMEDIAPLAYER_CREATED
00:00:00 00	url	http://once.unicornmedia.com/now/od/auto/4d993388-8b49-4f34-9e48-87906e690281/85957be9-026a-415e-a8ce-7bfdc19d5e23/98be4223-fd3b-41c5-a7b6-b77cc6dc5ed5/content.once?UMADPARAMreferer=http://espn.go.com/video/clip?id=15355541&UMADPARAMcsid=espnmobile:frontpage
00:00:06 961	total_bytes	16571865
00:00:06 961	streaming	false
00:00:06 961	single_origin	false
00:00:06 962	passed_cors_access_check	false
00:00:06 962	range_header_supported	true
00:00:06 978	pipeline_state	kInitDemuxer
00:00:08 411	info	FFmpegDemuxer: created video stream, config codec: h264 format: 2 profile: h264 baseline coded size: [400,224] visible rect: [0,0,400,224] natural size: [400,224] has extra data? true encrypted? false
00:00:08 411	info	FFmpegDemuxer: created audio stream, config codec: aac bytes_per_channel: 4 channel_layout: 3 samples_per_second: 44100 sample_format: 6 bytes_per_frame: 8 seek_preroll: 0ms codec_delay: 0 has extra data? true encrypted? false
00:00:08 412	duration	160.821
00:00:08 412	audio_channels_count	2
00:00:08 412	audio_codec_name	aac
00:00:08 412	audio_sample_format	Float 32-bit planar
00:00:08 412	audio_samples_per_second	44100
00:00:08 412	bitrate	824363
00:00:08 412	coded_height	0
00:00:08 412	coded_width	0
00:00:08 412	found_audio_stream	true
00:00:08 412	found_video_stream	true
00:00:08 412	height	224
00:00:08 412	max_duration	160.821
00:00:08 412	start_time	0
00:00:08 412	time_base	1/30
00:00:08 412	video_codec_name	h264
00:00:08 412	video_format	PIXEL_FORMAT_YV12
00:00:08 412	video_is_encrypted	false
00:00:08 412	width	400
00:00:08 412	pipeline_state	kInitRenderer
00:00:08 413	audio_dds	false
00:00:08 413	audio_decoder	FFmpegAudioDecoder
00:00:08 858	video_dds	false
00:00:08 858	video_decoder	GpuVideoDecoder
00:00:08 858	pipeline_state	kPlaying
00:00:08 931	event	PLAY
00:00:10 489	pipeline_state	kSeeking
00:00:10 493	pipeline_state	kPlaying
00:00:13 98	pipeline_state	kSeeking
00:00:13 102	pipeline_state	kPlaying
00:00:15 219	pipeline_state	kSeeking
00:00:15 227	pipeline_state	kPlaying
00:00:16 963	pipeline_state	kSeeking
00:00:16 974	pipeline_state	kPlaying
00:00:19 631	event	PAUSE
00:00:21 238	pipeline_state	kSuspending
00:00:21 251	pipeline_state	kSuspended
00:00:34 226	pipeline_state	kResuming
00:00:34 239	audio_dds	false
00:00:34 239	audio_decoder	FFmpegAudioDecoder
00:00:34 453	video_dds	false
00:00:34 453	video_decoder	GpuVideoDecoder
00:00:34 453	pipeline_state	kPlaying
00:00:39 93	pipeline_state	kSeeking
00:00:39 108	pipeline_state	kPlaying
00:00:39 201	pipeline_state	kSeeking
00:00:39 937	pipeline_state	kPlaying
00:00:39 937	pipeline_state	kSeeking
00:00:40 743	pipeline_state	kPlaying
00:00:41 712	event	PLAY
00:00:43 493	event	PAUSE
00:00:48 385	pipeline_state	kSuspending
00:00:48 400	pipeline_state	kSuspended
00:01:11 500	pipeline_state	kResuming
00:01:11 502	audio_dds	false
00:01:11 502	audio_decoder	FFmpegAudioDecoder
00:01:11 771	video_dds	false
00:01:11 771	video_decoder	GpuVideoDecoder
00:01:11 771	pipeline_state	kPlaying
00:01:16 00	pipeline_state	kSuspending
00:01:16 21	pipeline_state	kSuspended
00:03:09 865	pipeline_state	kResuming
00:03:09 867	audio_dds	false
00:03:09 867	audio_decoder	FFmpegAudioDecoder
00:03:10 279	video_dds	false
00:03:10 280	video_decoder	GpuVideoDecoder
00:03:10 280	pipeline_state	kPlaying
00:03:13 547	event	PLAY
00:03:15 222	pipeline_state	kSeeking
00:03:15 228	pipeline_state	kPlaying
00:03:16 670	debug	Dropping audio frame which failed decode with timestamp: 42167302 us, duration: 46440 us, packet size: 230 bytes
00:03:16 670	debug	Dropping audio frame which failed decode with timestamp: 42213741 us, duration: 46417 us, packet size: 237 bytes
00:03:16 671	debug	Dropping audio frame which failed decode with timestamp: 42260159 us, duration: 46440 us, packet size: 253 bytes
00:03:16 671	debug	Dropping audio frame which failed decode with timestamp: 42306599 us, duration: 46440 us, packet size: 219 bytes
00:03:16 672	debug	Dropping audio frame which failed decode with timestamp: 42353039 us, duration: 46417 us, packet size: 233 bytes

<snip>

00:03:18 628	debug	Dropping audio frame which failed decode with timestamp: 72260408 us, duration: 46417 us, packet size: 229 bytes
00:03:18 628	debug	Dropping audio frame which failed decode with timestamp: 72306825 us, duration: 46440 us, packet size: 229 bytes
00:03:18 629	debug	Dropping audio frame which failed decode with timestamp: 72353265 us, duration: 46440 us, packet size: 239 bytes
00:03:18 629	debug	Dropping audio frame which failed decode with timestamp: 72399705 us, duration: 46417 us, packet size: 235 bytes
00:03:18 629	debug	Dropping audio frame which failed decode with timestamp: 72446122 us, duration: 46440 us, packet size: 229 bytes
00:03:18 636	debug	Dropping audio frame which failed decode with timestamp: 72492562 us, duration: 46440 us, packet size: 232 bytes
00:03:18 636	debug	Dropping audio frame which failed decode with timestamp: 72539002 us, duration: 46440 us, packet size: 232 bytes
00:03:18 637	debug	Detected AAC midstream configuration change PTS:72585442 Sample Rate: 44100 vs 44100, ChannelLayout: 2 vs 3, Channels: 1 vs 2
00:03:18 637	debug	Dropping audio frame which failed decode with timestamp: 72585442 us, duration: 46417 us, packet size: 243 bytes
00:03:18 637	error	Unsupported midstream configuration change! Sample Rate: 44100 vs 44100, Channels: 1 vs 2
00:03:18 637	error	audio error during playing, status: pipeline: decode error
00:03:18 637	pipeline_state	kStopping
00:03:18 652	pipeline_state	kStopped
00:03:18 657	pipeline_error	pipeline: decode error
00:03:18 658	event	PAUSE
00:03:22 549	event	PLAY
00:03:29 389	event	WEBMEDIAPLAYER_DESTROYED

FYI, when I tried on cnbc video as a different site last night, I noticed video was able to play while there was no audio after seek. In espn, neither played.

Hmm, watk@ is able to repro this on desktop, there are a variety of errors showing up, some network serving errors from the site too. This might be another case where we're being too strict about the failures.

Figured out what's happening. 

The src of the video is a redirect. Initially it redirects to the video. When you seek, we make another request (to the original src), and get redirected again. The second redirect goes to a different video (an ad) and that breaks everything because we expect it to be the same file.

This won't repro with MediaPlayer because we follow redirects once and give MediaPlayer the redirected url.

I'll work on copying that behavior for Spitzer. Whether we should do it everywhere is not clear yet.

cc: hubbe, horo, philipj, mmenke for commentary on why we might want to use the original URL given to the video tag versus the final response URL (i.e. after redirects).

I can't find anything in the HTML5 video spec which codifies this behavior. This has come up in the past for  issue 74975  and  issue 102201 . The resolution of the latter issue leads me to believe this is a cache header issue on ESPNs side. Chrome is being told the redirect is not cacheable, so it does not do so. See this comment specifically:

https://bugs.chromium.org/p/chromium/issues/detail?id=102201#c12

I don't recall all the reasons why we reuse the original URL, but at the very least it allows CDNs to load balance subsequent requests to the same file. It's entirely unexpected that a site would redirect to a different file/stream, which is unrecoverable.

As watk@ mentions, for M51, we can restore the previous behavior if we have to. It'd be nicer to find a contact at espn and have them update their cache headers though. +pangu to see if we have a contact.

Or can we just remember the seek position and seek on the 2nd redirected video url? 

I suppose video from the 2nd redirected url is the same as the first one, probably just caused by CDN?

qinmin: The second redirected URL is a completely different video, so the all the cached TOC data and byte-ranges we have for it are incorrect. This leads to failed decodes as invalid chunks are returned to the decoder.

Interesting.

But anyway, for seek operations, i think we shouldn't create a separate http range request to the src if the connection already establishes

qinmin: We avoid creating a followup request if the range is nearby (i.e. straight-line reading would be faster than seeking), but if the range is distant or the connection slow it's much faster to initiate a new range request.

Multibuffers will use the redirected URL for follow-up requests.

hubbe: Always? Or just when allowed by the cache headers?

Always. It's not clear what is the *right* behavior though. Caching the redirect while we're playing the video is definitely allowed, but not required.

BTW, I saw the similar weirdness in cnbc video as mentioned in #6 last night, again not able to repro this morning. But this may not be espn only case.

klobag: I think the CNBC issue is something different; they use HLS for their non-ad videos (so playback occurs using the fallback path). Do you remember if you had audio issues on an ad or if it was CNBC content?

I don't think they let user to skip the ads. So I must view the non-ad video.

So not caching the redirect at the network layer if it's not a cacheable redirect is certainly the right thing to do.  I'd need to see an about:net-internals log to verify the redirect is not cacheable - the range-request logic cache could be getting confused by the fact that it's a redirect, but I suspect the redirect is not cacheable - they presumably want to rotate ads.

The range request RFC has no mention of interactions with redirects, which isn't terribly surprising.  I assume the relevant HTML media RFCs also don't discuss the issue.

While it would be great if we could find some RFC to refer to, if we can't, I think it's worth looking at how we handle HTTP redirects for HTML:  For the main frame, we completely replace the URL everywhere (URL bar, history, etc).  I'm not sure how they're handled for iframes - do we update the src value in the DOM, for instance?

I don't think that I have anything else useful to contribute here, unfortunately.

Video and HTML are not the same thing though. HTML is usually downloaded and then displayed, while video requires the remote resource to be available while you're playing it. (See the "fetch" rfc) This additional requirement means that you can't just change the file willy nilly while someone is playing it and expect it to work. AFAIK, there is nothing that actually specifies weather a redirect should be cashed or not, but *if* redirects are not cached, then the redirecting server must redirect to something that contains the same data each time, or playback will not work.

Given this requirement, it seems preferable to me to cache the redirect, as that removes the requirements that redirects points to the same thing each time. Load balancing will still work assuming an even load of users, and if you want to bounce a user from one server to another, you can still do that by having the server abort the connection and return a redirect on the retry .

Also, caching the redirect is more efficient. :)

There are indeed HTTP specs on when to cache HTTP redirects, which the network stack adheres to.

It's worth noting that HTTP caching is always done on a best-effort basis, with no promises, so correctness should never depend on the HTTP cache retaining something (Fine to depending on it not retaining things it shouldn't).

My point about HTML is that caching is irrelevant - if you reload the main document, we reload the URL after the navigation, because, architecturally, Chrome views it as being at the redirect destination URL, not at the original URL that was redirected.

I can confirm that the HTML spec is silent on these issues. The relevant bits are in https://html.spec.whatwg.org/multipage/embedded-content.html#concept-media-load-resource but it's written as if there is a single request and doesn't say anything about HTTP or the Range header, because it's supposed to be protocol agnostic.

I'm inclined to say that the most rational behavior would be to cache the redirect if it is allowed by headers, but otherwise not. To always cache it would fix this problem, but would presumably be a willful violation of HTTP, which is always an option but not the first option.

Has anyone done testing of what other browsers do? One should be able to see it by just playing something over a HTTP redirect and looking in Wireshark.

Whatever the outcome, it would be good to have this documented in one spec or another so that implementations can converge on one behavior.

I think perhaps saying "caching the redirect" is a bit misleading, because it makes it seem like it is a best-effort thing. I think the question at hand is really weather an HTTP redirect means "play from this new resource" or "please get *this* chunk of data from this location", when we're fetching video.
Personally I like the first interpretation better.

Neither of those are really an HTTP property, but more a property of how media elements (Or perhaps HTML DOM elements, more generally) interpret HTTP redirects.

Anyhow, I think we're agreed that this has nothing to do with the network stack's HTTP cache, and if we choose to use range requests on the post-redirect URL, this logic should live somewhere outside the network stack's HTTP implementation?

Agreed, network stack should follow HTTP and may (or may not) cache the redirect. The media element then needs to use this to implement the right behavior for audio/video playback, whatever that is...

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/7ca0b0cfb005a022f08346a778b4481b985078c1

commit 7ca0b0cfb005a022f08346a778b4481b985078c1
Author: watk <watk@chromium.org>
Date: Tue May 03 00:36:06 2016

BufferedDataSource now caches redirects for subsequent requests on Android

Previously BDS would always make requests to the initial URL. So if the
response was a redirect it would be followed on every subsequent request.
Now we save the destination after redirects and use it for future
 requests. This will speed up seeking because we need to do
fewer http requests, and is more robust because we can be more sure that
we're requesting bytes from the same resource each time. See the bug for
an example.

This is Android only for now because Android has historically had this
behavior. MultiBufferDataSource, which will replace BDS, also
implements this logic, so all platforms will soon have it.

BUG= 606666 

Review-Url: https://codereview.chromium.org/1924383002
Cr-Commit-Position: refs/heads/master@{#391121}

[modify] https://crrev.com/7ca0b0cfb005a022f08346a778b4481b985078c1/media/blink/buffered_data_source.cc
[modify] https://crrev.com/7ca0b0cfb005a022f08346a778b4481b985078c1/media/blink/buffered_data_source_unittest.cc

Your change meets the bar and is auto-approved for M51 (branch: 2704)

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/53716c01e23140c6889be4be1216245164f39728

commit 53716c01e23140c6889be4be1216245164f39728
Author: Chris Watkins <watk@chromium.org>
Date: Tue May 03 20:02:24 2016

BufferedDataSource now caches redirects for subsequent requests on Android

Previously BDS would always make requests to the initial URL. So if the
response was a redirect it would be followed on every subsequent request.
Now we save the destination after redirects and use it for future
 requests. This will speed up seeking because we need to do
fewer http requests, and is more robust because we can be more sure that
we're requesting bytes from the same resource each time. See the bug for
an example.

This is Android only for now because Android has historically had this
behavior. MultiBufferDataSource, which will replace BDS, also
implements this logic, so all platforms will soon have it.

BUG= 606666 

Review-Url: https://codereview.chromium.org/1924383002
Cr-Commit-Position: refs/heads/master@{#391121}
(cherry picked from commit 7ca0b0cfb005a022f08346a778b4481b985078c1)

Review URL: https://codereview.chromium.org/1947693003 .

Cr-Commit-Position: refs/branch-heads/2704@{#360}
Cr-Branched-From: 6e53600def8f60d8c632fadc70d7c1939ccea347-refs/heads/master@{#386251}

[modify] https://crrev.com/53716c01e23140c6889be4be1216245164f39728/media/blink/buffered_data_source.cc
[modify] https://crrev.com/53716c01e23140c6889be4be1216245164f39728/media/blink/buffered_data_source_unittest.cc

Verified in Nexus6P/MTC19T/51.0.2704.36