Issue 490144 in chromium: MEDIA_ERR_DECODE randomly occuring within playback

[chro...@googlecode.com]

Status: Unconfirmed
Owner: ----
Labels: Cr-Internals-Media Pri-2 Via-Wizard Type-Bug OS-Mac

New issue 490144 by kenneth....@magine.com: MEDIA_ERR_DECODE randomly
occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

UserAgent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3)
AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.152 Safari/537.36

Example URL:
magine.com

Steps to reproduce the problem:
1. Go to Magine.com and sign up for a free account
2. Try playing Discovery or any other channel
3. Watch any show a while and the player randomly stalls with
MEDIA_ERR_DECODE

This happens randomly but often on almost any channel (Reported for over a
1000 users)

What is the expected behavior?
Seamless playing, the media source should not choke up

What went wrong?
The source somewhere messes up, a decoding error occurs and playback gets
halted. The only error that is received is MEDIA_ERR_DECODE. The player
cannot continue. At first i thought this was a player issue, because of
dash.js.

However it seems that when just loading in fragments normally, without
quality switching it will give this error as well. Theres nothing wrong
with the initialization fragment or the other fragments it seems.

I hope this can be fixed easily. I wish i had more information about this
bug but i cannot seem to get it to work with a chrome debug version. Maybe
the codecs are hard to decode?

Did this work before? N/A

Is it a problem with Flash or HTML5? HTML5

Does this work in other browsers? N/A

Chrome version: 42.0.2311.152 Channel: n/a
OS Version: OS X 10.10.3
Flash Version: Shockwave Flash 17.0 r0

video/mp4;codecs="avc1.4d401f
audio/mp4;codecs="mp4a.40.2"

Those codecs are used

Attachments:
log.txt 65.1 KB

--
You received this message because this project is configured to send all
issue notifications to this address.
You may adjust your notification preferences at:
https://code.google.com/hosting/settings

[chro...@googlecode.com]

Comment #1 on issue 490144 by kenneth....@magine.com: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

Note this problem is not exclusively to Mac OSX, this also affects Windows
and Linux, the userbase that is affected is quite large

[chro...@googlecode.com]

Comment #3 on issue 490144 by yini...@chromium.org: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

kenneth.vanderwerf@,I am not able to sign up magine.com because "We're
sorry but Magine TV is not available in your country yet."

[chro...@googlecode.com]

Comment #7 on issue 490144 by kenneth....@magine.com: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

Hi,

Magine is playable if you go via a proxy to the website and register, we
are based in Germany and Sweden.

Thanks!



Kenneth van der Werf
Software Developer

Magine TV
kenneth.v...@magine.com <mailto:kenneth.v...@magine.com> |
Mob: +46 735247563
Regeringsgatan 25 | 111 53 Stockholm, Sweden | www.magine.com
<http://www.magine.com/>

Privileged and/or Confidential Information may be contained in this
message. If you are not the addressee indicated in this message
(or responsible for delivery of the message to such a person), you may not
copy or deliver this message to anyone. In such case,
you should destroy this message and kindly notify the sender by reply email.

[chro...@googlecode.com]

Comment #8 on issue 490144 by kenneth....@magine.com: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

I suggest
https://chrome.google.com/webstore/detail/hola-better-internet/gkojfkhlekighikafcpjkiklfbnlmeio?hl=en
to temporarily go from a different location

[chro...@googlecode.com]

Comment #9 on issue 490144 by kenneth....@magine.com: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

A log from the chrome media internals.

00:12:14 255 debug Skipping unrecognized top-level box: styp
00:12:14 300 debug Skipping unrecognized top-level box: styp
00:12:14 376 debug Skipping unrecognized top-level box: styp
00:12:14 419 debug Skipping unrecognized top-level box: styp
00:12:14 482 debug Skipping unrecognized top-level box: styp
00:12:14 485 debug Skipping unrecognized top-level box: styp
00:12:14 615 debug Skipping unrecognized top-level box: styp
00:12:14 694 debug Skipping unrecognized top-level box: styp
00:12:14 730 debug Skipping unrecognized top-level box: styp
00:12:50 20 debug Skipping unrecognized top-level box: styp
00:12:50 266 debug Skipping unrecognized top-level box: styp
00:12:56 125 debug Skipping unrecognized top-level box: styp
00:12:56 331 debug Skipping unrecognized top-level box: styp
00:12:56 334 debug Skipping unrecognized top-level box: styp
00:12:56 371 debug Skipping unrecognized top-level box: styp
00:12:56 386 debug Skipping unrecognized top-level box: styp
00:12:56 505 debug Skipping unrecognized top-level box: styp
00:12:56 589 debug Skipping unrecognized top-level box: styp
00:12:56 711 debug Skipping unrecognized top-level box: styp
00:13:19 359 pipeline_error pipeline: decode error
00:13:19 359 pipeline_state kStopping
00:13:19 359 pipeline_state kStopped
00:13:19 361 EVENT PAUSE
00:13:19 391 EVENT WEBMEDIAPLAYER_DESTROYED
00:13:19 469 EVENT PIPELINE_DESTROYED



