Could someone from the media team please take a look at this? Could the PIPELINE_ERROR be the reason the AbortError was raised? Why would this be flaky?

Sources for the test:
src/third_party/webgl/src/sdk/tests/conformance2/textures/video/tex-2d-rgba8-rgba-unsigned_byte.html

Need to run with --enable-unsafe-es3-apis, or:

./content/test/gpu/run_gpu_integration_test.py webgl_conformance --browser=release --webgl-conformance-version=2.0.0 --webgl2-only=true --test-filter=WebglConformance_conformance2_textures_video_tex_2d_rgba8_rgba_unsigned_byte

which will launch the browser for you.

Changing the flag to Internals>Media since it's more likely to be a pipeline issue.

This is reported because the audio output device reported an error. +olka, grunell who have made changes here recently.

grunell@, can you take a look and assign appropriately? 

Error code(88890004) returned by system layer seems to be AUDCLNT_E_DEVICE_INVALIDATED
(The audio endpoint device has been unplugged, or the audio hardware or associated hardware resources have been reconfigured, disabled, removed, or otherwise made unavailable for use)
So
[3816:2228:0708/144238:ERROR:render_media_log.cc(25)] MediaEvent: PIPELINE_ERROR audio renderer: output device reported an error
- looks reasonable.

Seems to be an audio hardware problem.

What is the expected test behavior in such a case?

These video files shouldn't have an audio track to the best of my knowledge. Have you confirmed that they do?

Why would opening the audio device be flaky? It should be 100% reliable.

From what I see, media::AudioRendererImpl is being initialized and requests device output parameters, which results in audio output device creation.
Then media::DecoderStream<>::OnDecoderSelected() is called which starts audio playout.

