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

Issue metadata

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

Blocked on:
issue 713747
issue 731727
issue 757136



Sign in to add a comment
link

Issue 714873: 4.1%-21.5% regression in thread_times.simple_mobile_sites at 465908:466012

Reported by rsch...@chromium.org, Apr 25 2017 Project Member

Issue description

See the link to graphs below.
 

Comment 3 by 42576172...@developer.gserviceaccount.com, Apr 26 2017

Project Member
=== BISECT JOB RESULTS ===
Bisect failed for unknown reasons

Please contact the team (see below) and report the error.


Bisect Details
  Configuration: android_webview_nexus6_aosp_perf_bisect
  Benchmark    : thread_times.key_mobile_sites_smooth
  Metric       : thread_renderer_compositor_cpu_time_per_frame/thread_renderer_compositor_cpu_time_per_frame


To Run This Test
  src/tools/perf/run_benchmark -v --browser=android-webview --output-format=chartjson --upload-results --pageset-repeat=1 --also-run-disabled-tests thread_times.key_mobile_sites_smooth

Debug Info
  https://chromeperf.appspot.com/buildbucket_job_status/8981387490819080320

Is this bisect wrong?
  https://chromeperf.appspot.com/bad_bisect?try_job_id=5862846488903680


| 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 Speed>Bisection.  Thank you!

Comment 5 by 42576172...@developer.gserviceaccount.com, Apr 27 2017

Project Member
=== BISECT JOB RESULTS ===
Bisect failed for unknown reasons

Please contact the team (see below) and report the error.


Bisect Details
  Configuration: android_webview_nexus6_aosp_perf_bisect
  Benchmark    : thread_times.key_mobile_sites_smooth
  Metric       : thread_renderer_compositor_cpu_time_per_frame/thread_renderer_compositor_cpu_time_per_frame


To Run This Test
  src/tools/perf/run_benchmark -v --browser=android-webview --output-format=chartjson --upload-results --pageset-repeat=1 --also-run-disabled-tests thread_times.key_mobile_sites_smooth

Debug Info
  https://chromeperf.appspot.com/buildbucket_job_status/8981285919725039776

Is this bisect wrong?
  https://chromeperf.appspot.com/bad_bisect?try_job_id=5862846488903680


| 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 Speed>Bisection.  Thank you!

Comment 7 by 42576172...@developer.gserviceaccount.com, Apr 29 2017

Project Member
=== BISECT JOB RESULTS ===
Bisect failed for unknown reasons

Please contact the team (see below) and report the error.


Bisect Details
  Configuration: android_webview_arm64_aosp_perf_bisect
  Benchmark    : thread_times.key_mobile_sites_smooth
  Metric       : thread_other_cpu_time_per_frame/thread_other_cpu_time_per_frame


To Run This Test
  src/tools/perf/run_benchmark -v --browser=android-webview --output-format=chartjson --upload-results --pageset-repeat=1 --also-run-disabled-tests thread_times.key_mobile_sites_smooth

Debug Info
  https://chromeperf.appspot.com/buildbucket_job_status/8981112618183500752

Is this bisect wrong?
  https://chromeperf.appspot.com/bad_bisect?try_job_id=5862846488903680


| 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 Speed>Bisection.  Thank you!

Comment 8 by simonhatch@chromium.org, May 3 2017

Blockedon: 713747
Blocking on crbug.com/713747 for busted android_webview_nexus6_aosp_perf_bisect.

Comment 9 by benhenry@chromium.org, Jul 27 2017

Status: WontFix (was: Untriaged)
This alert was found before M-60 branched. Closing as WontFix as this is believed to either be invalid or non-reproducible.

Comment 10 by vmi...@chromium.org, Aug 19 2017

Owner: vmi...@chromium.org
Status: Assigned (was: WontFix)
I'd like to investigate this more, as there seems to be a ~10% regression that we never recovered from.  Bisecting individual pages may help.

