New issue
Advanced search Search tips

Issue 709080 link

Starred by 1 user

Issue metadata

Status: Fixed
Owner:
Closed: Aug 31
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 2
Type: Bug

Blocking:
issue 703263



Sign in to add a comment

LayerWithRealCompositorTest.ReportMetrics flaky on Windows

Project Member Reported by ellyjo...@chromium.org, Apr 6 2017

Issue description

This test is quite flaky: https://test-results.appspot.com/dashboards/flakiness_dashboard.html#tests=LayerWithRealCompositorTest.ReportMetrics&testType=compositor_unittests

The last reported failure was four timeouts.

varkha@, can you take a peek? :)
 
Project Member

Comment 1 by bugdroid1@chromium.org, Apr 6 2017

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

commit 2ad62ba5846137528f1e75332c4f0f54dab0593e
Author: ellyjones <ellyjones@chromium.org>
Date: Thu Apr 06 18:14:02 2017

compositor: disable LayerWithRealCompositorTest.ReportMetrics

This test is quite flaky, especially on win7 dbg.

BUG= 709080 
TBR=varkha@chromium.org

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

[modify] https://crrev.com/2ad62ba5846137528f1e75332c4f0f54dab0593e/ui/compositor/layer_unittest.cc

Comment 2 by varkha@chromium.org, Apr 12 2017

Cc: staraz@chromium.org
+staraz@, could the flakiness be a result of https://codereview.chromium.org/2776973004/diff/80001/ui/compositor/layer_unittest.cc ?

Comment 3 by staraz@chromium.org, Apr 12 2017

Seem like it.
I'm reverting my CL.

Comment 4 by varkha@chromium.org, Apr 13 2017

Status: Started (was: Assigned)
I will be restoring the test.
Draft CL at https://codereview.chromium.org/2812403002
Project Member

Comment 5 by bugdroid1@chromium.org, Apr 13 2017

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

commit 468178c6ee34ad0880f8fa21dd3d46a8a9657cac
Author: varkha <varkha@chromium.org>
Date: Thu Apr 13 02:57:34 2017

Restores LayerWithRealCompositorTest.ReportMetrics test

The flake was likely a result of this change:
https://codereview.chromium.org/2776973004/diff/80001/ui/compositor/layer_unittest.cc

That change is now reverted in https://codereview.chromium.org/2815073002/
Restoring the test.

BUG= 709080 
TBR=ellyjones@chromium.org

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

[modify] https://crrev.com/468178c6ee34ad0880f8fa21dd3d46a8a9657cac/ui/compositor/layer_unittest.cc

Comment 6 by varkha@chromium.org, Apr 13 2017

Haven't realized that https://codereview.chromium.org/2815073002/ hasn't landed yet. I'll revert #5 unless https://codereview.chromium.org/2815073002 lands soon.

Comment 7 by staraz@chromium.org, Apr 13 2017

I just manually rebased the patch. It should land soon.
Project Member

Comment 8 by bugdroid1@chromium.org, Apr 13 2017

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

commit b14cc10ccf83caad627156403239fc6758c2dbbb
Author: staraz <staraz@chromium.org>
Date: Thu Apr 13 18:06:39 2017