88890004 error is reported in successful runs as well (for example https://build.chromium.org/p/chromium.gpu.fyi/builders/Win7%20Release%20%28NVIDIA%29/builds/26806), looks like it means there is no audio hardware on the system and it results in failing back to the fake device.

So, only these two lines are relevant:
[3816:2228:0708/144238:ERROR:render_media_log.cc(25)] MediaEvent: PIPELINE_ERROR audio renderer: output device reported an error
[628:1440:0708/144240:INFO:CONSOLE(0)] "Uncaught (in promise) AbortError: The play() request was interrupted by a call to pause().", 

*correction: "there is no audio hardware on the system and it results in failing back to the fake audio parameters".

The only thing I can say so far is AudioRendererImpl::OnRenderError() was called in one of many places it can be called.

kbr@, are you aware of other failing runs?

I haven't found any more on the builder (https://build.chromium.org/p/chromium.gpu.fyi/builders/Win7%20Release%20%28NVIDIA%29?numbuilds=200), but probably I missed something.

olka@: I looked through the Windows bots on https://build.chromium.org/p/chromium.gpu.fyi/builders but don't see other instances of this failure.

These machines run their tests on physical hardware which is almost never touched, and definitely not during test runs, so it's difficult to understand why the audio device would disappear suddenly.

What can be done to make Chrome more robust in this situation? Marking all of the video-related WebGL tests as flaky is not a good solution.

I'm not sure if there is audio hardware there at all. From the logs of successful runs it seems there is no.

The error in question could appear because, for example, device authorization timed out for some reason (where "device" is a logical entity which still exists even if there is not hardware). From what we have here it's hard to say what caused the problem; and it does not seem to be reproducible.


kbr@:
"What can be done to make Chrome more robust in this situation?"
- By "this situation" do you mean a pipeline error? From what I see, it's intentional that pipeline stops as soon as any error is encountered (https://cs.chromium.org/chromium/src/media/base/pipeline_impl.cc?cl=GROK&gsn=OnError&l=1141). 

+alokp@ - you made some major changes in PipelineImpl recently, so I guess you know the area, could you comment on this?


"Marking all of the video-related WebGL tests as flaky is not a good solution"
- It caused one failure of a single test, and it's almost a month since the failure, and it does not seem to cause any problems any more. Current flakiness of the tests is caused by something else.
I'm tempted to close it as WontFix.

I'd like a reasonable effort to be made to:

 - Understand why the flakiness crept in, given that the physical hardware and the OS that it's running have not changed recently
 - Understand why the flakiness now seems to be resolved

before closing this as WontFix.

Another flake:

https://build.chromium.org/p/tryserver.chromium.win/builders/win_optional_gpu_tests_rel/builds/3773

WebglConformance_conformance2_textures_video_tex_3d_r32f_red_float (gpu_tests.webgl_conformance_integration_test.WebGLConformanceIntegrationTest) ... [2512:3504:0915/215016:ERROR:interface_registry.cc(99)] Failed to locate a binder for interface: dom_distiller::mojom::DistillabilityService
[3600:3172:0915/215017:ERROR:render_media_log.cc(25)] MediaEvent: PIPELINE_ERROR audio renderer: output device reported an error
[2512:2928:0915/215016:ERROR:audio_manager_win.cc(464)] GetPreferredAudioParameters failed: 88890004
[2512:3504:0915/215020:ERROR:interface_registry.cc(99)] Failed to locate a binder for interface: dom_distiller::mojom::DistillabilityService
[2512:3504:0915/215020:INFO:CONSOLE(0)] "Uncaught (in promise) AbortError: The play() request was interrupted by a call to pause().", source: http://127.0.0.1:56757/conformance2/textures/video/tex-3d-r32f-red-float.html?webglVersion=2 (0)


I would like to add a command line flag which disables the use of the actual audio hardware on the machine, so failures like these do not affect our group's tests. Does such a flag exist today?

You're already using a fake device on these machines since they don't have audio hardware -- see the messages in the log about falling back to a fake device.

I think this is something to do with a timeout of the device authorization triggering an output device error. Perhaps instead of ending playback this should just restart using a NullAudioSink?

Thanks Dale for pointing that out. You're right, upon each browser restart the following is printed:

[3524:2484:0915/215538:ERROR:audio_manager_win.cc(464)] GetPreferredAudioParameters failed: 88890004
[3524:2484:0915/215538:ERROR:audio_manager_win.cc(464)] GetPreferredAudioParameters failed: 88890004
[3524:2484:0915/215538:ERROR:audio_output_resampler.cc(295)] Unable to open audio device in low latency mode.  Falling back to high latency audio output.
[3524:2484:0915/215538:ERROR:audio_output_resampler.cc(305)] Unable to open audio device in high latency mode.  Falling back to fake audio output.

Falling back in the way you suggest sounds fine to me, at least for these tests. They aren't testing the audio subsystem, so we want to eliminate all sources of flakiness associated with it.

(re: no hardware - see #13)

Could you clarify about NullAudioSink: at which level a switch to it should take place? Are you talking about the failing test or about the pipeline? (I'm not really familiar with media pipeline)

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

commit baa81d2463a8e2d7869a71044579b29981305ac9
Author: olka <olka@chromium.org>
Date: Thu Sep 22 12:09:04 2016

Log a warning when device authorization times out.

BUG= 626862 

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

[modify] https://crrev.com/baa81d2463a8e2d7869a71044579b29981305ac9/media/audio/audio_output_device.cc

Yes, I was talking about replacing the error with a switch, but on second consideration I think deflaking the timeout might be more useful.

Caveat, if this results in a invalid parameters detected here: https://cs.chromium.org/chromium/src/media/renderers/audio_renderer_impl.cc?l=345 I think we should switch to a fake instead of letting an error fall through. I'll put a patch together for this and see if it helps anything.

Actually my idea doesn't explain the issue since AudioOutputDevice doesn't know about AudioRendererImpl at that point, so it can't be sending an error causing abort.

Audio output appears to "work" all the way up to AudioOutputResampler::OpenStream() which is doing the fake fallback. So up to that point the rest of the code thinks it has a valid output device.

I think this is just spurious timeouts happening on the bots, but the log you added above will help sleuth this out for sure.

I see another failure of WebglConformance_conformance2_textures_video_tex_3d_rgb8_rgb_unsigned_byte here:
https://build.chromium.org/p/chromium.gpu.fyi/builders/Win7%20Release%20%28New%20Intel%29/builds/1535/steps/webgl2_conformance_tests/logs/stdio

There is this error:
err: rx::Renderer11::testDeviceLost(2571): The D3D11 device was removed: 0x887A0006
[3444:3212:0922/103538:ERROR:gles2_cmd_decoder.cc(4067)]   GLES2DecoderImpl: Context lost during MakeCurrent.
[3444:3212:0922/103538:ERROR:gpu_command_buffer_stub.cc(387)] Context lost because MakeCurrent failed.
[3444:3212:0922/103538:ERROR:gpu_channel_manager.cc(224)] Exiting GPU process because some drivers cannot recover from problems.

Followed by a stack trace.

According to cwallez@ this may be caused by a TDR.

Another failure of WebglConformance_conformance2_textures_video_tex_2d_r11f_g11f_b10f_rgb_half_float here:
https://build.chromium.org/p/chromium.gpu.fyi/builders/Win7%20Release%20%28NVIDIA%29/builds/27565/steps/webgl2_conformance_tests%20on%20NVIDIA%20GPU%20on%20Windows%20on%20Windows-2008ServerR2-SP1/logs/stdio

This time with the old "GetPreferredAudioParameters failed: 88890004" messages.

#22: there's a suppression in webgl2_conformance_expectations.py for that:

    # It's unfortunate that these suppressions need to be so broad, but it
    # looks like the D3D11 device can be lost spontaneously on this
    # configuration while running basically any test.
    self.Flaky('conformance/*', ['win', 'intel'], bug= 628395 )
    self.Flaky('conformance2/*', ['win', 'intel'], bug= 628395 )
    self.Flaky('deqp/*', ['win', 'intel'], bug= 628395 )

I echo that these are very unfortunate suppressions. Did they seem to take effect for that failure?

Perhaps they did - the test was not reported as a failure, but the whole suite excepted. I thought maybe because of this test, since it's near the end of the log, but now I suspect maybe it timed out after 3 hours?

Another failure mode:

https://build.chromium.org/p/tryserver.chromium.win/builders/win_optional_gpu_tests_rel/builds/3982

from https://codereview.chromium.org/2363833002/

[4948:3384:0923/115245:FATAL:video_renderer_impl.cc(307)] Check failed: buffering_state_ == BUFFERING_HAVE_NOTHING (1 vs. 0)
Backtrace:
	base::debug::StackTrace::StackTrace [0x60776097+23]
	logging::LogMessage::~LogMessage [0x6071E931+49]
	media::VideoRendererImpl::OnTimeStateChanged [0x6203F618+180]
	media::RendererImpl::StartPlayback [0x6203DBED+410]
	media::RendererImpl::OnBufferingStateChange [0x6203C1F9+1041]
	media::RendererImpl::RendererClientInternal::OnBufferingStateChange [0x6203BDE4+17]
	media::AudioRendererImpl::OnBufferingStateChange [0x62038838+97]
	base::internal::InvokeHelper<1,void>::MakeItSo<void (__thiscall media::WebMediaPlayerImpl::*const &)(enum media::PipelineStatus),base::WeakPtr<media::WebMediaPlayerImpl> const &,enum media::PipelineStatus> [0x623B5C39+43]
	base::internal::Invoker<base::internal::BindState<void (__thiscall media::WebMediaPlayerImpl::*)(enum media::BufferingState),base::WeakPtr<media::WebMediaPlayerImpl>,enum media::BufferingState>,void __cdecl(void)>::Run [0x60CF60DD+23]
	base::debug::TaskAnnotator::RunTask [0x6077B10B+267]
	base::MessageLoop::RunTask [0x60728583+1203]
	base::MessageLoop::DoWork [0x60727855+597]
	base::MessagePumpDefault::Run [0x6077DA50+416]
	base::MessageLoop::RunHandler [0x607280C7+103]
	base::RunLoop::Run [0x60762D09+41]
	base::Thread::Run [0x60761E9D+173]
	base::Thread::ThreadMain [0x6076276E+622]
	base::PlatformThread::Sleep [0x607382F2+290]
	BaseThreadInitThunk [0x76E2337A+18]
	RtlInitializeExceptionChain [0x77A092B2+99]
	RtlInitializeExceptionChain [0x77A09285+54]

Thanks, I have that on my plate to look at,  issue 630860  - it fell off my radar though, sorry -- will try to get to it today. I think the dcheck can just be deleted, but needs some more thought.

Could we limit this bug to dealing with the pipeline error described in #1? I unfortunately cannot handle all those various causes of flakiness.

What happens in #1 (AbortError) resembles  Issue 644622  to me, which appeared after pipeline refactoring.
Does something like device switch happens in the tests?

+guidou@ - Could you take a look if this failure looks familiar?

Sorry for the delay. I missed this cc.
This failure is definitely not  issue 644622 .
The AbortError in this case seems to be thrown by the HTMLMediaElement here https://cs.chromium.org/chromium/src/third_party/WebKit/Source/core/html/HTMLMediaElement.cpp?q=%22request+was+interrupted+by+a+call+to+pause%22&sq=package:chromium&dr=C&l=3920

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

commit 36e6930d420b5549b3dfdde51ae22da03b3a01ff
Author: guidou <guidou@chromium.org>
Date: Thu Oct 13 08:27:20 2016

Use NullAudioSink in WebMediaPlayerImpl if the audio sink is not OK.

This implements the recommendation given in  http://crbug.com/626862#c16 

BUG= 626862 

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

[modify] https://crrev.com/36e6930d420b5549b3dfdde51ae22da03b3a01ff/media/blink/webmediaplayer_impl.cc

Thanks for fixing this source of test flakiness.

https://codereview.chromium.org/2533443002/

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

commit a8d73a9f728dd8d305feadb1a1febc75c40e13b3
Author: olka <olka@chromium.org>
Date: Tue Dec 13 12:03:39 2016

Fallback to null sink moved from WebMediaPlayer to WebAudioSourceProvider::Initialize(), so that we do it on media thread. UMA stats for AudioOutputDevice status and for fallbacks to null sink.

BUG= 668506 , 668201 ,663546, 626862 , 673291 
CQ_INCLUDE_TRYBOTS=master.tryserver.chromium.linux:linux_optional_gpu_tests_rel;master.tryserver.chromium.mac:mac_optional_gpu_tests_rel;master.tryserver.chromium.win:win_optional_gpu_tests_rel
TBR=dalecurtis@chromium.org,dcheng@chromium.org,holte@chromium.org
NOTRY=true
NOPRESUBMIT=true

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

Review-Url: https://codereview.chromium.org/2569883003
Cr-Commit-Position: refs/branch-heads/2924@{#472}
Cr-Branched-From: 3a87aecc31cd1ffe751dd72c04e5a96a1fc8108a-refs/heads/master@{#433059}

[modify] https://crrev.com/a8d73a9f728dd8d305feadb1a1febc75c40e13b3/content/common/media/audio_messages.h
[modify] https://crrev.com/a8d73a9f728dd8d305feadb1a1febc75c40e13b3/content/renderer/media/html_audio_element_capturer_source_unittest.cc
[modify] https://crrev.com/a8d73a9f728dd8d305feadb1a1febc75c40e13b3/media/audio/audio_output_device.cc
[modify] https://crrev.com/a8d73a9f728dd8d305feadb1a1febc75c40e13b3/media/audio/null_audio_sink.cc
[modify] https://crrev.com/a8d73a9f728dd8d305feadb1a1febc75c40e13b3/media/base/output_device_info.h
[modify] https://crrev.com/a8d73a9f728dd8d305feadb1a1febc75c40e13b3/media/blink/webaudiosourceprovider_impl.cc
[modify] https://crrev.com/a8d73a9f728dd8d305feadb1a1febc75c40e13b3/media/blink/webaudiosourceprovider_impl.h
[modify] https://crrev.com/a8d73a9f728dd8d305feadb1a1febc75c40e13b3/media/blink/webaudiosourceprovider_impl_unittest.cc
[modify] https://crrev.com/a8d73a9f728dd8d305feadb1a1febc75c40e13b3/media/blink/webmediaplayer_impl.cc
[modify] https://crrev.com/a8d73a9f728dd8d305feadb1a1febc75c40e13b3/tools/metrics/histograms/histograms.xml