If you have an account on Magine, let me know the account name and ill
disable the geo lock so you can help us out. Thanks!

[chro...@googlecode.com]

Comment #10 on issue 490144 by kenneth....@magine.com: MEDIA_ERR_DECODE

[chro...@googlecode.com]

Updates:
Cc: xhw...@chromium.org

Comment #11 on issue 490144 by xhw...@chromium.org: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

(No comment was entered for this change.)

[chro...@googlecode.com]

Comment #12 on issue 490144 by xhw...@chromium.org: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

kenneth.vanderwerf: When the error happens, are the contents encrypted?

[chro...@googlecode.com]

Comment #15 on issue 490144 by wolen...@chromium.org: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

kenneth.vanderwerf: Thanks for the media-internals logs. Unfortunately,
there's not enough info in those to clarify what's causing the decode
error. Do you know if any of the appended media segments have tracks that
do not begin with key-frames? If so, that is a known issue (bug 229412)
with Chrome's MSE stack at the moment that leads to decode errors.

[chro...@googlecode.com]

Comment #16 on issue 490144 by kenneth....@magine.com: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

The errors are completely random, i dont do the transcoding but ill talk to
the transcoding guys and see if we transcode keyframes like that, noted
must be that when replaying the same segment it does work. Odd behaviour..

Skickat från min iPhone

[chro...@googlecode.com]

Comment #17 on issue 490144 by kenneth....@magine.com: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

Could this be drm related, we are not respecting renewals, instead we are
using a cached key valid for 6 hours..

[chro...@googlecode.com]

Updates:
Cc: tins...@chromium.org tdr...@chromium.org
Labels: -Needs-Feedback

Comment #18 on issue 490144 by xhw...@chromium.org: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

+tinskip and tdrews:

Re #17: Is there any particular reason you don't repect renewals? I won't
be surprised if that causes errors.

[chro...@googlecode.com]

Comment #20 on issue 490144 by tins...@chromium.org: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

RE #18: The CDM does observe renewals. I am somewhat confused by the
comment in #17.

[chro...@googlecode.com]

Comment #24 on issue 490144 by wolen...@chromium.org: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

Clicking around various channels, changing the bitrate from auto to various
among low/medium/high manually, seeking to different portions of a show (I
noted some failure to complete buffering during some of these seeks, btw,
though manually seeking somewhere else later in the same show "rescued" the
player and allowed playback to commence), etc, eventually led to a
DRM-related error: (I'm not sure if this is the same decode error you
observed because I ran this in a Release build with no extra logging):

