New issue
Advanced search Search tips
Note: Color blocks (like █ or █) mean that a user may not be available. Tooltip shows the reason.

Issue 655630 link

Starred by 1 user
Status: Fixed
Owner:
█ w...@chromium.org
Last visit > 30 days ago
Closed: Nov 2016
Cc:
█ w...@chromium.org
xhw...@chromium.org
liber...@chromium.org
dalecur...@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Android
Pri: 1
Type: ----



Sign in to add a comment

EncryptedMediaTest.FrameSizeChangeVideo is flaky on android

Project Member Reported by joh...@chromium.org, Oct 13 2016 
Both MSE_ClearKey/EncryptedMediaTest.FrameSizeChangeVideo/0 and SRC_ClearKey/EncryptedMediaTest.FrameSizeChangeVideo/0 frequently fail on Android bots:
https://test-results.appspot.com/dashboards/flakiness_dashboard.html#testType=content_browsertests&tests=EncryptedMediaTest.FrameSizeChangeVideo

Comment 1 by joh...@chromium.org, Oct 13 2016 

By the way, it's quite confusing having both chrome/browser/media/encrypted_media_browsertest.cc and content/browser/media/encrypted_media_browsertest.cc sharing the same test names - is that temporary?
Project Member

Comment 2 by bugdroid1@chromium.org, Oct 13 2016 

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

commit 461b59b181abf04710f31bfa44694c1a5b63a8a6
Author: johnme <johnme@chromium.org>
Date: Thu Oct 13 14:09:59 2016

Mark EncryptedMediaTest.FrameSizeChangeVideo flaky on android

NOTREECHECKS=true
NOTRY=true
BUG= 655630 
TBR=wolenetz@chromium.org

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

[modify] https://crrev.com/461b59b181abf04710f31bfa44694c1a5b63a8a6/content/browser/media/encrypted_media_browsertest.cc

Comment 3 by xhw...@chromium.org, Oct 13 2016

Cc: w...@chromium.org liber...@chromium.org
Re #1: chrome/browser/media/encrypted_media_browsertest.cc and content/browser/media/encrypted_media_browsertest.cc do the same set of tests with different key systems. It's parameterized test and the final test names are different. This is intentional and we don't have a plan to change it.

Re #0: It seems most of the failure happened on JellyBean and low end devices. And I don't find this specific test to be flaky. When it fails, either a lot of other tests are also failing [1], or some other EncryptedMediaTest failed as well [2].

Also, we are doing decryption in the render process, so in the GPU process, it's decoding a clear content. I suspect that media service is in a bad state when the flakiness happens.

+watk/liberato for any insights.

[1] https://luci-logdog.appspot.com/v/?s=chromium%2Fbb%2Fchromium.android%2FLollipop_Low-end_Tester%2F4079%2F%2B%2Frecipes%2Fsteps%2Fcontent_browsertests%2F0%2Fstdout

[2] https://build.chromium.org/p/chromium.android/builders/Lollipop%20Low-end%20Tester/builds/4120

Comment 4 by joh...@chromium.org, Oct 14 2016 

> chrome/browser/media/encrypted_media_browsertest.cc and
> content/browser/media/encrypted_media_browsertest.cc do the same set of tests
> with different key systems. It's parameterized test and the final test names
> are different. 

I'm confused - both files contain the following pair of instantiations (though the chrome/ one has additional instantiations):

INSTANTIATE_TEST_CASE_P(SRC_ClearKey, EncryptedMediaTest,
                        Combine(Values(kClearKeyKeySystem), Values(SRC)));

INSTANTIATE_TEST_CASE_P(MSE_ClearKey, EncryptedMediaTest,
                        Combine(Values(kClearKeyKeySystem), Values(MSE)));

Doesn't that mean they both test these 2 key systems, and these particular tests will have the same names (e.g. SRC_ClearKey/EncryptedMediaTest.FrameSizeChangeVideo/0 in both cases)?

Comment 5 by w...@chromium.org, Oct 18 2016

Cc: xhw...@chromium.org
Owner: w...@chromium.org
Status: Started (was: Untriaged)
Re #3: Shouldn't be an AVDA or mediaserver problem because we should be using libvpx for the framesize test.

I'll take a look.

Comment 6 by w...@chromium.org, Oct 18 2016

Cc: dalecur...@chromium.org
I'm 90% sure this is broken by the change to suspend players aggressively on low end devices. I commented out this line and I can't make it fail any more: https://cs.chromium.org/chromium/src/content/renderer/media/renderer_webmediaplayer_delegate.cc?sq=package:chromium&dr=C&rcl=1476804170&l=84

The test is waiting for some event that never arrives because the player is suspended.

Comment 7 by w...@chromium.org, Oct 19 2016 

Looks like the sequence of events is:
* One player reaches canplay and the test play()s it.
* That causes the second player to be forcibly suspended before canplay.
* No events occur that might resume the second player, so it never reaches canplay.
* There are no more DidLoadingProgress() events. There's a window in which we haven't reached HAVE_ENOUGH, but there will be no more loading. Maybe when the frames have been submitted to the decoder, but before they're decoded?

