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

Issue 632544 link

Starred by 2 users

Issue metadata

Status: Fixed
Owner:
ooo
Closed: Sep 2016
Cc:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 2
Type: Bug

Blocking:
issue 606056



Sign in to add a comment

MainFrameBeforeActivation fails to ever send new main frame in tests

Project Member Reported by danakj@chromium.org, Jul 29 2016

Issue description

Currently these tests use a FakeOutputSurface which is doing *something* a little different.

When I switch them to use a more real delegating output surface, and a Display/DisplayScheduler/BFS, they fail. They fail because in cc::Scheduler it determines that can_activate_before_deadline is true. And then it stays true forever while these tests have blocked activation, so we never send a main frame.

sunnyps says this is a bug and to ask you about it, brianderson.
 

Comment 1 by danakj@chromium.org, Jul 29 2016

This is what a pass looks like with a FakeOutputSurface:

[ RUN      ] LayerTreeHostScrollTestScrollMFBA.RunMultiThread_DelegatingRenderer
[31914:31915:0728/181024:1404710795216:ERROR:scheduler.cc(457)] can_activate_before_deadline 0
[31914:31915:0728/181024:1404710795372:ERROR:scheduler_state_machine.cc(837)] INSIDE IMPL FRAME
[31914:31914:0728/181024:1404710795681:ERROR:layer_tree_host_unittest_scroll.cc(1536)] UpdateLayerTreeHost 0
[31914:31915:0728/181024:1404710796304:ERROR:layer_tree_host_unittest_scroll.cc(1560)] ReadyToCommitOnThread 0
[31914:31915:0728/181024:1404710796371:ERROR:scheduler_state_machine.cc(589)] WillCommit became 0 idle is 0
[31914:31915:0728/181024:1404710798852:ERROR:scheduler_state_machine.cc(856)] DEADLNE
[31914:31915:0728/181024:1404710799226:ERROR:layer_tree_host_unittest_scroll.cc(1577)] DrawLayersOnThread 0
[31914:31915:0728/181024:1404710799365:ERROR:scheduler_state_machine.cc(992)] DidSwapBuffers
[31914:31915:0728/181024:1404710799628:ERROR:scheduler_state_machine.cc(870)] IDLE
[31914:31915:0728/181024:1404710799796:ERROR:scheduler_state_machine.cc(1005)] DidSwapBuffersComplete
[31914:31915:0728/181024:1404710800150:ERROR:scheduler.cc(457)] can_activate_before_deadline 0
[31914:31915:0728/181024:1404710800203:ERROR:scheduler_state_machine.cc(837)] INSIDE IMPL FRAME
[31914:31914:0728/181024:1404710800450:ERROR:layer_tree_host_unittest_scroll.cc(1536)] UpdateLayerTreeHost 1
[31914:31915:0728/181024:1404710800911:ERROR:layer_tree_host_unittest_scroll.cc(1560)] ReadyToCommitOnThread 1
[31914:31915:0728/181024:1404710800979:ERROR:scheduler_state_machine.cc(589)] WillCommit became 0 idle is 0
[31914:31915:0728/181024:1404710805160:ERROR:scheduler_state_machine.cc(856)] DEADLNE
[31914:31915:0728/181024:1404710805219:ERROR:scheduler_state_machine.cc(870)] IDLE
[31914:31915:0728/181024:1404710805305:ERROR:scheduler.cc(457)] can_activate_before_deadline 0
[31914:31915:0728/181024:1404710805375:ERROR:scheduler_state_machine.cc(837)] INSIDE IMPL FRAME
[31914:31914:0728/181024:1404710805602:ERROR:layer_tree_host_unittest_scroll.cc(1536)] UpdateLayerTreeHost 2
[31914:31915:0728/181024:1404710806066:ERROR:layer_tree_host_unittest_scroll.cc(1560)] ReadyToCommitOnThread 2
[31914:31915:0728/181024:1404710806257:ERROR:scheduler_state_machine.cc(589)] WillCommit became 0 idle is 0
[31914:31915:0728/181024:1404710806571:ERROR:scheduler_state_machine.cc(856)] DEADLNE
[31914:31915:0728/181024:1404710806816:ERROR:layer_tree_host_unittest_scroll.cc(1577)] DrawLayersOnThread 1
[31914:31915:0728/181024:1404710806944:ERROR:scheduler_state_machine.cc(992)] DidSwapBuffers
[31914:31915:0728/181024:1404710807158:ERROR:scheduler_state_machine.cc(870)] IDLE
[31914:31915:0728/181024:1404710807234:ERROR:scheduler_state_machine.cc(1005)] DidSwapBuffersComplete
[31914:31915:0728/181024:1404710810177:ERROR:scheduler.cc(457)] can_activate_before_deadline 0
[31914:31915:0728/181024:1404710810242:ERROR:scheduler_state_machine.cc(837)] INSIDE IMPL FRAME
[31914:31915:0728/181024:1404710810324:ERROR:scheduler_state_machine.cc(856)] DEADLNE
[31914:31915:0728/181024:1404710810592:ERROR:layer_tree_host_unittest_scroll.cc(1577)] DrawLayersOnThread 2
[31914:31915:0728/181024:1404710810708:ERROR:scheduler_state_machine.cc(992)] DidSwapBuffers
[31914:31915:0728/181024:1404710810864:ERROR:scheduler_state_machine.cc(870)] IDLE
[31914:31915:0728/181024:1404710810940:ERROR:scheduler_state_machine.cc(1005)] DidSwapBuffersComplete
[       OK ] LayerTreeHostScrollTestScrollMFBA.RunMultiThread_DelegatingRenderer (24 ms)