DRM: Session created. SessionID = [[[ elided from bug report ]]]
KeySystem_Widevine.js:96 POST
https://magine.com/api/drm/v4/license/widevine 403 (Forbidden)g @
KeySystem_Widevine.js:96b @ ProtectionController.js:23b.System.notify @
dijon.js:599notify @ Notifier.js:37e.handleEvent @
ProtectionModel_21Jan2015.js:120
CorePlayer.js:203 CorePlayer.onError Detected a bad error, we might need to
reset Object {type: "error", error: "key_session", event: "Error: DRM:
widevine update, XHR status is "Forbid…e 200. readyState is 4. Response is
{"code":523}"}b.onError @ CorePlayer.js:203b.onError @
MaginePlayer.js:269dispatchEvent @ EventBus.js:42mediaKeySessionError @
ErrorHandler.js:66s @ Stream.js:65z @ Stream.js:156b.System.notify @
dijon.js:599notify @ Notifier.js:37m @ KeySystem_Widevine.js:56
player.js:939 mediaFailed CustomEvent {detail: Object}
player.js:752 Object {code: "523"} "en_US"
Debug.js:76 Error: DRM: widevine update, XHR status is "Forbidden" (403),
expected to be 200. readyState is 4. Response is {"code":523}
Debug.js:76 ScheduleController video stop.
Debug.js:76 ScheduleController audio stop.
Debug.js:76 ScheduleController text/vtt stop.

[chro...@googlecode.com]

Comment #25 on issue 490144 by wolen...@chromium.org: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

Further to #24, subsequent inspection of the <video> element using the dev
console shows the following error (MEDIA_ERR_SRC_NOT_SUPPORTED), and none
of the players in media-internals shows a pipeline decode error, so this
might not be a repro of the issue tracked by this bug:

$('video')[0].error
MediaError {}code: 4__proto__: MediaError

[chro...@googlecode.com]

Comment #30 on issue 490144 by kenneth....@magine.com: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

xhwang@: Please share instructions with me, separately, for how to get a
CDM-enabled Linux Debug Chromium (with proprietary codecs) built, and what
EME-related vmodule's and loglevels you might suggest I include in further
repro attempt in case this really is specific to EME, not MSE.


I would like to second this, have been trying forever to get a debug
version of chrome w more media info but cant get it to work..

Skickat från min iPhone

[chro...@googlecode.com]

Updates:
Status: Assigned
Owner: xhw...@chromium.org

Comment #32 on issue 490144 by wolen...@chromium.org: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

Confirmed xhwang@ will take a look. If this ends up being MSE, please
assign back to me.

[chro...@googlecode.com]

Comment #35 on issue 490144 by wolen...@chromium.org: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

Further inspection of the larger log shows that the audio splice durations
are quite long (23232microseconds or 23231microseconds). These are
strangely similar to exactly the same duration as the audio frames
previously appended. In short, it looks like, very frequently, the last
audio frame in a media segment is a duplicate (timestamp & duration, at
least) of the first audio frame in the next media segment.

kenneth.vanderwerf@: Is the muxer you use to create the media streams
hitting some off-by-one error during content creation, and sending
duplicate frames for at least audio?

[chro...@googlecode.com]

Updates:
Labels: MSEscrubbedM45

Comment #38 on issue 490144 by wolen...@chromium.org: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

(No comment was entered for this change.)

[chro...@googlecode.com]

Updates:
Labels: Needs-Feedback

Comment #39 on issue 490144 by xhw...@chromium.org: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

kenneth.vanderwerf:

Do you still see this error happening? If so, could you please check
wolenetz's comment in #31 and see whether we have mis-muxed content?
Otherwise, I'll mark this issue as WontFix since there's no issue in
Chromium that needs to be fixed.

[chro...@googlecode.com]

Updates:
Status: WontFix

Comment #41 on issue 490144 by xhw...@chromium.org: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

We are not getting feedback from the reporter. Mark this issue as WontFix
for now. Feel free to reopen if we have any new info.

[chro...@googlecode.com]

Comment #44 on issue 490144 by bugd...@chromium.org: MEDIA_ERR_DECODE
randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144#c44

The following revision refers to this bug:

https://chromium.googlesource.com/chromium/src.git/+/e27df71fa3f038ca2a25f457560036ae861b4679

commit e27df71fa3f038ca2a25f457560036ae861b4679
Author: wolenetz <wole...@chromium.org>
Date: Fri Jul 10 03:06:38 2015

Log audio splice sanitizer warnings and errors to media-internals

Plumbs a MediaLog into AudioSplicer's AudioStreamSanitizers and uses it
to log warnings and errors to chrome://media-internals. This should
help ease of diagnosis of potentially badly muxed frame timestamps
and durations. Previously, a repro on a Debug build and inspection
of DVLOG()s was required to get similar logs.

BUG=505931,490144
R=dalec...@chromium.org,chcunn...@chromium.org,xhw...@chromium.org
TEST=repro of bug 505931's audio-only gap tolerance decode error shows log
in media-internals.

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

Cr-Commit-Position: refs/heads/master@{#338233}

[modify]
http://crrev.com/e27df71fa3f038ca2a25f457560036ae861b4679/media/base/audio_splicer.cc
[modify]
http://crrev.com/e27df71fa3f038ca2a25f457560036ae861b4679/media/base/audio_splicer.h
[modify]
http://crrev.com/e27df71fa3f038ca2a25f457560036ae861b4679/media/base/audio_splicer_unittest.cc
[modify]
http://crrev.com/e27df71fa3f038ca2a25f457560036ae861b4679/media/renderers/audio_renderer_impl.cc

[chro...@googlecode.com]

Comment #45 on issue 490144 by wolen...@chromium.org: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

With a preliminary fix for bug 492833, additional chrome://media-internals
buffered audio splice statistics are showing frequent "degenerate" splice
frame creation attempts (these are exact buffer overlaps (as might occur on
re-appending the last buffer in a segment as the first buffer in the next
segment), or splice overlaps that are too small or don't otherwise have
enough data to generate a real splice). For example, I see 74 of these
occur within about 8 minutes of buffering and playback of a channel on
magine.com. No "real" splices are buffered in the same time frame.
Generally, this indicates inefficient appending or muxed stream contents
(coded frame timestamps and durations) may not match exactly the web app's
expectations. These new statistics are all for pre-decode splice frame
detection, so further errors could occur downstream on actual decode if the
encoded contents' timestamps and durations differ significantly from the
muxed container frame timestamp and duration metadata. I hope this helps
identify the problem as very likely incorrectly muxed content (or incorrect
metadata used by the player to append the content). I've included this bug
as a reference in my change, so this bug will be updated when the new
buffered audio splice generation statistics land in Chromium.

[chro...@googlecode.com]

Comment #46 on issue 490144 by wolen...@chromium.org: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

An updated fix for bug 492833 (patch set 2 of
https://codereview.chromium.org/1236543007) includes greater timestamp
detail and explanations in logs. When repro'ing this bug 490144, for
example, it shows:

00:00:03 974 pipeline_state kSeeking
00:00:04 101 pipeline_state kPlaying
00:00:04 243 debug Skipping splice frame buffering: not enough samples for
splicing new buffer at 1254016870us. Have 12us, but need 1000us.
00:00:06 216 event PLAY
00:00:23 905 debug Skipping splice frame buffering: not enough samples for
splicing new buffer at 1260007619us. Have 11us, but need 1000us.
00:00:36 316 debug Skipping splice frame buffering: not enough samples for
splicing new buffer at 1265998367us. Have 12us, but need 1000us.
00:00:42 165 debug Skipping splice frame buffering: not enough samples for
splicing new buffer at 1272012335us. Have 12us, but need 1000us.
00:00:48 251 debug (Log limit reached. Further similar entries may be
suppressed): Skipping splice frame buffering: not enough samples for
splicing new buffer at 1278003083us. Have 12us, but need 1000us.

[chro...@googlecode.com]

Comment #47 on issue 490144 by bugd...@chromium.org: MEDIA_ERR_DECODE
randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144#c47

The following revision refers to this bug:

https://chromium.googlesource.com/chromium/src.git/+/2bf99047afc7d15fb3a301c1ee5c2e6c06be9ee1

commit 2bf99047afc7d15fb3a301c1ee5c2e6c06be9ee1
Author: wolenetz <wole...@chromium.org>
Date: Fri Jul 17 22:09:08 2015

MSE: Log buffered audio splice generation to media-internals

Uses MediaLog to log a limited number of buffered audio splice
frame generation warnings and successes to chrome://media-internals.

BUG=492833,490144,505931,482085
R=dalec...@chromium.org,chcunn...@chromium.org,xhw...@chromium.org
TEST=Manual

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

Cr-Commit-Position: refs/heads/master@{#339341}

[modify]
http://crrev.com/2bf99047afc7d15fb3a301c1ee5c2e6c06be9ee1/media/filters/source_buffer_stream.cc
[modify]
http://crrev.com/2bf99047afc7d15fb3a301c1ee5c2e6c06be9ee1/media/filters/source_buffer_stream.h

[chro...@googlecode.com]

Comment #49 on issue 490144 by kenneth....@magine.com: MEDIA_ERR_DECODE

randomly occuring within playback
https://code.google.com/p/chromium/issues/detail?id=490144

As a result of the changes landed and as a result of your ongoing help, we
have been able to pinpoint the the timings were slightly off. We corrected
that and that fixed the error. Its also worth noting that the new chrome
tools help a lot in giving insight if the issue exists.

Thanks so much for the help!