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

Issue 719549 link

Starred by 1 user

Issue metadata

Status: WontFix
Owner:
inactive
Closed: May 2017
Cc:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 2
Type: Bug-Regression



Sign in to add a comment

5.8% regression in thread_times.key_mobile_sites_smooth at 468316:468535

Project Member Reported by kraynov@chromium.org, May 8 2017

Issue description

See the link to graphs below.
 
All graphs for this bug:
  https://chromeperf.appspot.com/group_report?bug_id=719549

Original alerts at time of bug-filing:
  https://chromeperf.appspot.com/group_report?keys=agxzfmNocm9tZXBlcmZyFAsSB0Fub21hbHkYgIDgivnkogsM


Bot(s) for this bug's original alert(s):

android-nexus5
Cc: mfomitchev@chromium.org
Owner: mfomitchev@chromium.org

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

Hi mfomitchev@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 : mfomitchev
  Commit : 859478de176cb190f39398aba66157315e66fd17
  Date   : Mon May 01 18:50:38 2017
  Subject: Adding source_event_type to LatencyInfo mojom

Bisect Details
  Configuration: android_nexus5_perf_bisect
  Benchmark    : thread_times.key_mobile_sites_smooth
  Metric       : thread_browser_cpu_time_per_frame/thread_browser_cpu_time_per_frame
  Change       : 7.75% | 3.30232203904 -> 3.55840941948

Revision             Result                    N
chromium@468315      3.30232 +- 0.0659203      6      good
chromium@468370      3.34853 +- 0.0810636      6      good
chromium@468371      3.32155 +- 0.0522027      6      good
chromium@468372      3.51873 +- 0.0445781      6      bad       <--
chromium@468374      3.50299 +- 0.0562709      6      bad
chromium@468377      3.52271 +- 0.0705466      6      bad
chromium@468384      3.49484 +- 0.0668907      6      bad
chromium@468398      3.51248 +- 0.114813       6      bad
chromium@468425      3.51971 +- 0.173851       6      bad
chromium@468535      3.55841 +- 0.0824545      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 thread_times.key_mobile_sites_smooth

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

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


| 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!

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

Suspected Commit
  Author : mfomitchev
  Commit : 859478de176cb190f39398aba66157315e66fd17
  Date   : Mon May 01 18:50:38 2017
  Subject: Adding source_event_type to LatencyInfo mojom

Bisect Details
  Configuration: android_nexus5_perf_bisect
  Benchmark    : thread_times.key_mobile_sites_smooth
  Metric       : thread_browser_cpu_time_per_frame/thread_browser_cpu_time_per_frame
  Change       : 5.79% | 3.32012469996 -> 3.51222846213

Revision             Result                    N
chromium@468315      3.32012 +- 0.108893       6      good
chromium@468370      3.33876 +- 0.0494452      6      good
chromium@468371      3.3019 +- 0.0740647       6      good
chromium@468372      3.51663 +- 0.0935055      6      bad       <--
chromium@468374      3.55183 +- 0.129484       6      bad
chromium@468377      3.53297 +- 0.140656       6      bad
chromium@468384      3.5177 +- 0.111474        6      bad
chromium@468398      3.49945 +- 0.107426       6      bad
chromium@468425      3.51879 +- 0.137702       6      bad
chromium@468535      3.51223 +- 0.0838951      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 thread_times.key_mobile_sites_smooth

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

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


| 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!
Cc: tdres...@chromium.org
+tdresser

My CL fixed a regression in latency reporting. The regression was introduced inhttps://codereview.chromium.org/2774373002/. 

I don't know what the details of how is smoothness measured, but there is actually a dip in the graph around the time the breaking CL was submitted. So it would make sense that my fix undid that effect.

I am inclined to close this bug. Let me know if there are any objections.
This is looking at the CPU time per frame in the browser. It's extremely unintuitive to me that this would regress this much from this change.

Any hypothesis? I think you're right that we can WontFix this, but I wouldn't mind understanding what's going on here.

Is this just the cost of reporting UMA metrics?
How does it determine begin/end of the frame? Could it be that it's relying on some data that is logged in LatencyTracker::ComputeTouchAndWheelScrollLatencyHistograms (which doesn't get logged without my fix)?

I'd hope the cost of UMA metrics reporting is not 5% of the CPU time per frame... :/
Nope, we count the number of LayerTreeHostImpl::DrawLayers slices, and assume that's the number of frames.

https://cs.chromium.org/chromium/src/tools/perf/metrics/timeline.py?rcl=714a743dbf866eb7bd2084c58217d36ce6f4881b&l=300
I see. The graph doesn't have a "vertical step" at my change. Rather it's horizontal - is that normal for regressions?
Also, I've looked at CLs around the time mine landed, and I see this, which looks a little suspect: https://codereview.chromium.org/2690183002/. How reliable are these bysects? Does the +/- range that is quoted represent the actual possible deviation from run to run?
I'm not quite sure what you mean by "horizontal".

I've kicked off another bisect. Two of them identified this CL, which is a pretty strong indicator, but let's see if a third is the same.
Sorry, I meant it's sloped, not vertical. Basically the graph looks like 
 /
/
rather than 
  _
_|
Oh, yeah, that's noise.
Just look at cuteoverload.com, for example.
It's much more stable.
Project Member

Comment 15 by 42576172...@developer.gserviceaccount.com, May 10 2017


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

Suspected Commit
  Author : mfomitchev
  Commit : 859478de176cb190f39398aba66157315e66fd17
  Date   : Mon May 01 18:50:38 2017
  Subject: Adding source_event_type to LatencyInfo mojom

Bisect Details
  Configuration: android_nexus5_perf_bisect
  Benchmark    : thread_times.key_mobile_sites_smooth
  Metric       : thread_browser_cpu_time_per_frame/http___cuteoverload.com

Revision             Result                    N
chromium@468315      3.56776 +- 0.083945       6      good
chromium@468370      3.54187 +- 0.0750024      6      good
chromium@468371      3.52919 +- 0.0405093      6      good
chromium@468372      3.75228 +- 0.079671       6      bad       <--
chromium@468374      3.72274 +- 0.0720403      6      bad
chromium@468377      3.76345 +- 0.0328498      6      bad
chromium@468384      3.75799 +- 0.0205145      6      bad
chromium@468398      3.73209 +- 0.049046       6      bad
chromium@468425      3.72266 +- 0.0644751      6      bad
chromium@468535      3.75286 +- 0.0548383      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 thread_times.key_mobile_sites_smooth

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

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


| 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!
Ok, well, it seems like LatencyTracker::ComputeTouchAndWheelScrollLatencyHistograms does take 5% of the CPU time. I can create a new bug to try to optimize this. Does this sound reasonable?
We'd need to measure this first, but perhaps it's the string concatenation...
Either the string concatenation or histogram gunk. I've been meaning to migrate everything over to static histogram pointer groups (https://cs.chromium.org/chromium/src/base/metrics/histogram_macros.h?rcl=6f9445e94f65449f392ea05167979c053b1826cd&l=288), but still haven't gotten around to it.
If you've got bandwidth to dig in here, that would be awesome.
Status: WontFix (was: Untriaged)
Ok, created issue 721930, and closing this one. I will try to look into it, but making no promises, so feel free to grab it/reassign if other people get cycles.

Sign in to add a comment