Dale, got ideas for how to fix this? I don't really want to augment idleness to include pending decodes.

Comment 8 by w...@chromium.org, Oct 19 2016 

I've seen both cases:
a) WMPI::didLoadingProgress() stops being called by blink.
b) WMPI::didLoadingProgress() gets called but Pipeline::DidLoadingProgress() and BufferedDataSource::DidLoadingProgress() are both false.

I don't know. This is fragile. It seems like there's still the case where we resume because loading progresses. We start a decode. We get suspended before the decode completes. We never resume again, but the decode would have caused us to reach HAVE_ENOUGH.

Comment 9 by dmazz...@chromium.org, Oct 25 2016 

Flaky on Win too:

https://uberchromegw.corp.google.com/i/chromium.win/builders/Win7%20Tests%20%28dbg%29%281%29/builds/54000

MSE_ClearKey/EncryptedMediaTest.FrameSizeChangeVideo/0 (run #1):
[ RUN      ] MSE_ClearKey/EncryptedMediaTest.FrameSizeChangeVideo/0
[5140:6652:1025/020912:WARNING:persistent_histogram_allocator.cc(502)] Creating the results-histogram inside persistent memory can cause future allocations to crash if that memory is ever released (for testing).
[2360:6100:1025/020913:INFO:media_foundation_video_encode_accelerator_win.cc(290)] Windows versions earlier than 8 are not supported.
[2360:7544:1025/020913:WARNING:persistent_histogram_allocator.cc(502)] Creating the results-histogram inside persistent memory can cause future allocations to crash if that memory is ever released (for testing).
[2468:2660:1025/020914:WARNING:persistent_histogram_allocator.cc(502)] Creating the results-histogram inside persistent memory can cause future allocations to crash if that memory is ever released (for testing).
[5140:6652:1025/020915:INFO:media_browsertest.cc(42)] 02:09:15.615 Starting HTTP server
[5140:6652:1025/020915:INFO:media_browsertest.cc(58)] 02:09:15.621 Running test URL: http://127.0.0.1:52921/encrypted_frame_size_change.html?mediaFile=frame_size_change-av_enc-v.webm&mediaType=video/webm;%20codecs=%22vorbis,%20vp8%22&keySystem=org.w3.clearkey&useMSE=1
[2644:5512:1025/020916:WARNING:persistent_histogram_allocator.cc(502)] Creating the results-histogram inside persistent memory can cause future allocations to crash if that memory is ever released (for testing).
[5140:6652:1025/020917:INFO:CONSOLE(270)] "02:09:17.506 -  Registering video event handlers.", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[5140:6652:1025/020917:INFO:CONSOLE(270)] "02:09:17.510 -  Setting video media keys: org.w3.clearkey", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[5140:6652:1025/020917:INFO:CONSOLE(270)] "02:09:17.551 -  Loading media using MSE.", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[5140:6652:1025/020917:INFO:CONSOLE(270)] "02:09:17.566 -  video.src has been set to blob:http://127.0.0.1:52921/c2af4475-9b77-492a-a88f-c895de4acba9", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[5140:6652:1025/020917:INFO:CONSOLE(270)] "02:09:17.567 -  initEMEPlayer() done", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[5140:6652:1025/020917:INFO:CONSOLE(270)] "02:09:17.569 -  Registering video event handlers.", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[5140:6652:1025/020917:INFO:CONSOLE(270)] "02:09:17.571 -  Setting video media keys: org.w3.clearkey", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[2644:5096:1025/020917:ERROR:remoting_controller.cc(87)] NOT IMPLEMENTED
[5140:5112:1025/020917:ERROR:audio_manager_win.cc(464)] GetPreferredAudioParameters failed: 88890004
[5140:7560:1025/020917:WARNING:embedded_test_server.cc(201)] Request not handled. Returning 404: /favicon.ico
[5140:6652:1025/020917:INFO:CONSOLE(270)] "02:09:17.660 -  onSourceOpen [object Event]", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[5140:6652:1025/020917:INFO:CONSOLE(270)] "02:09:17.661 -  Creating a source buffer for type video/webm; codecs="vorbis, vp8"", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[5140:6652:1025/020917:INFO:CONSOLE(270)] "02:09:17.692 -  Loading media using MSE.", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[5140:6652:1025/020917:INFO:CONSOLE(270)] "02:09:17.695 -  video.src has been set to blob:http://127.0.0.1:52921/d6d0b011-2ec8-490f-b1dd-55ce5409f92b", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[5140:6652:1025/020917:INFO:CONSOLE(270)] "02:09:17.695 -  initEMEPlayer() done", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[2644:5096:1025/020917:ERROR:remoting_controller.cc(87)] NOT IMPLEMENTED
[5140:6652:1025/020917:INFO:CONSOLE(270)] "02:09:17.744 -  onSourceOpen [object Event]", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[5140:6652:1025/020917:INFO:CONSOLE(270)] "02:09:17.744 -  Creating a source buffer for type video/webm; codecs="vorbis, vp8"", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[2360:6100:1025/020917:INFO:gpu_video_decode_accelerator_factory.cc(163)] Initializing DXVA HW decoder for windows.
[2360:6100:1025/020917:ERROR:mf_helpers.cc(12)] Error in dxva_video_decode_accelerator_win.cc on line 599
[2360:6100:1025/020917:ERROR:gpu_video_decode_accelerator.cc(370)] HW video decode not available for profile 11
[2644:2896:1025/020917:ERROR:gpu_video_decode_accelerator_host.cc(93)] Send(GpuCommandBufferMsg_CreateVideoDecoder()) failed
[5140:5112:1025/020917:ERROR:audio_manager_win.cc(464)] GetPreferredAudioParameters failed: 88890004
[2644:2896:1025/020917:ERROR:gpu_video_decoder.cc(848)] VDA Error: 4
[2360:7544:1025/020917:ERROR:gpu_channel.cc(569)] Could not find message queue
[5140:5112:1025/020917:ERROR:audio_output_resampler.cc(301)] Unable to open audio device in low latency mode.  Falling back to high latency audio output.
[5140:5112:1025/020917:ERROR:audio_output_resampler.cc(311)] Unable to open audio device in high latency mode.  Falling back to fake audio output.
[5140:6652:1025/020917:INFO:CONSOLE(270)] "02:09:17.943 -  Creating new media key session for initDataType: webm, initData: a58104e269934c050403b78eeb0ee57b", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[5140:6652:1025/020918:INFO:CONSOLE(270)] "02:09:18.035 -  MediaKeySession onMessage [object MediaKeyMessageEvent]", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[5140:6652:1025/020918:INFO:CONSOLE(270)] "02:09:18.041 -  Calling update: {"keys":[{"kty":"oct","alg":"A128KW","kid":"pYEE4mmTTAUEA7eO6w7lew","k":"691i8WgU0nto7xIq_OSuPA"}]}", source: http://127.0.0.1:52921/eme_player_js/utils.js (270)
[2360:6100:1025/020918:INFO:gpu_video_decode_accelerator_factory.cc(163)] Initializing DXVA HW decoder for windows.
[2360:6100:1025/020918:ERROR:mf_helpers.cc(12)] Error in dxva_video_decode_accelerator_win.cc on line 599
[2360:6100:1025/020918:ERROR:gpu_video_decode_accelerator.cc(370)] HW video decode not available for profile 11
[2644:2896:1025/020918:ERROR:gpu_video_decode_accelerator_host.cc(93)] Send(GpuCommandBufferMsg_CreateVideoDecoder()) failed
[2644:2896:1025/020918:ERROR:gpu_video_decoder.cc(848)] VDA Error: 4
[2360:7544:1025/020918:ERROR:gpu_channel.cc(569)] Could not find message queue
[2644:3912:1025/020918:FATAL:video_renderer_algorithm.cc(318)] Check failed: frame_queue_[last_frame_index_].drop_count <= frame_queue_[last_frame_index_].render_count (2 vs. 1)
Backtrace:
	base::debug::StackTrace::StackTrace [0x1007B3E7+23]
	logging::LogMessage::~LogMessage [0x100CD4EB+59]
	media::VideoRendererAlgorithm::OnLastFrameDropped [0x09432A13+259]
	media::VideoRendererImpl::OnFrameDropped [0x094A6F1A+42]
	media::VideoFrameCompositor::CallRender [0x377AEC73+499]
	media::VideoFrameCompositor::UpdateCurrentFrame [0x377B01C1+209]
	cc::VideoFrameProviderClientImpl::OnBeginFrame [0x0F7239E1+769]
	cc::LayerTreeHostImpl::WillBeginImplFrame [0x0F98C00D+157]
	cc::ProxyImpl::WillBeginImplFrame [0x0FA2A911+209]
	cc::Scheduler::BeginImplFrame [0x0F8A1214+612]
	cc::Scheduler::BeginImplFrameWithDeadline [0x0F8A1B45+1701]
	cc::Scheduler::OnBeginFrameDerivedImpl [0x0F8A343C+1036]
	cc::BeginFrameObserverBase::OnBeginFrame [0x0F88FF6F+351]
	cc::ExternalBeginFrameSource::OnBeginFrame [0x0F89009A+138]
	content::CompositorExternalBeginFrameSource::OnBeginFrame [0x12F84DB7+23]
	base::DispatchToMethodImpl<content::CompositorExternalBeginFrameSource *,void (__thiscall content::CompositorExternalBeginFrameSource::*)(cc::BeginFrameArgs const &),std::tuple<cc::BeginFrameArgs> const &,0> [0x12F83BA4+36]
	base::DispatchToMethod<content::CompositorExternalBeginFrameSource *,void (__thiscall content::CompositorExternalBeginFrameSource::*)(cc::BeginFrameArgs const &),std::tuple<cc::BeginFrameArgs> const &> [0x12F83AC7+39]
	IPC::DispatchToMethod<content::CompositorExternalBeginFrameSource,void (__thiscall content::CompositorExternalBeginFrameSource::*)(cc::BeginFrameArgs const &),void,std::tuple<cc::BeginFrameArgs> > [0x12F83B38+24]
	IPC::MessageT<ViewMsg_BeginFrame_Meta,std::tuple<cc::BeginFrameArgs>,void>::Dispatch<content::CompositorExternalBeginFrameSource,content::CompositorExternalBeginFrameSource,void,void (__thiscall content::CompositorExternalBeginFrameSource::*)(cc::BeginFra [0x12F838F5+213]
	content::CompositorExternalBeginFrameSource::OnMessageReceived [0x12F85010+576]
	content::CompositorExternalBeginFrameSource::CompositorExternalBeginFrameSourceProxy::OnMessageReceived [0x12F850EF+31]
	base::internal::FunctorTraits<void (__thiscall content::CompositorExternalBeginFrameSource::CompositorExternalBeginFrameSourceProxy::*)(IPC::Message const &),void>::Invoke<scoped_refptr<content::CompositorExternalBeginFrameSource::CompositorExternalBeginF [0x12F83C15+37]
	base::internal::InvokeHelper<0,void>::MakeItSo<void (__thiscall content::CompositorExternalBeginFrameSource::CompositorExternalBeginFrameSourceProxy::*const &)(IPC::Message const &),scoped_refptr<content::CompositorExternalBeginFrameSource::CompositorExte [0x12F83CC5+53]
	base::internal::Invoker<base::internal::BindState<void (__thiscall content::CompositorExternalBeginFrameSource::CompositorExternalBeginFrameSourceProxy::*)(IPC::Message const &),scoped_refptr<content::CompositorExternalBeginFrameSource::CompositorExternal [0x12F83D21+65]
	base::internal::Invoker<base::internal::BindState<void (__thiscall content::CompositorExternalBeginFrameSource::CompositorExternalBeginFrameSourceProxy::*)(IPC::Message const &),scoped_refptr<content::CompositorExternalBeginFrameSource::CompositorExternal [0x12F852A1+49]
	base::internal::RunMixin<base::Callback<void __cdecl(IPC::Message const &),1,1> >::Run [0x12F8857C+76]
	content::CompositorForwardingMessageFilter::ProcessMessageOnCompositorThread [0x12F88268+296]
	base::internal::FunctorTraits<void (__thiscall content::CompositorForwardingMessageFilter::*)(IPC::Message const &),void>::Invoke<scoped_refptr<content::CompositorForwardingMessageFilter> const &,IPC::Message const &> [0x12F85905+37]
	base::internal::InvokeHelper<0,void>::MakeItSo<void (__thiscall content::CompositorForwardingMessageFilter::*const &)(IPC::Message const &),scoped_refptr<content::CompositorForwardingMessageFilter> const &,IPC::Message const &> [0x12F859B5+53]
	base::internal::Invoker<base::internal::BindState<void (__thiscall content::CompositorForwardingMessageFilter::*)(IPC::Message const &),scoped_refptr<content::CompositorForwardingMessageFilter>,IPC::Message>,void __cdecl(void)>::RunImpl<void (__thiscall c [0x12F85A23+83]
	base::internal::Invoker<base::internal::BindState<void (__thiscall content::CompositorForwardingMessageFilter::*)(IPC::Message const &),scoped_refptr<content::CompositorForwardingMessageFilter>,IPC::Message>,void __cdecl(void)>::Run [0x12F88514+36]
	base::internal::RunMixin<base::Callback<void __cdecl(void),0,0> >::Run [0x10081184+68]
	base::debug::TaskAnnotator::RunTask [0x1008131F+367]
	base::MessageLoop::RunTask [0x100FD8F4+660]
	base::MessageLoop::DeferOrRunPendingTask [0x100FB6EC+44]
	base::MessageLoop::DoWork [0x100FBCD2+242]
	base::MessagePumpDefault::Run [0x10103B1E+190]
	base::MessageLoop::RunHandler [0x100FD5EC+444]
	base::RunLoop::Run [0x101A4914+52]
	base::Thread::Run [0x1023A63F+319]
	base::Thread::ThreadMain [0x1023BA0B+955]
	base::PlatformThread::Sleep [0x10215E2C+380]
	BaseThreadInitThunk [0x7606337A+18]
	RtlInitializeExceptionChain [0x775B92B2+99]
	RtlInitializeExceptionChain [0x775B9285+54]


MSE_ClearKey/EncryptedMediaTest.FrameSizeChangeVideo/0 (run #2):
[ RUN      ] MSE_ClearKey/EncryptedMediaTest.FrameSizeChangeVideo/0
[6540:7980:1025/021006:WARNING:persistent_histogram_allocator.cc(502)] Creating the results-histogram inside persistent memory can cause future allocations to crash if that memory is ever released (for testing).
[6312:4984:1025/021006:INFO:media_foundation_video_encode_accelerator_win.cc(290)] Windows versions earlier than 8 are not supported.
[6312:2392:1025/021006:WARNING:persistent_histogram_allocator.cc(502)] Creating the results-histogram inside persistent memory can cause future allocations to crash if that memory is ever released (for testing).
[3932:7340:1025/021007:WARNING:persistent_histogram_allocator.cc(502)] Creating the results-histogram inside persistent memory can cause future allocations to crash if that memory is ever released (for testing).
[6540:7980:1025/021008:INFO:media_browsertest.cc(42)] 02:10:08.542 Starting HTTP server
[6540:7980:1025/021008:INFO:media_browsertest.cc(58)] 02:10:08.548 Running test URL: http://127.0.0.1:53071/encrypted_frame_size_change.html?mediaFile=frame_size_change-av_enc-v.webm&mediaType=video/webm;%20codecs=%22vorbis,%20vp8%22&keySystem=org.w3.clearkey&useMSE=1
[3028:4356:1025/021009:WARNING:persistent_histogram_allocator.cc(502)] Creating the results-histogram inside persistent memory can cause future allocations to crash if that memory is ever released (for testing).
[3932:6152:1025/021009:ERROR:render_process_impl.cc(112)] WebFrame LEAKED 2 TIMES
[6540:8136:1025/021009:ERROR:process_win.cc(135)] Unable to terminate process: Access is denied. (0x5)
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.288 -  Registering video event handlers.", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.293 -  Setting video media keys: org.w3.clearkey", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.335 -  Loading media using MSE.", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.339 -  video.src has been set to blob:http://127.0.0.1:53071/1ecc5936-2f99-4d69-bb23-60076681496c", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.339 -  initEMEPlayer() done", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.341 -  Registering video event handlers.", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.343 -  Setting video media keys: org.w3.clearkey", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[3028:7588:1025/021010:ERROR:remoting_controller.cc(87)] NOT IMPLEMENTED
[6540:6232:1025/021010:ERROR:audio_manager_win.cc(464)] GetPreferredAudioParameters failed: 88890004
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.428 -  onSourceOpen [object Event]", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.429 -  Creating a source buffer for type video/webm; codecs="vorbis, vp8"", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[3028:7588:1025/021010:ERROR:remoting_controller.cc(87)] NOT IMPLEMENTED
[6540:1636:1025/021010:WARNING:embedded_test_server.cc(201)] Request not handled. Returning 404: /favicon.ico
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.435 -  Loading media using MSE.", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.437 -  video.src has been set to blob:http://127.0.0.1:53071/d5c3daf3-1b43-46f4-b32a-b2ea5503f7c5", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.437 -  initEMEPlayer() done", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.444 -  onSourceOpen [object Event]", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.445 -  Creating a source buffer for type video/webm; codecs="vorbis, vp8"", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[6540:6232:1025/021010:ERROR:audio_manager_win.cc(464)] GetPreferredAudioParameters failed: 88890004
[6312:4984:1025/021010:INFO:gpu_video_decode_accelerator_factory.cc(163)] Initializing DXVA HW decoder for windows.
[6312:4984:1025/021010:ERROR:mf_helpers.cc(12)] Error in dxva_video_decode_accelerator_win.cc on line 599
[6312:4984:1025/021010:ERROR:gpu_video_decode_accelerator.cc(370)] HW video decode not available for profile 11
[6540:6232:1025/021010:ERROR:audio_output_resampler.cc(301)] Unable to open audio device in low latency mode.  Falling back to high latency audio output.
[3028:7600:1025/021010:ERROR:gpu_video_decode_accelerator_host.cc(93)] Send(GpuCommandBufferMsg_CreateVideoDecoder()) failed
[3028:7600:1025/021010:ERROR:gpu_video_decoder.cc(848)] VDA Error: 4
[6540:6232:1025/021010:ERROR:audio_output_resampler.cc(311)] Unable to open audio device in high latency mode.  Falling back to fake audio output.
[6312:2392:1025/021010:ERROR:gpu_channel.cc(569)] Could not find message queue
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.632 -  Creating new media key session for initDataType: webm, initData: a58104e269934c050403b78eeb0ee57b", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.736 -  MediaKeySession onMessage [object MediaKeyMessageEvent]", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[6540:7980:1025/021010:INFO:CONSOLE(270)] "02:10:10.744 -  Calling update: {"keys":[{"kty":"oct","alg":"A128KW","kid":"pYEE4mmTTAUEA7eO6w7lew","k":"691i8WgU0nto7xIq_OSuPA"}]}", source: http://127.0.0.1:53071/eme_player_js/utils.js (270)
[6312:4984:1025/021010:INFO:gpu_video_decode_accelerator_factory.cc(163)] Initializing DXVA HW decoder for windows.
[6312:4984:1025/021010:ERROR:mf_helpers.cc(12)] Error in dxva_video_decode_accelerator_win.cc on line 599
[6312:4984:1025/021010:ERROR:gpu_video_decode_accelerator.cc(370)] HW video decode not available for profile 11
[3028:7600:1025/021010:ERROR:gpu_video_decode_accelerator_host.cc(93)] Send(GpuCommandBufferMsg_CreateVideoDecoder()) failed
[3028:7600:1025/021010:ERROR:gpu_video_decoder.cc(848)] VDA Error: 4
[6312:2392:1025/021010:ERROR:gpu_channel.cc(569)] Could not find message queue
[3028:4544:1025/021010:FATAL:video_renderer_algorithm.cc(318)] Check failed: frame_queue_[last_frame_index_].drop_count <= frame_queue_[last_frame_index_].render_count (2 vs. 1)
Backtrace:
	base::debug::StackTrace::StackTrace [0x1007B3E7+23]
	logging::LogMessage::~LogMessage [0x100CD4EB+59]
	media::VideoRendererAlgorithm::OnLastFrameDropped [0x093D2A13+259]
	media::VideoRendererImpl::OnFrameDropped [0x09446F1A+42]
	media::VideoFrameCompositor::CallRender [0x377AEC73+499]
	media::VideoFrameCompositor::UpdateCurrentFrame [0x377B01C1+209]
	cc::VideoFrameProviderClientImpl::OnBeginFrame [0x0F7239E1+769]
	cc::LayerTreeHostImpl::WillBeginImplFrame [0x0F98C00D+157]
	cc::ProxyImpl::WillBeginImplFrame [0x0FA2A911+209]
	cc::Scheduler::BeginImplFrame [0x0F8A1214+612]
	cc::Scheduler::BeginImplFrameWithDeadline [0x0F8A1B45+1701]
	cc::Scheduler::OnBeginFrameDerivedImpl [0x0F8A343C+1036]
	cc::BeginFrameObserverBase::OnBeginFrame [0x0F88FF6F+351]
	cc::ExternalBeginFrameSource::OnBeginFrame [0x0F89009A+138]
	content::CompositorExternalBeginFrameSource::OnBeginFrame [0x12F84DB7+23]
	base::DispatchToMethodImpl<content::CompositorExternalBeginFrameSource *,void (__thiscall content::CompositorExternalBeginFrameSource::*)(cc::BeginFrameArgs const &),std::tuple<cc::BeginFrameArgs> const &,0> [0x12F83BA4+36]
	base::DispatchToMethod<content::CompositorExternalBeginFrameSource *,void (__thiscall content::CompositorExternalBeginFrameSource::*)(cc::BeginFrameArgs const &),std::tuple<cc::BeginFrameArgs> const &> [0x12F83AC7+39]
	IPC::DispatchToMethod<content::CompositorExternalBeginFrameSource,void (__thiscall content::CompositorExternalBeginFrameSource::*)(cc::BeginFrameArgs const &),void,std::tuple<cc::BeginFrameArgs> > [0x12F83B38+24]
	IPC::MessageT<ViewMsg_BeginFrame_Meta,std::tuple<cc::BeginFrameArgs>,void>::Dispatch<content::CompositorExternalBeginFrameSource,content::CompositorExternalBeginFrameSource,void,void (__thiscall content::CompositorExternalBeginFrameSource::*)(cc::BeginFra [0x12F838F5+213]
	content::CompositorExternalBeginFrameSource::OnMessageReceived [0x12F85010+576]
	content::CompositorExternalBeginFrameSource::CompositorExternalBeginFrameSourceProxy::OnMessageReceived [0x12F850EF+31]
	base::internal::FunctorTraits<void (__thiscall content::CompositorExternalBeginFrameSource::CompositorExternalBeginFrameSourceProxy::*)(IPC::Message const &),void>::Invoke<scoped_refptr<content::CompositorExternalBeginFrameSource::CompositorExternalBeginF [0x12F83C15+37]
	base::internal::InvokeHelper<0,void>::MakeItSo<void (__thiscall content::CompositorExternalBeginFrameSource::CompositorExternalBeginFrameSourceProxy::*const &)(IPC::Message const &),scoped_refptr<content::CompositorExternalBeginFrameSource::CompositorExte [0x12F83CC5+53]
	base::internal::Invoker<base::internal::BindState<void (__thiscall content::CompositorExternalBeginFrameSource::CompositorExternalBeginFrameSourceProxy::*)(IPC::Message const &),scoped_refptr<content::CompositorExternalBeginFrameSource::CompositorExternal [0x12F83D21+65]
	base::internal::Invoker<base::internal::BindState<void (__thiscall content::CompositorExternalBeginFrameSource::CompositorExternalBeginFrameSourceProxy::*)(IPC::Message const &),scoped_refptr<content::CompositorExternalBeginFrameSource::CompositorExternal [0x12F852A1+49]
	base::internal::RunMixin<base::Callback<void __cdecl(IPC::Message const &),1,1> >::Run [0x12F8857C+76]
	content::CompositorForwardingMessageFilter::ProcessMessageOnCompositorThread [0x12F88268+296]
	base::internal::FunctorTraits<void (__thiscall content::CompositorForwardingMessageFilter::*)(IPC::Message const &),void>::Invoke<scoped_refptr<content::CompositorForwardingMessageFilter> const &,IPC::Message const &> [0x12F85905+37]
	base::internal::InvokeHelper<0,void>::MakeItSo<void (__thiscall content::CompositorForwardingMessageFilter::*const &)(IPC::Message const &),scoped_refptr<content::CompositorForwardingMessageFilter> const &,IPC::Message const &> [0x12F859B5+53]
	base::internal::Invoker<base::internal::BindState<void (__thiscall content::CompositorForwardingMessageFilter::*)(IPC::Message const &),scoped_refptr<content::CompositorForwardingMessageFilter>,IPC::Message>,void __cdecl(void)>::RunImpl<void (__thiscall c [0x12F85A23+83]
	base::internal::Invoker<base::internal::BindState<void (__thiscall content::CompositorForwardingMessageFilter::*)(IPC::Message const &),scoped_refptr<content::CompositorForwardingMessageFilter>,IPC::Message>,void __cdecl(void)>::Run [0x12F88514+36]
	base::internal::RunMixin<base::Callback<void __cdecl(void),0,0> >::Run [0x10081184+68]
	base::debug::TaskAnnotator::RunTask [0x1008131F+367]
	base::MessageLoop::RunTask [0x100FD8F4+660]
	base::MessageLoop::DeferOrRunPendingTask [0x100FB6EC+44]
	base::MessageLoop::DoWork [0x100FBCD2+242]
	base::MessagePumpDefault::Run [0x10103B1E+190]
	base::MessageLoop::RunHandler [0x100FD5EC+444]
	base::RunLoop::Run [0x101A4914+52]
	base::Thread::Run [0x1023A63F+319]
	base::Thread::ThreadMain [0x1023BA0B+955]
	base::PlatformThread::Sleep [0x10215E2C+380]
	BaseThreadInitThunk [0x7606337A+18]
	RtlInitializeExceptionChain [0x775B92B2+99]
	RtlInitializeExceptionChain [0x775B9285+54]

Comment 10 by dmazz...@chromium.org, Oct 25 2016 

BTW, I agree with comment #4 - it's confusing that the test names are the same, would prefer if they were distinct.

The only difference is that one runs under content_browsertests vs browser_tests

Comment 11 by w...@chromium.org, Oct 25 2016 

Dale, are you aware of the check failure in video_renderer_algorithm.cc in #9?
Project Member

Comment 12 by bugdroid1@chromium.org, Oct 25 2016 

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

commit d498c4bb664f317f03f1ab4d9badec3f4b03522e
Author: dmazzoni <dmazzoni@chromium.org>
Date: Tue Oct 25 21:59:47 2016

Disable browser_tests : EncryptedMediaTest.FrameSizeChangeVideo on Win

BUG= 655630 
TBR=watk@chromium.org
NOTRY=true

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

[modify] https://crrev.com/d498c4bb664f317f03f1ab4d9badec3f4b03522e/chrome/browser/media/encrypted_media_browsertest.cc

Comment 13 by dalecur...@chromium.org, Oct 26 2016 

Fixing DCHECK in  issue 656231 . Leaving this one open since it predates this issue.
Project Member

Comment 14 by bugdroid1@chromium.org, Nov 5 2016 

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

commit d026f79cc5949df6bae399f58128b470f8061ad7
Author: watk <watk@chromium.org>
Date: Sat Nov 05 00:28:51 2016

Stop suspending the pipeline before HaveFutureData while decoding

Previously we could suspend the pipeline before HaveFutureData but
after the media had been completely loaded, relying on the assumption
that we could use the signal of didLoadingProgress() to resume and check
if the new data got us to HaveFutureData. However, if the media is
completely downloaded, there will be no more didLoadingProgress() calls
which meant we could leave the player suspended forever.

Now we check whether loading is stalled (didLoadingProgress() has not
returned true for least 3 seconds) before suspending before
HaveFutureData. If loading is stalled but we haven't reached
HaveFutureData we assume that the pipeline is waiting for more data to
complete preroll.

BUG= 655630 
TEST=new tests

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

[modify] https://crrev.com/d026f79cc5949df6bae399f58128b470f8061ad7/content/browser/media/encrypted_media_browsertest.cc
[modify] https://crrev.com/d026f79cc5949df6bae399f58128b470f8061ad7/content/renderer/media/android/webmediaplayer_android.cc
[modify] https://crrev.com/d026f79cc5949df6bae399f58128b470f8061ad7/content/renderer/media/android/webmediaplayer_android.h
[modify] https://crrev.com/d026f79cc5949df6bae399f58128b470f8061ad7/content/renderer/media/renderer_webmediaplayer_delegate.cc
[modify] https://crrev.com/d026f79cc5949df6bae399f58128b470f8061ad7/content/renderer/media/renderer_webmediaplayer_delegate_browsertest.cc
[modify] https://crrev.com/d026f79cc5949df6bae399f58128b470f8061ad7/content/renderer/media/webmediaplayer_ms.cc
[modify] https://crrev.com/d026f79cc5949df6bae399f58128b470f8061ad7/content/renderer/media/webmediaplayer_ms.h
[modify] https://crrev.com/d026f79cc5949df6bae399f58128b470f8061ad7/media/blink/webmediaplayer_delegate.h
[modify] https://crrev.com/d026f79cc5949df6bae399f58128b470f8061ad7/media/blink/webmediaplayer_impl.cc
[modify] https://crrev.com/d026f79cc5949df6bae399f58128b470f8061ad7/media/blink/webmediaplayer_impl.h
[modify] https://crrev.com/d026f79cc5949df6bae399f58128b470f8061ad7/media/blink/webmediaplayer_impl_unittest.cc

Comment 15 by w...@chromium.org, Nov 5 2016

Status: Fixed (was: Started)

Comment 16 by dalecur...@chromium.org, Nov 7 2016 

Merge M55?

Comment 17 by w...@chromium.org, Nov 7 2016

Labels: Merge-Request-55

Comment 18 by dimu@chromium.org, Nov 7 2016

Labels: -Merge-Request-55 Merge-Approved-55 Hotlist-Merge-Approved
Your change meets the bar and is auto-approved for M55 (branch: 2883)
Project Member

Comment 19 by bugdroid1@chromium.org, Nov 7 2016

Labels: -merge-approved-55 merge-merged-2883
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/7aae49babcf9acaa0f549fc5d996945a8aba192d

commit 7aae49babcf9acaa0f549fc5d996945a8aba192d
Author: Chris Watkins <watk@chromium.org>
Date: Mon Nov 07 19:50:06 2016

Stop suspending the pipeline before HaveFutureData while decoding

Previously we could suspend the pipeline before HaveFutureData but
after the media had been completely loaded, relying on the assumption
that we could use the signal of didLoadingProgress() to resume and check
if the new data got us to HaveFutureData. However, if the media is
completely downloaded, there will be no more didLoadingProgress() calls
which meant we could leave the player suspended forever.

Now we check whether loading is stalled (didLoadingProgress() has not
returned true for least 3 seconds) before suspending before
HaveFutureData. If loading is stalled but we haven't reached
HaveFutureData we assume that the pipeline is waiting for more data to
complete preroll.

BUG= 655630 
TEST=new tests

Review-Url: https://codereview.chromium.org/2445533002
Cr-Commit-Position: refs/heads/master@{#430086}
(cherry picked from commit d026f79cc5949df6bae399f58128b470f8061ad7)

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

Cr-Commit-Position: refs/branch-heads/2883@{#481}
Cr-Branched-From: 614d31daee2f61b0180df403a8ad43f20b9f6dd7-refs/heads/master@{#423768}

[modify] https://crrev.com/7aae49babcf9acaa0f549fc5d996945a8aba192d/content/renderer/media/android/webmediaplayer_android.cc
[modify] https://crrev.com/7aae49babcf9acaa0f549fc5d996945a8aba192d/content/renderer/media/android/webmediaplayer_android.h
[modify] https://crrev.com/7aae49babcf9acaa0f549fc5d996945a8aba192d/content/renderer/media/renderer_webmediaplayer_delegate.cc
[modify] https://crrev.com/7aae49babcf9acaa0f549fc5d996945a8aba192d/content/renderer/media/renderer_webmediaplayer_delegate_browsertest.cc
[modify] https://crrev.com/7aae49babcf9acaa0f549fc5d996945a8aba192d/content/renderer/media/webmediaplayer_ms.cc
[modify] https://crrev.com/7aae49babcf9acaa0f549fc5d996945a8aba192d/content/renderer/media/webmediaplayer_ms.h
[modify] https://crrev.com/7aae49babcf9acaa0f549fc5d996945a8aba192d/media/blink/webmediaplayer_delegate.h
[modify] https://crrev.com/7aae49babcf9acaa0f549fc5d996945a8aba192d/media/blink/webmediaplayer_impl.cc
[modify] https://crrev.com/7aae49babcf9acaa0f549fc5d996945a8aba192d/media/blink/webmediaplayer_impl.h
[modify] https://crrev.com/7aae49babcf9acaa0f549fc5d996945a8aba192d/media/blink/webmediaplayer_impl_unittest.cc

Comment 20 by dpranke@chromium.org, Jan 24 2018

Components: Tests>Disabled
Labels: Test-Disabled
►

Sign in to add a comment