Comment 2 by danakj@chromium.org, Jul 29 2016

This is what a failure looks with a TestDelegatingOutputSurface:

[ RUN      ] LayerTreeHostScrollTestScrollMFBA.RunMultiThread_DelegatingRenderer
[32464:32465:0728/181156:1404802712298:ERROR:scheduler.cc(457)] can_activate_before_deadline 1
[32464:32465:0728/181156:1404802712544:ERROR:scheduler_state_machine.cc(837)] INSIDE IMPL FRAME
[32464:32464:0728/181156:1404802712942:ERROR:layer_tree_host_unittest_scroll.cc(1536)] UpdateLayerTreeHost 0
[32464:32465:0728/181156:1404802713665:ERROR:layer_tree_host_unittest_scroll.cc(1560)] ReadyToCommitOnThread 0
[32464:32465:0728/181156:1404802713850:ERROR:scheduler_state_machine.cc(589)] WillCommit became 0 idle is 0
[32464:32465:0728/181156:1404802718061:ERROR:scheduler_state_machine.cc(856)] DEADLNE
[32464:32465:0728/181156:1404802718783:ERROR:layer_tree_host_unittest_scroll.cc(1577)] DrawLayersOnThread 0
[32464:32465:0728/181156:1404802719287:ERROR:scheduler_state_machine.cc(992)] DidSwapBuffers
[32464:32465:0728/181156:1404802719748:ERROR:scheduler_state_machine.cc(870)] IDLE
[32464:32465:0728/181156:1404802720522:ERROR:scheduler_state_machine.cc(1005)] DidSwapBuffersComplete
[32464:32465:0728/181156:1404802722507:ERROR:scheduler.cc(457)] can_activate_before_deadline 1
[32464:32465:0728/181156:1404802722588:ERROR:scheduler_state_machine.cc(837)] INSIDE IMPL FRAME
[32464:32464:0728/181156:1404802722831:ERROR:layer_tree_host_unittest_scroll.cc(1536)] UpdateLayerTreeHost 1
[32464:32465:0728/181156:1404802723145:ERROR:layer_tree_host_unittest_scroll.cc(1560)] ReadyToCommitOnThread 1
[32464:32465:0728/181156:1404802723235:ERROR:scheduler_state_machine.cc(589)] WillCommit became 0 idle is 0
[32464:32465:0728/181156:1404802739153:ERROR:scheduler_state_machine.cc(856)] DEADLNE
[32464:32465:0728/181156:1404802739238:ERROR:scheduler_state_machine.cc(870)] IDLE
[32464:32465:0728/181156:1404802739380:ERROR:scheduler.cc(457)] can_activate_before_deadline 1
[32464:32465:0728/181156:1404802739451:ERROR:scheduler_state_machine.cc(837)] INSIDE IMPL FRAME
[32464:32465:0728/181156:1404802739525:ERROR:scheduler_state_machine.cc(484)] reduce latency
[32464:32465:0728/181156:1404802755826:ERROR:scheduler_state_machine.cc(856)] DEADLNE
[32464:32465:0728/181156:1404802755913:ERROR:scheduler_state_machine.cc(484)] reduce latency
[32464:32465:0728/181156:1404802755971:ERROR:scheduler_state_machine.cc(870)] IDLE


