AudioOutputDeviceTest.VerifyDataFlow is flaky on Fuchsia |
|||||
Issue descriptionAudioOutputDeviceTest.VerifyDataFlow is flaking, from what seems to be a race condition in which the test is checking the state of the Render() mock callback before the AudioOutputDevice has finished processing. (Note: Fuchsia on QEMU uses a suboptimal process scheduler which has a tendency to unearth latent race conditions.) Failing runs: https://chromium-swarm.appspot.com/task?id=3d30a92a74901310&refresh=10 https://chromium-swarm.appspot.com/task?id=3d30a92a74901310&refresh=10&show_raw=1 Output: [ RUN ] AudioOutputDeviceTest.VerifyDataFlow [227091:1971274495:0430/183924.706692:155363385:ERROR:platform_thread_fuchsia.cc(41)] Not implemented reached in static void base::PlatformThread::SetCurrentThreadPriority(base::ThreadPriority)setting ThreadPriority 3 ../../media/audio/audio_output_device_unittest.cc:392: Failure Actual function call count doesn't match EXPECT_CALL(env.callback, Render(kDelay, env.time_stamp, kFramesSkipped, NotNull()))... Expected: to be called once Actual: never called - unsatisfied and active Stack trace: #00: pc 0x4b062a5bfb79 (libmojo_base_lib.so,0xa30f6941b79) #01: pc 0x4b062a5ce987 (libmojo_base_lib.so,0xa30f6950987) #02: pc 0x4b062a5cdd27 (libmojo_base_lib.so,0xa30f694fd27) #03: pc 0x4b062a5ade5d (libmojo_base_lib.so,0xa30f692fe5d) #04: pc 0x4b0629cca858 (libmojo_base_lib.so,0xa30f604c858) #05: pc 0x4b062a5b72e3 (libmojo_base_lib.so,0xa30f69392e3) #06: pc 0x4b062a5b8765 (libmojo_base_lib.so,0xa30f693a765) #07: pc 0x4b062a5b8912 (libmojo_base_lib.so,0xa30f693a912) #08: pc 0x4b0629d212f4 (libmojo_base_lib.so,0xa30f60a32f4) #09: pc 0x4b062a6045de (libmojo_base_lib.so,0xa30f69865de) ../../media/audio/audio_output_device_unittest.cc:407: Failure Expected equality of these values: kAudioData Which is: 0.618 test_bus->channel(0)[i] Which is: 0 Stack trace: #00: pc 0x4b062a5bfb79 (libmojo_base_lib.so,0xa30f6941b79) #01: pc 0x4b062a5ce987 (libmojo_base_lib.so,0xa30f6950987) #02: pc 0x4b062a5cdd27 (libmojo_base_lib.so,0xa30f694fd27) #03: pc 0x4b0629d213ea (libmojo_base_lib.so,0xa30f60a33ea) #04: pc 0x4b062a6045de (libmojo_base_lib.so,0xa30f69865de) unknown file: Failure Uninteresting mock function call - returning default value. Function call: Render(0.000123 s, 155337963 bogo-microseconds, 456, 0x26795e71f000) Returns: 0 Stack trace: #00: pc 0x4b062a5bfb79 (libmojo_base_lib.so,0xa30f6941b79) #01: pc 0x4b062a5ce987 (libmojo_base_lib.so,0xa30f6950987) #02: pc 0x4b062a5cdd27 (libmojo_base_lib.so,0xa30f694fd27) #03: pc 0x4b062a5ade5d (libmojo_base_lib.so,0xa30f692fe5d) #04: pc 0x4b0629cca858 (libmojo_base_lib.so,0xa30f604c858) #05: pc 0x4b062a5b435d (libmojo_base_lib.so,0xa30f693635d) #06: pc 0x4b062a5b526e (libmojo_base_lib.so,0xa30f693726e) #07: pc 0x4b0629d31352 (libmojo_base_lib.so,0xa30f60b3352) #08: pc 0x4b0629d312eb (libmojo_base_lib.so,0xa30f60b32eb) #09: pc 0x4b0629d253cb (libmojo_base_lib.so,0xa30f60a73cb) #10: media::AudioOutputDevice::AudioThreadCallback::Process(unsigned int) at ??:? #11: media::AudioDeviceThread::ThreadMain() at ??:? #12: base::(anonymous namespace)::ThreadFunc(void*) at platform_thread_posix.cc:? #13: pc 0x70ac3ba33cd6 (libc.so,0x17cd6) #14: pc 0x70ac3baa9d59 (libc.so,0x8dd59)
,
May 9 2018
,
Jun 4 2018
This is still flaking, e.g. see: https://ci.chromium.org/buildbot/chromium.fyi/Fuchsia/18264 In that run the AudioOutputDeviceTest.VerifyDataFlow test failed both on the first run and on the retry; if this were an issue with the test being too close to the timeouts then I'd expect that one of the runs would succeed with the new increased timeouts. In this failure, for instance, the first run takes 8s, but the second takes only 2s to fail.
,
Jun 4 2018
Looking at the VerifyDataFlow test, it is setting an EXPECT_CALL() on |env.callback| and then making the |env.reader| calls which should trigger that to be met, but the callback will actually be invoked on the AudioOutputDevice' thread, so there is no reason to assume that that will have happened before we reach the Mock::VerifyAndClear() call. Without some explicit synchronization with the AudioDeviceThread between |env.reader->Read()| and |Mock::VerifyAndClear(&env.callback)|, this test is inherently flaky, I think.
,
Jun 5 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/227e9498a3acc26c08ec01bf9b195ba931f227b5 commit 227e9498a3acc26c08ec01bf9b195ba931f227b5 Author: Wez <wez@chromium.org> Date: Tue Jun 05 05:52:10 2018 Increase timeout for AudioOutputDeviceTests under Fuchsia. Increase the max-wait timeout from 50ms to 250ms, to allow for extreme scheduler jank under nested virtualization. Bug: 838367 , 848926 Cq-Include-Trybots: luci.chromium.try:android_optional_gpu_tests_rel;luci.chromium.try:linux_optional_gpu_tests_rel;luci.chromium.try:mac_optional_gpu_tests_rel;luci.chromium.try:win_optional_gpu_tests_rel Change-Id: If70da6f568293f45e7375a8d4645c27883c34872 Reviewed-on: https://chromium-review.googlesource.com/1086287 Commit-Queue: Max Morin <maxmorin@chromium.org> Reviewed-by: Max Morin <maxmorin@chromium.org> Cr-Commit-Position: refs/heads/master@{#564370} [modify] https://crrev.com/227e9498a3acc26c08ec01bf9b195ba931f227b5/media/audio/audio_output_device_unittest.cc
,
Jun 6 2018
|
|||||
►
Sign in to add a comment |
|||||
Comment 1 by bugdroid1@chromium.org
, May 1 2018