Comment 12 by 42576172...@developer.gserviceaccount.com, Aug 19 2017

Project Member
Cc: nhiroki@chromium.org
Owner: nhiroki@chromium.org
=== Auto-CCing suspected CL author nhiroki@chromium.org ===

Hi nhiroki@chromium.org, the bisect results pointed to your CL, please take a look at the
results.


=== BISECT JOB RESULTS ===
Perf regression found with culprit

Suspected Commit
  Author : nhiroki
  Commit : 7800a474d39eacc36c6c247f6a956e15f5d2489a
  Date   : Thu Apr 20 10:06:51 2017
  Subject: Reland of Worker: Introduce per-global-scope task scheduler

Bisect Details
  Configuration: android_nexus5_perf_bisect
  Benchmark    : thread_times.key_mobile_sites_smooth
  Metric       : thread_renderer_compositor_cpu_time_per_frame/http___cuteoverload.com
  Change       : 13.73% | 2.75377829139 -> 3.13193840561

Revision             Result                    N
chromium@465907      2.75378 +- 0.048775       6      good
chromium@465947      2.78989 +- 0.0534469      6      good
chromium@465957      2.79313 +- 0.039395       6      good
chromium@465960      2.84062 +- 0.0672269      6      good
chromium@465961      2.81334 +- 0.125605       6      good
chromium@465962      3.15406 +- 0.0691507      6      bad       <--
chromium@465967      3.11319 +- 0.141406       6      bad
chromium@465986      3.13194 +- 0.138384       6      bad

To Run This Test
  src/tools/perf/run_benchmark -v --browser=android-chromium --output-format=chartjson --upload-results --pageset-repeat=1 --also-run-disabled-tests --story-filter=http...cuteoverload.com thread_times.key_mobile_sites_smooth

More information on addressing performance regressions:
  http://g.co/ChromePerformanceRegressions

Debug information about this bisect:
  https://chromeperf.appspot.com/buildbucket_job_status/8970875476749054912


For feedback, file a bug with component Speed>Bisection

Comment 13 by vmi...@chromium.org, Aug 19 2017

Blockedon: 757136
nhiroki@: That's a surprising result that your change is affecting the compositor thread in some way.  This could be a change of timing on Main Thread having a knock on effect on the Impl thread.   Issue 757136  looks like the same thing.

The regression seems to be there on multiple devices: Nexus 5, 6, and 7v2.

Comment 14 by vmi...@chromium.org, Aug 19 2017

Cc: sunn...@chromium.org skyos...@chromium.org briander...@chromium.org
+ more scheduling folks

Comment 15 by vmi...@chromium.org, Aug 19 2017

Components: Internals>Compositing Blink>Scheduling

Comment 16 by 42576172...@developer.gserviceaccount.com, Aug 19 2017

Project Member
Cc: vmi...@chromium.org
 Issue 757136  has been merged into this issue.

Comment 17 by nhiroki@chromium.org, Aug 21 2017

Cc: flackr@chromium.org majidvp@chromium.org petermayo@chromium.org
Components: Blink>Workers
Do you think this regression is influential? We investigated similar regressions ( issue 714874 ) when the patch is landed and decided to close it as WONTFIX because the diffs looked small.

