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

Issue 627080 link

Starred by 2 users

Issue metadata

Status: Fixed
Owner:
Closed: Aug 2016
Cc:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 2
Type: Bug-Regression



Sign in to add a comment

2.7%-44.7% regression in thread_times.key_silk_cases at 404343:404398

Project Member Reported by tdres...@chromium.org, Jul 11 2016

Issue description

See the link to graphs below.
 
Project Member

Comment 2 by 42576172...@developer.gserviceaccount.com, Jul 11 2016

Cc: dtapu...@chromium.org
Owner: dtapu...@chromium.org

=== Auto-CCing suspected CL author dtapuska@chromium.org ===

Hi dtapuska@chromium.org, the bisect results pointed to your CL below as possibly
causing a regression. Please have a look at this info and see whether
your CL be related.


===== BISECT JOB RESULTS =====
Status: completed


===== SUSPECTED CL(s) =====
Subject : Enable PassiveDocumentEventListeners on waterfall.
Author  : dtapuska
Commit description:
  
Enable passive document event listeners finch experimentl on waterfall.

BUG= 625675 
R=rkaplow@chromium.org

Review-Url: https://codereview.chromium.org/2119403002
Cr-Commit-Position: refs/heads/master@{#404351}
Commit  : 19233086ad7e2363e7e1d14582dc6a5428816169
Date    : Fri Jul 08 14:08:27 2016


===== TESTED REVISIONS =====
Revision         Mean     Std Dev    N  Good?
chromium@404344  2.92889  0.0284909  5  good
chromium@404348  2.94432  0.0293655  5  good
chromium@404350  2.91791  0.0322114  5  good
chromium@404351  3.9987   0.461728   5  bad    <--
chromium@404357  4.06522  0.378625   5  bad
chromium@404370  3.96122  0.301571   5  bad
chromium@404396  4.08645  0.401925   5  bad

Bisect job ran on: android_nexus5_perf_bisect
Bug ID: 627080

Test Command: src/tools/perf/run_benchmark -v --browser=android-chromium --output-format=chartjson --upload-results --also-run-disabled-tests thread_times.key_silk_cases
Test Metric: thread_browser_cpu_time_per_frame/thread_browser_cpu_time_per_frame
Relative Change: 39.52%
Score: 99.0

Buildbot stdio: http://build.chromium.org/p/tryserver.chromium.perf/builders/android_nexus5_perf_bisect/builds/3818
Job details: https://chromeperf.appspot.com/buildbucket_job_status/9007430048686868080


Not what you expected? We'll investigate and get back to you!
  https://chromeperf.appspot.com/bad_bisect?try_job_id=5889435489533952

| O O | Visit http://www.chromium.org/developers/speed-infra/perf-bug-faq
|  X  | for more information addressing perf regression bugs. For feedback,
| / \ | file a bug with component Tests>AutoBisect.  Thank you!
Project Member

Comment 3 by 42576172...@developer.gserviceaccount.com, Jul 11 2016


===== BISECT JOB RESULTS =====
Status: completed


===== SUSPECTED CL(s) =====
Subject : Enable PassiveDocumentEventListeners on waterfall.
Author  : dtapuska
Commit description:
  
Enable passive document event listeners finch experimentl on waterfall.

BUG= 625675 
R=rkaplow@chromium.org

Review-Url: https://codereview.chromium.org/2119403002
Cr-Commit-Position: refs/heads/master@{#404351}
Commit  : 19233086ad7e2363e7e1d14582dc6a5428816169
Date    : Fri Jul 08 14:08:27 2016


===== TESTED REVISIONS =====
Revision         Mean     Std Dev    N  Good?
chromium@404342  2.89136  0.0243311  5  good
chromium@404349  2.92463  0.0199825  5  good
chromium@404350  2.93708  0.0347452  5  good
chromium@404351  3.80149  0.33386    5  bad    <--
chromium@404353  4.07594  0.370823   5  bad
chromium@404356  4.14752  0.258042   5  bad
chromium@404370  4.48347  0.278837   5  bad
chromium@404398  3.99636  0.313412   5  bad

Bisect job ran on: android_nexus5_perf_bisect
Bug ID: 627080

Test Command: src/tools/perf/run_benchmark -v --browser=android-chromium --output-format=chartjson --upload-results --also-run-disabled-tests thread_times.key_silk_cases
Test Metric: thread_browser_cpu_time_per_frame/thread_browser_cpu_time_per_frame
Relative Change: 38.22%
Score: 99.5

Buildbot stdio: http://build.chromium.org/p/tryserver.chromium.perf/builders/android_nexus5_perf_bisect/builds/3819
Job details: https://chromeperf.appspot.com/buildbucket_job_status/9007429990598143824


Not what you expected? We'll investigate and get back to you!
  https://chromeperf.appspot.com/bad_bisect?try_job_id=5898004486160384

| O O | Visit http://www.chromium.org/developers/speed-infra/perf-bug-faq
|  X  | for more information addressing perf regression bugs. For feedback,
| / \ | file a bug with component Tests>AutoBisect.  Thank you!
Cc: sullivan@chromium.org
sullivan@ I'm trying to capture traces on these android bots using the dashboard and on the two jobs that I tried I don't seem to get the traces available on the dashboard.

Here are the jobs:
https://codereview.chromium.org/2141713004/ (Just clicked trace on the one)
https://codereview.chromium.org/2136383003/ (Adjusted the values to limit the range)

Should the trace results not appear on the dashboard?

We suspect this regression is because we are less blocked on main which is causing us to be able to produce more frames; but we'd like to understand how many frames are being generated from the traces.
Cc: robert...@chromium.org dtu@chromium.org
dtapuska: It looks like the perf try jobs are failing. +dtu +robertocn why do they show up green?

Fortunately, the traces for the original runs are available on the perf dashboard, they're just a bit hard to find since they're only linked on the individual pages. You need to go into the report page and add a chart for an individual page like this:

https://chromeperf.appspot.com/report?sid=a282db19f7a83581d9bf6af5f2172cdf3eeb82e351bec82aa2f301137c8f0df9&rev=404398

Then you can click on the tooltip and get the before after links:
before: https://console.developers.google.com/m/cloudstorage/b/chrome-telemetry-output/o/trace-file-id_14-2016-07-07_13-43-42-23275.html
after: https://console.developers.google.com/m/cloudstorage/b/chrome-telemetry-output/o/trace-file-id_14-2016-07-07_15-37-12-35565.html
Cc: briander...@chromium.org alexclarke@chromium.org
briananderson@, alexclarke@: Wondering if you can help me understand the traces produced in #5. This is where we activated an experiment to treat root document event listeners as passive so they don't block scrolling the compositor on main thread. And I wonder if it has caused the compositor scheduler to generate smoother frames and cause the thread times to increase.

Specifically what I see in the traces in are:

Before Trace: 
Each frame the Scheduler::BeginImplFrame never seems to ThreadProxy::ScheduledActionSendBeginMainFrame

After Trace:
Each frame the Scheduler::BeginImpFrame seems to always call 	ThreadProxy::ScheduledActionSendBeginMainFrame.


And these scheduling differences causes the higher CPU utilization.



I've posted a revert of this change for the waterfall. However we need to understand if it has forced the scheduler to be more aggressive. Specifically I'm guessing it always thinks we are scrolling now (cause we likely are)

I tried a try job with smoothness off (but it failed)
https://codereview.chromium.org/2149643002/

Re-running it here:
https://codereview.chromium.org/2150623003/

Sorry for the slow response this slipped through the cracks. Telemetry traces only have a few categories enabled which makes analysis hard. Anyway looking at the main thread and selecting the tasks during the animation, I can see that wall time regressed but cpu time did not.  This suggests the main thread was getting descheduled more.  I note the CPU time for compositor work went up slightly.

Perhaps this is working as intended?
dtapuska, do you still need assistance here?
With the nexus5 bisect bots now working I discovered that one page is the cause of all the trouble. I'm working on turning off the intervention for that page because we believe it is doing scrolling so we end up doing scrolling twice with the change. Job (https://codereview.chromium.org/2178573002/) is giving that a test right now.
Status: Fixed (was: Assigned)
Reverted here: https://codereview.chromium.org/2149673002
Regression fixed via: https://codereview.chromium.org/2181413005
Relanded here: https://codereview.chromium.org/2227823002

bots seem stable with the re-land; closing this issue.


Labels: Hotlist-Input-Dev

Sign in to add a comment