Revert of Remove CompositorObserver::OnCompositingEnded() (patchset #5 id:80001 of https://codereview.chromium.org/2776973004/ )

Reason for revert:
Cause LayerWithRealCompositorTest.ReportMetrics to
be flaky on Windows.

We don't need this change anyway now that
MojoCompositorFrameSinkClient::WillDrawSurface() is
removed.

Original issue's description:
> Remove CompositorObserver::OnCompositingEnded()
>
> OnCompistingEnded() is only used in tests. By replacing usages of
> OnCompositingEnded() with OnCompositingStarted(), we are able to remove
> the call to OnCompositingEnded() in
> ui::Compositor::DidReceiveCompositorFrameAck() without making the tests less
> effective.
>
> This is the first step in simplifying CompositorFrameAcks.
>
> BUG= 671202 
>
> Review-Url: https://codereview.chromium.org/2776973004
> Cr-Commit-Position: refs/heads/master@{#460409}
> Committed: https://chromium.googlesource.com/chromium/src/+/ce75f9388f73820bc5bb31401bcc75520f467a3f

TBR=fsamuel@chromium.org,danakj@chromium.org,varkha@chromium.org,sky@chromium.org,asvitkine@chromium.org
# Not skipping CQ checks because original CL landed more than 1 days ago.
BUG= 671202 ,  709080 

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

[modify] https://crrev.com/b14cc10ccf83caad627156403239fc6758c2dbbb/ash/mus/non_client_frame_controller_unittest.cc
[modify] https://crrev.com/b14cc10ccf83caad627156403239fc6758c2dbbb/content/browser/renderer_host/browser_compositor_view_mac.mm
[modify] https://crrev.com/b14cc10ccf83caad627156403239fc6758c2dbbb/content/browser/renderer_host/delegated_frame_host.cc
[modify] https://crrev.com/b14cc10ccf83caad627156403239fc6758c2dbbb/content/browser/renderer_host/delegated_frame_host.h
[modify] https://crrev.com/b14cc10ccf83caad627156403239fc6758c2dbbb/ui/compositor/compositor.cc
[modify] https://crrev.com/b14cc10ccf83caad627156403239fc6758c2dbbb/ui/compositor/compositor_observer.h
[modify] https://crrev.com/b14cc10ccf83caad627156403239fc6758c2dbbb/ui/compositor/compositor_unittest.cc
[modify] https://crrev.com/b14cc10ccf83caad627156403239fc6758c2dbbb/ui/compositor/layer_unittest.cc
[modify] https://crrev.com/b14cc10ccf83caad627156403239fc6758c2dbbb/ui/compositor/test/draw_waiter_for_test.cc
[modify] https://crrev.com/b14cc10ccf83caad627156403239fc6758c2dbbb/ui/compositor/test/draw_waiter_for_test.h
[modify] https://crrev.com/b14cc10ccf83caad627156403239fc6758c2dbbb/ui/snapshot/snapshot_aura_unittest.cc
[modify] https://crrev.com/b14cc10ccf83caad627156403239fc6758c2dbbb/ui/views/controls/scroll_view_unittest.cc
[modify] https://crrev.com/b14cc10ccf83caad627156403239fc6758c2dbbb/ui/views/view_unittest.cc

Comment 9 by rogerm@chromium.org, Apr 19 2017

This flakiness is still happening.

Disabling this test on windows...
Project Member

Comment 10 by bugdroid1@chromium.org, Apr 19 2017

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

commit 69dd6905cf64dd3943c60fca73d6158236fbd8c8
Author: rogerm <rogerm@chromium.org>
Date: Wed Apr 19 18:17:25 2017

Disable flaky LayerWithRealCompositorTest.ReportMetrics test on windows.

BUG= 709080 
TBR=varkha@chromium.org

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

[modify] https://crrev.com/69dd6905cf64dd3943c60fca73d6158236fbd8c8/ui/compositor/layer_unittest.cc

Cc: -staraz@chromium.org rogerm@chromium.org varkha@chromium.org
Owner: staraz@chromium.org
Status: Assigned (was: Started)
staraz@, was there a reason that WaitForDraw wasn't restored to be WaitForSwap() in LayerWithRealCompositorTest.ReportMetrics when you landed CL in comment #8?I wonder if that is still causing the flake. Can you see if it is still flaky after restoring this?
Status: Started (was: Assigned)
Sorry I must have missed that line while reverting.
I uploaded another CL and it should land soon.
Project Member

Comment 13 by bugdroid1@chromium.org, Apr 20 2017

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

commit 349c2bfb9b604092ff8c4a78752cc7e25a1fca34
Author: staraz <staraz@chromium.org>
Date: Thu Apr 20 12:47:40 2017

Use WaitForSwap in LayerWithRealCompositorTest.ReportMetrics

Replace WaitForDraw with WaitForSwap in
LayerWithRealCompositorTest.ReportMetrics since WaitForDraw causes the test to
be flaky.

BUG= 709080 

TBR=danakj@chromium.org

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

[modify] https://crrev.com/349c2bfb9b604092ff8c4a78752cc7e25a1fca34/ui/compositor/layer_unittest.cc

Status: Fixed (was: Started)
Project Member

Comment 15 by bugdroid1@chromium.org, Apr 20 2017

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

commit f7de9f05260ea183c85c8f360de32d62ddf55a0a
Author: staraz <staraz@chromium.org>
Date: Thu Apr 20 14:29:11 2017

Enable LayerWithRealCompositorTest.ReportMetrics

The test was made non-flaky in
https://crrev.com/349c2bfb9b604092ff8c4a78752cc7e25a1fca34

BUG= 709080 

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

[modify] https://crrev.com/f7de9f05260ea183c85c8f360de32d62ddf55a0a/ui/compositor/layer_unittest.cc

Labels: Sheriff-Chromium
Status: Assigned (was: Fixed)
This test has timed out (4 runs) again in the build https://build.chromium.org/p/chromium.win/builders/Win7%20Tests%20%28dbg%29%281%29/builds/59467.

I am waiting for the second build to see whether this is consistent this time.


Labels: -Sheriff-Chromium
The next build is green:
https://build.chromium.org/p/chromium.win/builders/Win7%20Tests%20%28dbg%29%281%29/builds/59468

Please have a look into this.
Status: Fixed (was: Assigned)
Marking it as fixed as bots are green.
Components: Internals>Compositing
Labels: OS-Windows
Status: Assigned (was: Fixed)
The Windows test bots still flake on this even after the CL in #15, although maybe less frequently. Could have been a problem with the original test itself.
Cc: flackr@chromium.org suzyh@chromium.org
Sheriff here. This test is flakily timing out, mostly on Win7 Tests (dbg). Disabling in https://codereview.chromium.org/2851353003.

Eyeballing the test, it looks like it's waiting for the TestMetricsReporter to do something during an animation. Are we sure that it's ready before the animation actually runs?
Owner: varkha@chromium.org
Assigning back to varkha@ since my change is reverted and the test is still 
flaky.
I speculatively increased the animation time in the test from 100ms to 1000ms and have run it through win_chromium_dbg_ng a dozen times: https://codereview.chromium.org/2857853004

Unfortunately since the test is so infrequently flaky, I'm not actually sure whether this is a solution to the issue.

My thinking was that if the animation has finished before the reporter is ready to be updated in some way, then it spends its entire time in WaitForSwap calls waiting for the animation to progress.

I don't have enough of an understanding of the compositor side of animations to know if this is a plausible explanation. Even if it is, extending the time of the animation may not be the appropriate fix; rather, the appropriate fix may be to synchronize one thing to the other.
Cc: alancutter@chromium.org

Comment 24 by suzyh@chromium.org, Jun 13 2017

Cc: -suzyh@chromium.org
Cc: -varkha@chromium.org
Owner: jonr...@chromium.org
jonross@, can you PTAL? I think the suggestion in #22 makes sense so if that could land there would be one more test to rely on.
Blocking: 703263
Cc: -rogerm@chromium.org
Cc: jonr...@chromium.org
Owner: wutao@chromium.org
Assigning to wutao@ who added HidingWindowMetricsReporter which is the only usage of the AnimationMetricsReporter for UMA.

I did some debugging, this can be reproduced quite frequently by setting the animation duration 10 10ms. Including on Linux.

So what happens is LayerAnimationElement::ProgressToEnd only ever reports metrics if there's been more than 1 frame. While I would expect this to be rare in the wild, I'm not sure what usage the metrics for a 1 frame animation would be. wutao@ who is using the UMA stat could comment more.

The test then timesout waiting upon a second WaitForSwap which never arrives as the animation is done.

I'd say that either the reporting needs to be updated to handle single frame data.
Or the test needs to be re-written in a manner where the time source is mocked out, and controlled within the unit test itself.
An example of mocking out the time source of BeginFrameArgs is in scheduler_unittest.cc SendNextBeginFrame

https://cs.chromium.org/chromium/src/cc/scheduler/scheduler_unittest.cc?rcl=9777575af98a9e803b7fbef0a94c22af946f5ae9&l=472
Cc: wutao@chromium.org
Owner: jonr...@chromium.org
Hi jonross@,

HidingWindowMetricsReporter is one of the subclass of ui::AnimationMetricsReporter, which uses LayerAnimationElement::ProgressToEnd to report UMA.

Maybe fixing the reporter logic to handle single frame is better? Although one frame animation is not expected.
 

The other examples are:
1. OverviewEnterMetricsReporter, https://cs.chromium.org/chromium/src/ash/wm/overview/scoped_overview_animation_settings.cc?l=61&rcl=9ebcff160836f5c7057cad3694d19e7237475c26

2. StateAnimationMetricsReporter:
https://cs.chromium.org/chromium/src/ash/app_list/views/app_list_view.cc?l=187&rcl=176a3a3154870bc3e0722934c03d6dc3b5dae748
Status: Started (was: Assigned)
Project Member

Comment 32 by bugdroid1@chromium.org, Aug 31

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

commit 1ec7d99f5011c8ea2cf868011e93f04480a7ba52
Author: jonross <jonross@chromium.org>
Date: Fri Aug 31 03:55:54 2018

Update CompositorTestSuite mocking of Time

LayerWithRealCompositorTest.ReportMetrics was racy due to the fact that
LayerAnimationElement and SchedulerStateMachine's timing and task queues cannot
be mocked out.

This left the test vulnerable to differences in timing on bots.

The test had a certain expectation of the order of events, which is not actually
a guarantee. An animation's frame could be generated before it entered its wait
loop. Similarly a animation could be delayed in executing for so long that not
enough frames were generated to actually create a report.

This updates the test to mock out time, so that it can reliably control the order of events.

The test has also been moved to LayerAnimatorTest.ReportMetrics. LayerWithRealCompositorTest
utilizes a TestCompositorHost in order to control the Compositor throughout the tests.
This was done by having CompositorTestSuite always create a ScopedTaskEnvironment.
Unfortunately this causes a thread race with base::TimeTicks::Now, as this thread starts
enqueuing work before an individual test can mock out time.

This change also updates CompositorTestSuite to not create the ScopedTaskEnvironment.
Instead each test suite which desires to mock out the time of task runners, must explicitly
create one. Thus allowing tests which need not a full Compositor thread, can instead
be able to mock time separately.

TBR=sadrul@chromium.org
TEST=LayerWithRealCompositorTest.ReportMetrics
LayerAnimatorTest.ReportMetrics

Bug:  709080 
Change-Id: Ia12cdcdf2b6c67c8abc21399eae66cdb1d0d1eb1
Reviewed-on: https://chromium-review.googlesource.com/1157234
Commit-Queue: Jonathan Ross <jonross@chromium.org>
Reviewed-by: Robert Flack <flackr@chromium.org>
Cr-Commit-Position: refs/heads/master@{#587940}
[modify] https://crrev.com/1ec7d99f5011c8ea2cf868011e93f04480a7ba52/ui/compositor/compositor_unittest.cc
[modify] https://crrev.com/1ec7d99f5011c8ea2cf868011e93f04480a7ba52/ui/compositor/layer_animator_unittest.cc
[modify] https://crrev.com/1ec7d99f5011c8ea2cf868011e93f04480a7ba52/ui/compositor/layer_unittest.cc
[modify] https://crrev.com/1ec7d99f5011c8ea2cf868011e93f04480a7ba52/ui/compositor/test/test_layer_animation_delegate.cc
[modify] https://crrev.com/1ec7d99f5011c8ea2cf868011e93f04480a7ba52/ui/compositor/test/test_layer_animation_delegate.h
[modify] https://crrev.com/1ec7d99f5011c8ea2cf868011e93f04480a7ba52/ui/compositor/test/test_suite.cc
[modify] https://crrev.com/1ec7d99f5011c8ea2cf868011e93f04480a7ba52/ui/compositor/test/test_suite.h
[modify] https://crrev.com/1ec7d99f5011c8ea2cf868011e93f04480a7ba52/ui/snapshot/snapshot_aura_unittest.cc

Status: Fixed (was: Started)

Sign in to add a comment