The patch introduced per-global scope schedulers for workers and worklets. AnimationWorklet runs on the compositor thread, so the change may affect general composition tasks. IIUC, AnimationWorklet will be moved to its own thread ( issue 731727 ), so this issue would be fixed by that (see  https://crbug.com/714874#c5 ) (+flackr@,majidvp@,petermayo@ for AnimationWorklet).

Comment 18 by vmi...@chromium.org, Aug 21 2017

nhiroki@: Yes I think 18% regression in renderer compositor CPU time, 0.3 to 0.6ms per frame depending on the page, is large.  It seems unexpected to me on this type of page.

I would like to see some traces and understanding of why this regressed, and see if it's a potentially low hanging fruit to optimize.

Moving the tasks to another thread would make this thread time go down but other thread times would go up.  From what I can tell this change resulted in an increase in total CPU time rather than moving the time from A to B.

Comment 19 by vmi...@chromium.org, Aug 21 2017

Example graphs.
thread_times.png
237 KB View Download

Comment 20 by vmi...@chromium.org, Aug 21 2017

From the traces it doesn't look like this is related to AnimationWorklet.  It looks like a direct per-task cost of TQM on top of MessageLoop.

[Before]

Name                                        Cpu Duration  Cpu Self Time  Occurrences
MessageLoop::RunTask                        1.643 ms      0.367 ms       11
                        
[After]

Name                                        Cpu Duration  Cpu Self Time  Occurrences
MessageLoop::RunTask                        2.086 ms      0.256 ms       4
TaskQueueManager::ProcessTaskFromWorkQueue  1.830 ms      0.375 ms       11
Totals                                      3.916 ms      0.631 ms       15

~34us per task, adding up to ~0.375ma per frame in this example.

It's possible some of what we're measuring here is Tracing overhead.  If so, removing the "TaskQueueManager::ProcessTaskFromWorkQueue" from the 'toplevel' trace category may shift the thread times back into the black.

Comment 21 by vmi...@chromium.org, Aug 21 2017

before-trace-file-id_0-2017-04-19_21-06-26-45218.html
3.6 MB View Download
after-trace-file-id_0-2017-04-20_10-55-26-96977.html
3.6 MB View Download

Comment 22 by skyos...@chromium.org, Aug 21 2017

Part of this might be tracing overhead, but I expect TaskQueueManager to have some cost too simply because it's operating a set of prioritized queues rather than a simple FIFO.

When we last tried to enable TQM on the compositor thread we spent quite a bit of time optimizing it so I doubt there's any low hanging fruit left. The last bit of speedup came from enabling task cancellation in MessageLoop which is now done, so I think the next step is to take a perf trace from this and see what pops up.

By the way, I recall someone telling me AnimationWorklet was no longer going to run on the compositor thread? Has that changed or was I misinformed?

Comment 23 by nhiroki@chromium.org, Aug 23 2017

vmiura@: Thank you for the investigation.

The patch introduced TQM in the compositor thread because the global scope scheduler depends on it and the scheduler is necessary for running AnimationWorklet. We could remove TQM from the compositor thread once AnimationWorklet is moved to its own thread.

AnimationWorklet is still a behind-the-flag feature, so as a stopgap we could make the compositor thread use TQM only when the flag is enabled. I'll investigate it.

Re: c#22
> By the way, I recall someone telling me AnimationWorklet was no longer going to run on the compositor thread? Has that changed or was I misinformed?

According to  issue 731727 , it hasn't happened yet.

Comment 24 by nhiroki@chromium.org, Sep 8 2017

Blockedon: 731727
REG c#23:

> According to  issue 731727 , it hasn't happened yet.

petermayo@ is now working on this:
https://chromium-review.googlesource.com/c/chromium/src/+/630857

Comment 25 by rsch...@chromium.org, Sep 20 2017

Cc: -rsch...@chromium.org

Comment 26 by sullivan@chromium.org, Jan 5 2018

petermayo: any update here? Looks like the CL in #24 is ready to submit but had a merge conflict?

Comment 27 by petermayo@chromium.org, Jan 5 2018

The referenced CL is working it's way through the process slowed down by the break.  I have a merged version locally.
There are some unexplained test failures as a result (that I'm not able to reproduce yet).
The reviewers are due back next week to suggest the next set of redesigns.

Comment 28 by vmi...@chromium.org, Feb 5 2018

Components: Internals>GPU>Metrics

Comment 29 by altimin@chromium.org, Aug 15

Status: Fixed (was: Assigned)
It seems that it's done now.

Sign in to add a comment