This last bit then repeats until timeout.

Comment 3 by danakj@chromium.org, Jul 29 2016

So.. what is my question: Is this a bug in the scheduler? Do I want to work around it in these tests by somehow getting BeginFrameArgs such that can_activate_before_deadline is false?

I'll keep looking for what exactly is different tho.

Comment 4 by danakj@chromium.org, Jul 29 2016

Blocking: 606056

Comment 5 by danakj@chromium.org, Jul 29 2016

I think Sunny and I tracked down the difference. The BFS we have in LayerTreeTests before had a default refresh rate of 200frame/s (aka 5ms/frame), but the new one was running at 60frame/s (aka 16.67 ms/frame). When I run it at 200, the tests pass.

For reference the "bmf to activate" estimates are somewhere in the "3" to "6" ballpark. (Not sure of units.)

Comment 6 by danakj@chromium.org, Jul 29 2016

Owner: briander...@chromium.org
Status: Assigned (was: Untriaged)
If you add this to the LayerTreeHostScrollTestScrollMFBA::InitializeSettings(), then it will time out:

    settings->renderer_settings.refresh_rate = 60.f;


Comment 7 by enne@chromium.org, Sep 17 2016

Labels: -Pri-3 Pri-2
I am running into this where if I set the estimated parent draw time to be base::Delta(), then several MFBA tests fail.  https://cs.chromium.org/chromium/src/cc/trees/layer_tree_host_impl.cc?rcl=0&l=2357.

LayerTreeHostProxyTestCommitWaitsForActivationMFBA.RunMultiThread_DelegatingRenderer (../../cc/trees/layer_tree_host_unittest_proxy.cc:421)
LayerTreeHostTestKeepSwapPromiseMFBA.RunMultiThread_DelegatingRenderer (../../cc/trees/layer_tree_host_unittest.cc:4800)

I investigated the first test.  It appears that the scheduler thinks it should ShouldRecoverMainLatency and also that it can activate before the deadline, but the test is waiting for another begin frame before it allows activation to happen so activation never happens.  But the scheduler is in a state that it thinks it shouldn't send a begin frame in order to recover latency.  Therefore it just times out.

Comment 8 by enne@chromium.org, Sep 17 2016

Hilariously, if I change the refresh rate to be 500hz then this passes.  I think it's because the deadline has to faster than the historical activation rate in the test.  So, if the test is fast, the refresh rate has to be faster.  It's a race.

If the first activation is faster than the refresh rate, then every frame falls into the problem above.
Project Member

Comment 9 by bugdroid1@chromium.org, Sep 19 2016

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

commit eb16f56d14abc73321c5128b0374f94c747aa9db
Author: enne <enne@chromium.org>
Date: Mon Sep 19 21:46:51 2016

Add setting to disable latency recovery for tests

The scheduler uses timing history (and other inputs) to decide if it
should try to recover latency.  This makes some tests dependent
on timing in terms of whether the scheduler will ever send a begin
frame (or not, if it's trying to recover main thread latency).  In
some cases, this also can cause a live lock in tests where the
scheduler is waiting for activation to send a begin frame and the
activation is waiting for a begin frame before it lets itself finish.
This has been fixed in the past by just making the tests tick quicker,
but that's not very future proof.

So, in order to make cc tests more robust, add a setting that disables
all latency recover in the scheduler.

R=brianderson@chromium.org
BUG= 632544 

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

[modify] https://crrev.com/eb16f56d14abc73321c5128b0374f94c747aa9db/cc/scheduler/scheduler.cc
[modify] https://crrev.com/eb16f56d14abc73321c5128b0374f94c747aa9db/cc/scheduler/scheduler_settings.cc
[modify] https://crrev.com/eb16f56d14abc73321c5128b0374f94c747aa9db/cc/scheduler/scheduler_settings.h
[modify] https://crrev.com/eb16f56d14abc73321c5128b0374f94c747aa9db/cc/test/layer_tree_test.cc
[modify] https://crrev.com/eb16f56d14abc73321c5128b0374f94c747aa9db/cc/trees/layer_tree_settings.cc
[modify] https://crrev.com/eb16f56d14abc73321c5128b0374f94c747aa9db/cc/trees/layer_tree_settings.h

Comment 10 by enne@chromium.org, Sep 19 2016

Status: Fixed (was: Assigned)

Sign in to add a comment