Issue metadata
Sign in to add a comment
|
10.1% regression in thread_times.simple_mobile_sites at 409971:410003 |
||||||||||||||||||||
Issue descriptionSee the link to graphs below.
,
Aug 8 2016
Started bisect job https://chromeperf.appspot.com/buildbucket_job_status/9004891602170201872
,
Aug 8 2016
Started bisect job https://chromeperf.appspot.com/buildbucket_job_status/9004890872736619968
,
Aug 8 2016
Started bisect job https://chromeperf.appspot.com/buildbucket_job_status/9004885942426404416
,
Aug 8 2016
===== BISECT JOB RESULTS ===== Status: failed ===== TESTED REVISIONS ===== Revision Mean Std Dev N Good? chromium@409970 3.85479 0.0652782 5 good chromium@409987 3.84498 0.0310836 5 good chromium@409995 3.8719 0.0667711 5 good chromium@409999 3.77655 0.0433261 5 good chromium@410001 3.83708 0.064691 5 good chromium@410002 3.85249 0.041024 5 good chromium@410003 4.23639 0.0781021 5 bad Bisect job ran on: android_nexus5_perf_bisect Bug ID: 635515 Test Command: src/tools/perf/run_benchmark -v --browser=android-chromium --output-format=chartjson --upload-results --also-run-disabled-tests thread_times.simple_mobile_sites Test Metric: thread_browser_cpu_time_per_frame/thread_browser_cpu_time_per_frame Relative Change: 9.90% Score: 0 Buildbot stdio: http://build.chromium.org/p/tryserver.chromium.perf/builders/android_nexus5_perf_bisect/builds/3946 Job details: https://chromeperf.appspot.com/buildbucket_job_status/9004891602170201872 Not what you expected? We'll investigate and get back to you! https://chromeperf.appspot.com/bad_bisect?try_job_id=5793015159848960 | 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!
,
Aug 8 2016
===== BISECT JOB RESULTS ===== Status: failed ===== TESTED REVISIONS ===== Revision Mean Std Dev N Good? chromium@409970 3.87662 0.0424778 5 good chromium@409987 3.85454 0.0788216 5 good chromium@409995 3.80286 0.0947083 5 good chromium@409999 3.82189 0.0785811 5 good chromium@410001 3.83526 0.0657453 5 good chromium@410002 3.85046 0.0463827 5 good chromium@410003 4.22453 0.0712541 5 bad Bisect job ran on: android_nexus5_perf_bisect Bug ID: 635515 Test Command: src/tools/perf/run_benchmark -v --browser=android-chromium --output-format=chartjson --upload-results --also-run-disabled-tests thread_times.simple_mobile_sites Test Metric: thread_browser_cpu_time_per_frame/thread_browser_cpu_time_per_frame Relative Change: 8.97% Score: 0 Buildbot stdio: http://build.chromium.org/p/tryserver.chromium.perf/builders/android_nexus5_perf_bisect/builds/3947 Job details: https://chromeperf.appspot.com/buildbucket_job_status/9004890872736619968 Not what you expected? We'll investigate and get back to you! https://chromeperf.appspot.com/bad_bisect?try_job_id=5781626919845888 | 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!
,
Aug 8 2016
jinsukkim: bisect is pointing at https://codereview.chromium.org/2103243002 as causing the regression; can you take a look?
,
Aug 8 2016
Started bisect job https://chromeperf.appspot.com/buildbucket_job_status/9004866074473655328
,
Aug 8 2016
Started bisect job https://chromeperf.appspot.com/buildbucket_job_status/9004866071013673920
,
Aug 8 2016
===== BISECT JOB RESULTS ===== Status: failed ===== TESTED REVISIONS ===== Revision Mean Std Dev N Good? chromium@409970 3.87662 0.0424778 5 good chromium@409987 3.85454 0.0788216 5 good chromium@409995 3.80286 0.0947083 5 good chromium@409999 3.82189 0.0785811 5 good chromium@410001 3.83526 0.0657453 5 good chromium@410002 3.85046 0.0463827 5 good chromium@410003 4.22453 0.0712541 5 bad Bisect job ran on: android_nexus5_perf_bisect Bug ID: 635515 Test Command: src/tools/perf/run_benchmark -v --browser=android-chromium --output-format=chartjson --upload-results --also-run-disabled-tests thread_times.simple_mobile_sites Test Metric: thread_browser_cpu_time_per_frame/thread_browser_cpu_time_per_frame Relative Change: 8.97% Score: 0 Buildbot stdio: http://build.chromium.org/p/tryserver.chromium.perf/builders/android_nexus5_perf_bisect/builds/3947 Job details: https://chromeperf.appspot.com/buildbucket_job_status/9004890872736619968 Not what you expected? We'll investigate and get back to you! https://chromeperf.appspot.com/bad_bisect?try_job_id=5781626919845888 | 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!
,
Aug 8 2016
===== BISECT JOB RESULTS ===== Status: failed ===== TESTED REVISIONS ===== Revision Mean Std Dev N Good? chromium@409970 3.85479 0.0652782 5 good chromium@409987 3.84498 0.0310836 5 good chromium@409995 3.8719 0.0667711 5 good chromium@409999 3.77655 0.0433261 5 good chromium@410001 3.83708 0.064691 5 good chromium@410002 3.85249 0.041024 5 good chromium@410003 4.23639 0.0781021 5 bad Bisect job ran on: android_nexus5_perf_bisect Bug ID: 635515 Test Command: src/tools/perf/run_benchmark -v --browser=android-chromium --output-format=chartjson --upload-results --also-run-disabled-tests thread_times.simple_mobile_sites Test Metric: thread_browser_cpu_time_per_frame/thread_browser_cpu_time_per_frame Relative Change: 9.90% Score: 0 Buildbot stdio: http://build.chromium.org/p/tryserver.chromium.perf/builders/android_nexus5_perf_bisect/builds/3946 Job details: https://chromeperf.appspot.com/buildbucket_job_status/9004891602170201872 Not what you expected? We'll investigate and get back to you! https://chromeperf.appspot.com/bad_bisect?try_job_id=5793015159848960 | 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!
,
Aug 8 2016
===== BISECT JOB RESULTS ===== Status: failed ===== TESTED REVISIONS ===== Revision Mean Std Dev N Good? chromium@409970 3.83958 0.0673873 5 good chromium@409987 3.83757 0.0920416 5 good chromium@409995 3.82641 0.0521297 5 good chromium@409999 3.82844 0.0837517 5 good chromium@410001 3.83989 0.090717 5 good chromium@410002 3.84197 0.0380519 5 good chromium@410003 4.25781 0.115382 5 bad Bisect job ran on: android_nexus5_perf_bisect Bug ID: 635515 Test Command: src/tools/perf/run_benchmark -v --browser=android-chromium --output-format=chartjson --upload-results --also-run-disabled-tests thread_times.simple_mobile_sites Test Metric: thread_browser_cpu_time_per_frame/thread_browser_cpu_time_per_frame Relative Change: 10.89% Score: 0 Buildbot stdio: http://build.chromium.org/p/tryserver.chromium.perf/builders/android_nexus5_perf_bisect/builds/3948 Job details: https://chromeperf.appspot.com/buildbucket_job_status/9004885942426404416 Not what you expected? We'll investigate and get back to you! https://chromeperf.appspot.com/bad_bisect?try_job_id=5773034300899328 | 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!
,
Aug 8 2016
Started bisect job https://chromeperf.appspot.com/buildbucket_job_status/9004862020844669008
,
Aug 8 2016
===== BISECT JOB RESULTS ===== Status: failed ===== TESTED REVISIONS ===== Revision Mean Std Dev N Good? chromium@409970 3.83958 0.0673873 5 good chromium@409987 3.83757 0.0920416 5 good chromium@409995 3.82641 0.0521297 5 good chromium@409999 3.82844 0.0837517 5 good chromium@410001 3.83989 0.090717 5 good chromium@410002 3.84197 0.0380519 5 good chromium@410003 4.25781 0.115382 5 bad Bisect job ran on: android_nexus5_perf_bisect Bug ID: 635515 Test Command: src/tools/perf/run_benchmark -v --browser=android-chromium --output-format=chartjson --upload-results --also-run-disabled-tests thread_times.simple_mobile_sites Test Metric: thread_browser_cpu_time_per_frame/thread_browser_cpu_time_per_frame Relative Change: 10.89% Score: 0 Buildbot stdio: http://build.chromium.org/p/tryserver.chromium.perf/builders/android_nexus5_perf_bisect/builds/3948 Job details: https://chromeperf.appspot.com/buildbucket_job_status/9004885942426404416 Not what you expected? We'll investigate and get back to you! https://chromeperf.appspot.com/bad_bisect?try_job_id=5773034300899328 | 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!
,
Aug 9 2016
Started bisect job https://chromeperf.appspot.com/buildbucket_job_status/9004774030653707232
,
Aug 9 2016
Started bisect job https://chromeperf.appspot.com/buildbucket_job_status/9004774029037136976
,
Aug 9 2016
=== Auto-CCing suspected CL author jinsukkim@chromium.org === Hi jinsukkim@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 : Factor out ContentViewAndroidDelegate Author : jinsukkim Commit description: Took ContentViewAndroidDelegate out of ContentViewCore so that embedders come with their own implementation of ViewAndroidDelegate. This helps content layer not have to know about Android View/WebView-specific details. BUG= 617750 Review-Url: https://codereview.chromium.org/2103243002 Cr-Commit-Position: refs/heads/master@{#410003} Commit : 9ee8865d84c2156728f1b9f78fb8f8b812e4ba19 Date : Fri Aug 05 06:21:37 2016 ===== TESTED REVISIONS ===== Revision Mean Std Dev N Good? chromium@409970 3.8252 0.0699077 5 good chromium@409987 3.86681 0.0723581 5 good chromium@409995 3.83678 0.0688499 5 good chromium@409999 3.8834 0.082162 5 good chromium@410001 3.89228 0.0213914 5 good chromium@410002 3.84511 0.089861 5 good chromium@410003 4.25449 0.0535134 5 bad <-- Bisect job ran on: android_nexus5_perf_bisect Bug ID: 635515 Test Command: src/tools/perf/run_benchmark -v --browser=android-chromium --output-format=chartjson --upload-results --also-run-disabled-tests thread_times.simple_mobile_sites Test Metric: thread_browser_cpu_time_per_frame/thread_browser_cpu_time_per_frame Relative Change: 11.22% Score: 99.9 Buildbot stdio: http://build.chromium.org/p/tryserver.chromium.perf/builders/android_nexus5_perf_bisect/builds/3950 Job details: https://chromeperf.appspot.com/buildbucket_job_status/9004890872736619968 Not what you expected? We'll investigate and get back to you! https://chromeperf.appspot.com/bad_bisect?try_job_id=5781626919845888 | 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!
,
Aug 9 2016
===== BISECT JOB RESULTS ===== Status: completed ===== SUSPECTED CL(s) ===== Subject : Factor out ContentViewAndroidDelegate Author : jinsukkim Commit description: Took ContentViewAndroidDelegate out of ContentViewCore so that embedders come with their own implementation of ViewAndroidDelegate. This helps content layer not have to know about Android View/WebView-specific details. BUG= 617750 Review-Url: https://codereview.chromium.org/2103243002 Cr-Commit-Position: refs/heads/master@{#410003} Commit : 9ee8865d84c2156728f1b9f78fb8f8b812e4ba19 Date : Fri Aug 05 06:21:37 2016 ===== TESTED REVISIONS ===== Revision Mean Std Dev N Good? chromium@409970 3.83506 0.10545 5 good chromium@409987 3.88346 0.0304452 5 good chromium@409995 3.89198 0.0339406 5 good chromium@409999 3.85496 0.0372214 5 good chromium@410001 3.84327 0.1001 5 good chromium@410002 3.81636 0.0443401 5 good chromium@410003 4.2121 0.0695748 5 bad <-- Bisect job ran on: android_nexus5_perf_bisect Bug ID: 635515 Test Command: src/tools/perf/run_benchmark -v --browser=android-chromium --output-format=chartjson --upload-results --also-run-disabled-tests thread_times.simple_mobile_sites Test Metric: thread_browser_cpu_time_per_frame/thread_browser_cpu_time_per_frame Relative Change: 9.83% Score: 99.9 Buildbot stdio: http://build.chromium.org/p/tryserver.chromium.perf/builders/android_nexus5_perf_bisect/builds/3951 Job details: https://chromeperf.appspot.com/buildbucket_job_status/9004891602170201872 Not what you expected? We'll investigate and get back to you! https://chromeperf.appspot.com/bad_bisect?try_job_id=5793015159848960 | 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!
,
Aug 9 2016
Started bisect job https://chromeperf.appspot.com/buildbucket_job_status/9004770043992663024
,
Aug 9 2016
===== BISECT JOB RESULTS ===== Status: completed ===== SUSPECTED CL(s) ===== Subject : Factor out ContentViewAndroidDelegate Author : jinsukkim Commit description: Took ContentViewAndroidDelegate out of ContentViewCore so that embedders come with their own implementation of ViewAndroidDelegate. This helps content layer not have to know about Android View/WebView-specific details. BUG= 617750 Review-Url: https://codereview.chromium.org/2103243002 Cr-Commit-Position: refs/heads/master@{#410003} Commit : 9ee8865d84c2156728f1b9f78fb8f8b812e4ba19 Date : Fri Aug 05 06:21:37 2016 ===== TESTED REVISIONS ===== Revision Mean Std Dev N Good? chromium@409970 3.86336 0.0639579 5 good chromium@409987 3.84344 0.0786299 5 good chromium@409995 3.84121 0.0421395 5 good chromium@409999 3.86433 0.0404614 5 good chromium@410001 3.81758 0.0829782 5 good chromium@410002 3.84121 0.0909428 5 good chromium@410003 4.16836 0.0440763 5 bad <-- Bisect job ran on: android_nexus5_perf_bisect Bug ID: 635515 Test Command: src/tools/perf/run_benchmark -v --browser=android-chromium --output-format=chartjson --upload-results --also-run-disabled-tests thread_times.simple_mobile_sites Test Metric: thread_browser_cpu_time_per_frame/thread_browser_cpu_time_per_frame Relative Change: 7.89% Score: 99.9 Buildbot stdio: http://build.chromium.org/p/tryserver.chromium.perf/builders/android_nexus5_perf_bisect/builds/3952 Job details: https://chromeperf.appspot.com/buildbucket_job_status/9004885942426404416 Not what you expected? We'll investigate and get back to you! https://chromeperf.appspot.com/bad_bisect?try_job_id=5773034300899328 | 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!
,
Aug 9 2016
,
Aug 17 2016
jinsukkim@, does it seem to make sense that that CL could have affected perf test results? Do you think it would be OK to revert that CL?
,
Aug 17 2016
I'd say maybe we can hold off on reverting a bit and understand this better (given that it doesn't affect any user-perceivable metrics but just one currently unowned metric), since it'd cause some churn. We'll keep investigating. Jinsuk has been looking at this, but so far it's a bit surprising since he verified that the codepaths he touched are not executed during the test - except for applying a power save blocker once but I think he ruled that out. It did look in the trace though as if there was indeed some slight increase accountable to incompletely traced tasks (dipatchMessage and RunTask, i.e. Java-only tasks and ones that go into native but don't have trace events in any of the functions that are called). So we should be able to drill down further, but it's a bit cumbersome.
,
Aug 18 2016
This is intriguing. I'm doing incremental revert on the changes in the CL to figure out what slows down.
,
Aug 18 2016
,
Aug 19 2016
Honestly, I'm totally confused now, because I'm not getting consistent results out of experiments I'm doing locally. Most of the changes are not executed at all for this test in question (scrolling down on Nexus5) since: 1) they are used to show dropdown list on web page, which never happens in the course of the test 2) they are for tablet only, not for mobile for which we show Android dialog instead. The only exception is power save blocker but I tested it enough to make sure it's not the culprit. It remains disabled for the rest of the investigation. I verified they don't get called at all by putting abort()/throw RuntimeException in the path so that the test would stop if they get ever executed. https://codereview.chromium.org/2255833004/#ps1 (also tested it with logs) The test completes without a hiccup. But for some reason I cannot fathom, gutting out those changes affects the cpu thread time, reducing it from 10% down to 4~6%. If I gut out further, the regression is mysteriously gone. https://codereview.chromium.org/2255833004/#ps20001 As if to add more confusion, now I start getting nearly identical cpu duration with or without my CL as I repeat the test again. This does not make any sense. I wouldn't say the regression has nothing to do with my CL - I've seen such statements by other people often proven wrong, and the bisect repeatedly points a finger at mine :( It makes me think there's something I'm missing in my local experiments, which can be the reason I'm getting unreliable results. Sorry this is taking much longer than expected. I'll step back and check if there's any external condition that can affect the measurement.
,
Aug 19 2016
https://codereview.chromium.org/2259493005/ I don't think this will resolve the whole regression but it will at least help shave off the time (however small it may be) consumed by power save blocker when creating an anchor view through JNI during the test.
,
Aug 19 2016
Based on rule of thumb of JNI cost (https://docs.google.com/spreadsheets/d/1ulggKOZ7VQ8IytP1hKr-1wvBu70qG2qxKT4vRbHDIGw/edit ), https://codereview.chromium.org/2259493005/ doesn't seem of comparable magnitude. Can you post a more detailed before/after trace on this bug (if you can repro the 10% difference again), with additional categories like browser, UI, CC? I might be able to spot something given more details. > As if to add more confusion, now I start getting nearly identical cpu duration with or without my CL as I repeat the test again. Sometimes, thermal throttling can account for such varying results. You can put the phone on an icepack (seriously) or try to configure it in a less throttled mode.
,
Aug 19 2016
Thanks for offering help Alex. Here are some traces: https://console.developers.google.com/m/cloudstorage/b/chrome-telemetry-output/o/trace-file-id_0-2016-08-18_13-59-55-86178.html (Trace I got after reverting the CL. This is the baseline I used) 1,093.220 ms https://console.developers.google.com/m/cloudstorage/b/chrome-telemetry-output/o/trace-file-id_0-2016-08-18_15-48-00-39436.html (Partial revert https://codereview.chromium.org/2255833004/#ps1) 1,175.489 ms 7.5% https://console.developers.google.com/m/cloudstorage/b/chrome-telemetry-output/o/trace-file-id_0-2016-08-18_16-21-04-38110.html for https://codereview.chromium.org/2255833004/#ps20001 (after gutting out almost everything. Regression disappears) 1,109.851 ms 1.5%
,
Aug 19 2016
Just a guess, but I wonder if extra Java garbage collector work might be the culprit? The GC roots of JNI refs may be putting strange pressures on the ART GC. Those attachments are the same kind of low-detail traces as produced by the perfbot, so we need some special flags to get more details. --profiler=android-systrace should hopefully give some extra GC info, --profiler=trace-all or (if that's too slow) --profiler=trace-detailed would be good for generally looking for other causes.
,
Aug 22 2016
I still cannot reproduce 10% difference, and unfortunately the benchmark crashes when run with --profiler=xxxx. Didn't try hard to debug it:
File "/usr/local/data2/git/clank/src/third_party/catapult/telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py", line 98, in _StartDevToolsTracing
'backend %s.' % (client.remote_port, self._platform_backend))
ChromeTracingStartedError: Tracing is already running on devtools at port localabstract:chrome_devtools_remote on platformbackend <telemetry.internal.platform.android_platform_backend.AndroidPlatformBackend object at 0x7f18a41fbed0>.
Also tried with the device on a small icebox to rule out thermal throttling - it doesn't seem to make a difference.
Does anyone know how the browser_thread_cpu_time_per_frame is obtained out of 5 web sites used in the test? Is it an average? Following is from one of the test results run locally:
"thread_browser_cpu_time_per_frame": {
"http://www.apple.com/mac/": {
"std": 0.0,
"name": "thread_browser_cpu_time_per_frame",
"type": "list_of_scalar_values",
"important": true,
"values": [
10.613819277107778
],
"units": "ms",
"page_id": 2
},
"http://www.nyc.gov": {
"std": 0.0,
"name": "thread_browser_cpu_time_per_frame",
"type": "list_of_scalar_values",
"important": true,
"values": [
5.033451086956377
],
"units": "ms",
"page_id": 3
},
"summary": {
"std": 0.0,
"name": "thread_browser_cpu_time_per_frame",
"important": true,
"values": [
8.988503816793884,
6.480051094890457,
10.613819277107778,
5.033451086956377,
4.59624468085105
],
"units": "ms",
"type": "list_of_scalar_values"
},
"https://www.flickr.com/": {
"std": 0.0,
"name": "thread_browser_cpu_time_per_frame",
"type": "list_of_scalar_values",
"important": true,
"values": [
6.480051094890457
],
"units": "ms",
"page_id": 1
},
"http://www.ebay.co.uk/": {
"std": 0.0,
"name": "thread_browser_cpu_time_per_frame",
"type": "list_of_scalar_values",
"important": true,
"values": [
8.988503816793884
],
"units": "ms",
"page_id": 0
},
"http://m.nytimes.com/": {
"std": 0.0,
"name": "thread_browser_cpu_time_per_frame",
"type": "list_of_scalar_values",
"important": true,
"values": [
4.59624468085105
],
"units": "ms",
"page_id": 4
}
},
I guess the difference (0.4ms) is still there but it's just cpu time per frame somehow got bigger and makes the relative difference look less significant. Following are the averaged values from the results like above (repeated 4 times. unit ms):
before CL: 7.31, 6.86, 6.84, 6.95
after CL: 7.17, 7.20, 7.32, 7.14
Though not as distinct as before, results with CL applied is bigger.
,
Aug 22 2016
+nednguyen@, what's the right incantation to run --profiler=android-systrace/--profiler=trace-all/--profiler=trace-detailed ? Jinsuk reports the tool crashed when he tried it.
,
Aug 22 2016
Yes. Since thread_times benchmark already use traces you cannot enable chrome trace for it in the profiler which will create conflict. The recommend way is to modify the code in https://cs.chromium.org/chromium/src/tools/perf/measurements/timeline_controller.py?rcl=0&l=37 to add more trace categories. To also get systrace, you can do: config.enable_atrace_trace = True config.atrace_config.categories = ['sched'] Then when running the benchmark, add "--output-format=html --output-format=json" which will makes telemetry produce the trace files it used for computing the metrics.
,
Aug 23 2016
Thanks Ned. It did the trick. I'm checking the generated result with systrace but Alex/Daniel could I get some help? I believe your trained eyes will be able to get more out of it than mine. I've been checking ebay.co.uk because it's the site the shows the most distinct sign of regression on the perf bot. https://x20web.corp.google.com/~jinsukkim/23-09-35.before.zip https://x20web.corp.google.com/~jinsukkim/23-09-25.regr.zip
,
Aug 23 2016
Thanks. I don't yet see a culprit from systrace and on second thought, if there were some information only visible on systrace like an idle-time GC, that wouldn't cause the bot to alert. There are a lot of unaccounted for MessageLoop::RunTask's on the browser UI thread still. The next step would be to turn on more trace categories to see some actual function calls. You can first try "browser, UI, CC", and then even try dumping in 100% of the categories if you still don't see anything (even though it will increasingly make the running time slower -- you can prune back down the list once you figure out which other categories are relevant to the browser UI thread). If there's a new function call we *only* see post-regression, that would be an obvious smoking gun. Otherwise my next thing to look for would be to check if one function call seems to run consistently longer than before, and if so try to explain it by adding more sub-trace-events locally.
,
Aug 23 2016
> Thanks. I don't yet see a culprit from systrace and on second thought, if there were some information only visible on systrace like an idle-time GC, that wouldn't cause the bot to alert. I *think* it actually would because we did something to also count all the untraced work, and I think including Java messages dispatched that never enter native (only a top-level dispatchMessage event). I think BasicLooperMonitor in TraceEvent.java does this somehow based on the >, < markers, but I'm not quite sure where from. Also see kLooperDispatchMessage.
,
Aug 23 2016
Ah that's how it does it: ThreadUtils.getUiThreadLooper().setMessageLogging(enabled() ? LooperMonitorHolder.sInstance : null) So IIUC these are all top-level tasks posted to Looper. If you see a trace event without a scoped RunTask() trace underneath it, we never enter native.
,
Aug 23 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/bc403d8872340a62c310c9665e3b3972344c8c5b commit bc403d8872340a62c310c9665e3b3972344c8c5b Author: jinsukkim <jinsukkim@chromium.org> Date: Tue Aug 23 23:45:29 2016 Let PowerSaveBlocker manager anchor view in Java side This reduces the number of native-to-Java calls by one with a view to mitigating the benchmark test regression introduced with https://crrev.com/2103243002. PowerSaveBlocker was the only class that created an anchor view during the test. Though the root cause not being entirely clear yet, having the view created on Java side can possibly help decrease the browser thread cpu consumption. BUG= 635515 TBR=tedchoc@chromium.org Review-Url: https://codereview.chromium.org/2259493005 Cr-Commit-Position: refs/heads/master@{#413900} [modify] https://crrev.com/bc403d8872340a62c310c9665e3b3972344c8c5b/device/power_save_blocker/android/java/src/org/chromium/device/power_save_blocker/PowerSaveBlocker.java [modify] https://crrev.com/bc403d8872340a62c310c9665e3b3972344c8c5b/device/power_save_blocker/power_save_blocker_android.cc [modify] https://crrev.com/bc403d8872340a62c310c9665e3b3972344c8c5b/ui/android/view_android.cc [modify] https://crrev.com/bc403d8872340a62c310c9665e3b3972344c8c5b/ui/android/view_android.h
,
Aug 24 2016
This is a very useful measurement, unfortunately it seems prone to generating alerts that are hard to act upon by virtue of anonymously adding up everything we can measure and then simply calculating at the total and saying 'Nope!'. I'm actually wondering if fixing that once and for all would be more helpful here than doing days of terrible manual drilling into traces (and again the next time). If the script actually grouped the traces to show where the increase occurred, that'd be so much more useful. We'd also need to have - TraceEvent.java name the dispatchMessage trace events according to the |line| string - RunTask() accumulation by task according to the FROM_HERE data which already is in the trace as a |src_fung| arg, and is more useful for the aggregate since not very single function in the code has or will ever have a trace event
,
Aug 24 2016
I think that wouldn't really explain much given how few trace categories are dumped by default. The main visibility problem we're having right now is how stripped the traces are (in order to avoid biasing the results, of course). If we had more, either manual or automated approaches would be more productive. I'd suggest first adding categories using Ned's suggestion in #33.
,
Aug 24 2016
Another set (before/after) with categories {ui,cc,browser} enabled
https://x20web.corp.google.com/~jinsukkim/24-16-34.uiccb.before.zip
https://x20web.corp.google.com/~jinsukkim/24-16-58.uiccb.after.zip
Thanks again for your help.
,
Aug 24 2016
> I think that wouldn't really explain much given how few trace categories are dumped by default. IIUC we do actually trace *all* the work including framework Java workload on the UI thread and it also goes into the measurement, and that was intentional (I remember Eric doing this). It's just that we don't know what a lot of those pure Java tasks are, or the native ones that don't have a trace even in their call stack.
,
Aug 24 2016
Please ignore the output in #41. No categories seemed to be added there due to a mistake. Will upload another set.
,
Aug 24 2016
index f03bee0..8907ba6 100644
--- a/tools/perf/measurements/timeline_controller.py
+++ b/tools/perf/measurements/timeline_controller.py
@@ -17,7 +17,7 @@ class TimelineController(object):
def __init__(self, enable_auto_issuing_record=True):
super(TimelineController, self).__init__()
- self.trace_categories = None
+ self.trace_categories = '*,CC,UI,browser'
self._model = None
self._renderer_process = None
self._smooth_records = []
The change above doesn't seem to work as intended. I tried adding the categories manually in ChromeTraceCategoryFilter._included_categories. Then the set is ['trace_event_overhead', 'CC', 'webkit.console', 'benchmark', 'toplevel', 'UI', 'blink.console', 'browser'] but the trace looks no different to my eye.
Ned, I need more categories. Are the categories in chrome_trace_category_filter.py what we give in TRACE_EVENT*, as in TRACE_EVENT0("ui", "IsWindowVisible")? Is there anything wrong in what I'm doing?
If I take another look at the traces we have, they already show category like "cc,benchmark". I'm not sure but maybe they already include all that are supposed to appear there.
,
Aug 24 2016
That is the wrong place to hack more trace_categories in since it's reset by the call sites in https://cs.chromium.org/chromium/src/tools/perf/measurements/thread_times.py?rcl=0&l=25 To be sure, you would want to add more trace categories around line 37 of file tools/perf/measurements/timeline_controller.py
,
Aug 24 2016
Chatted with Ned - my brute hack worked okay but the category names should have been in lowercase :< https://x20web.corp.google.com/~jinsukkim/25-05-58.uicc.before.zip https://x20web.corp.google.com/~jinsukkim/trace-ebay-co-uk-before.html - ebay trace only https://x20web.corp.google.com/~jinsukkim/25-06-07.uicc.after.zip https://x20web.corp.google.com/~jinsukkim/trace-ebay-co-uk-after.html
,
Aug 24 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/0a717f521200898d1fe45c37b351daad1c4a4a32 commit 0a717f521200898d1fe45c37b351daad1c4a4a32 Author: jinsukkim <jinsukkim@chromium.org> Date: Wed Aug 24 21:42:05 2016 Remove anchor view from container when reset Makes sure ScopedAnchorView::Reset() removes the anchor view from its container view through JNI. This prevents potential leaks when the destructor fails to do the cleaning job. Not apparently related to the bug, but it helps avoid any issues that may happen in the future. Also deleted a method declaration of |SetWindowAndroid| sneaked in by mistake. BUG= 635515 Review-Url: https://codereview.chromium.org/2272673003 Cr-Commit-Position: refs/heads/master@{#414154} [modify] https://crrev.com/0a717f521200898d1fe45c37b351daad1c4a4a32/ui/android/view_android.cc [modify] https://crrev.com/0a717f521200898d1fe45c37b351daad1c4a4a32/ui/android/view_android.h
,
Aug 26 2016
I think this will fix it: https://codereview.chromium.org/2282983004/
,
Aug 26 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/eb47bc397e6d21f88b7017bc8b9276d86cd06bad commit eb47bc397e6d21f88b7017bc8b9276d86cd06bad Author: sievers <sievers@chromium.org> Date: Fri Aug 26 21:41:31 2016 Revert of Let PowerSaveBlocker manager anchor view in Java side (patchset #3 id:40001 of https://codereview.chromium.org/2259493005/ ) Reason for revert: not needed. doesn't fix the regression. Original issue's description: > Let PowerSaveBlocker manager anchor view in Java side > > This reduces the number of native-to-Java calls by one > with a view to mitigating the benchmark test regression > introduced with https://crrev.com/2103243002. > PowerSaveBlocker was the only class that created an anchor > view during the test. Though the root cause not being > entirely clear yet, having the view created on Java side > can possibly help decrease the browser thread cpu consumption. > > BUG= 635515 > TBR=tedchoc@chromium.org > > Committed: https://crrev.com/bc403d8872340a62c310c9665e3b3972344c8c5b > Cr-Commit-Position: refs/heads/master@{#413900} TBR=twellington@chromium.org,boliu@chromium.org,tedchoc@chromium.org,jinsukkim@chromium.org # Not skipping CQ checks because original CL landed more than 1 days ago. BUG= 635515 NOTRY=True Review-Url: https://codereview.chromium.org/2279313005 Cr-Commit-Position: refs/heads/master@{#414818} [modify] https://crrev.com/eb47bc397e6d21f88b7017bc8b9276d86cd06bad/device/power_save_blocker/android/java/src/org/chromium/device/power_save_blocker/PowerSaveBlocker.java [modify] https://crrev.com/eb47bc397e6d21f88b7017bc8b9276d86cd06bad/device/power_save_blocker/power_save_blocker_android.cc [modify] https://crrev.com/eb47bc397e6d21f88b7017bc8b9276d86cd06bad/ui/android/view_android.cc [modify] https://crrev.com/eb47bc397e6d21f88b7017bc8b9276d86cd06bad/ui/android/view_android.h
,
Aug 26 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/2ed2ebe585894c44ab7946fe63aa9676349e4b4f commit 2ed2ebe585894c44ab7946fe63aa9676349e4b4f Author: sievers <sievers@chromium.org> Date: Fri Aug 26 22:41:54 2016 Android: Fix benchmark regression Looks like explicitly not setting the layout to something with has zero bounds for the anchor view for the power save blocker has some effect on the benchmark. BUG= 635515 TBR=jinsukkim@chromium.org Review-Url: https://codereview.chromium.org/2282983004 Cr-Commit-Position: refs/heads/master@{#414840} [modify] https://crrev.com/2ed2ebe585894c44ab7946fe63aa9676349e4b4f/device/power_save_blocker/power_save_blocker_android.cc [modify] https://crrev.com/2ed2ebe585894c44ab7946fe63aa9676349e4b4f/ui/android/view_android.cc
,
Aug 28 2016
,
Aug 28 2016
Your change meets the bar and is auto-approved for M54 (branch: 2840)
,
Aug 28 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/a55a139e311ceff3c5b253a2ab9ad1fb86f6e68f commit a55a139e311ceff3c5b253a2ab9ad1fb86f6e68f Author: Jinsuk Kim <jinsukkim@chromium.org> Date: Sun Aug 28 23:03:23 2016 Revert of Let PowerSaveBlocker manager anchor view in Java side (patchset #3 id:40001 of https://codereview.chromium.org/2259493005/ ) Reason for revert: not needed. doesn't fix the regression. Original issue's description: > Let PowerSaveBlocker manager anchor view in Java side > > This reduces the number of native-to-Java calls by one > with a view to mitigating the benchmark test regression > introduced with https://crrev.com/2103243002. > PowerSaveBlocker was the only class that created an anchor > view during the test. Though the root cause not being > entirely clear yet, having the view created on Java side > can possibly help decrease the browser thread cpu consumption. > > BUG= 635515 > TBR=tedchoc@chromium.org > > Committed: https://crrev.com/bc403d8872340a62c310c9665e3b3972344c8c5b > Cr-Commit-Position: refs/heads/master@{#413900} TBR=twellington@chromium.org,boliu@chromium.org,tedchoc@chromium.org,jinsukkim@chromium.org BUG= 635515 NOTRY=True Review-Url: https://codereview.chromium.org/2279313005 Cr-Commit-Position: refs/heads/master@{#414818} (cherry picked from commit eb47bc397e6d21f88b7017bc8b9276d86cd06bad) Review URL: https://codereview.chromium.org/2285123002 . Cr-Commit-Position: refs/branch-heads/2840@{#10} Cr-Branched-From: 1ae106dbab4bddd85132d5b75c670794311f4c57-refs/heads/master@{#414607} [modify] https://crrev.com/a55a139e311ceff3c5b253a2ab9ad1fb86f6e68f/device/power_save_blocker/android/java/src/org/chromium/device/power_save_blocker/PowerSaveBlocker.java [modify] https://crrev.com/a55a139e311ceff3c5b253a2ab9ad1fb86f6e68f/device/power_save_blocker/power_save_blocker_android.cc [modify] https://crrev.com/a55a139e311ceff3c5b253a2ab9ad1fb86f6e68f/ui/android/view_android.cc [modify] https://crrev.com/a55a139e311ceff3c5b253a2ab9ad1fb86f6e68f/ui/android/view_android.h
,
Aug 28 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/2cf4e3e29b9caf2f734da7ca730c075aea246ea4 commit 2cf4e3e29b9caf2f734da7ca730c075aea246ea4 Author: Jinsuk Kim <jinsukkim@chromium.org> Date: Sun Aug 28 23:11:55 2016 Android: Fix benchmark regression Looks like explicitly not setting the layout to something with has zero bounds for the anchor view for the power save blocker has some effect on the benchmark. BUG= 635515 TBR=jinsukkim@chromium.org Review-Url: https://codereview.chromium.org/2282983004 Cr-Commit-Position: refs/heads/master@{#414840} (cherry picked from commit 2ed2ebe585894c44ab7946fe63aa9676349e4b4f) Review URL: https://codereview.chromium.org/2289543002 . Cr-Commit-Position: refs/branch-heads/2840@{#11} Cr-Branched-From: 1ae106dbab4bddd85132d5b75c670794311f4c57-refs/heads/master@{#414607} [modify] https://crrev.com/2cf4e3e29b9caf2f734da7ca730c075aea246ea4/device/power_save_blocker/power_save_blocker_android.cc [modify] https://crrev.com/2cf4e3e29b9caf2f734da7ca730c075aea246ea4/ui/android/view_android.cc
,
Aug 28 2016
Verified on perf dashboard. Thanks Daniel for the fix!
,
Oct 27 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/a55a139e311ceff3c5b253a2ab9ad1fb86f6e68f commit a55a139e311ceff3c5b253a2ab9ad1fb86f6e68f Author: Jinsuk Kim <jinsukkim@chromium.org> Date: Sun Aug 28 23:03:23 2016 Revert of Let PowerSaveBlocker manager anchor view in Java side (patchset #3 id:40001 of https://codereview.chromium.org/2259493005/ ) Reason for revert: not needed. doesn't fix the regression. Original issue's description: > Let PowerSaveBlocker manager anchor view in Java side > > This reduces the number of native-to-Java calls by one > with a view to mitigating the benchmark test regression > introduced with https://crrev.com/2103243002. > PowerSaveBlocker was the only class that created an anchor > view during the test. Though the root cause not being > entirely clear yet, having the view created on Java side > can possibly help decrease the browser thread cpu consumption. > > BUG= 635515 > TBR=tedchoc@chromium.org > > Committed: https://crrev.com/bc403d8872340a62c310c9665e3b3972344c8c5b > Cr-Commit-Position: refs/heads/master@{#413900} TBR=twellington@chromium.org,boliu@chromium.org,tedchoc@chromium.org,jinsukkim@chromium.org BUG= 635515 NOTRY=True Review-Url: https://codereview.chromium.org/2279313005 Cr-Commit-Position: refs/heads/master@{#414818} (cherry picked from commit eb47bc397e6d21f88b7017bc8b9276d86cd06bad) Review URL: https://codereview.chromium.org/2285123002 . Cr-Commit-Position: refs/branch-heads/2840@{#10} Cr-Branched-From: 1ae106dbab4bddd85132d5b75c670794311f4c57-refs/heads/master@{#414607} [modify] https://crrev.com/a55a139e311ceff3c5b253a2ab9ad1fb86f6e68f/device/power_save_blocker/android/java/src/org/chromium/device/power_save_blocker/PowerSaveBlocker.java [modify] https://crrev.com/a55a139e311ceff3c5b253a2ab9ad1fb86f6e68f/device/power_save_blocker/power_save_blocker_android.cc [modify] https://crrev.com/a55a139e311ceff3c5b253a2ab9ad1fb86f6e68f/ui/android/view_android.cc [modify] https://crrev.com/a55a139e311ceff3c5b253a2ab9ad1fb86f6e68f/ui/android/view_android.h
,
Oct 27 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/2cf4e3e29b9caf2f734da7ca730c075aea246ea4 commit 2cf4e3e29b9caf2f734da7ca730c075aea246ea4 Author: Jinsuk Kim <jinsukkim@chromium.org> Date: Sun Aug 28 23:11:55 2016 Android: Fix benchmark regression Looks like explicitly not setting the layout to something with has zero bounds for the anchor view for the power save blocker has some effect on the benchmark. BUG= 635515 TBR=jinsukkim@chromium.org Review-Url: https://codereview.chromium.org/2282983004 Cr-Commit-Position: refs/heads/master@{#414840} (cherry picked from commit 2ed2ebe585894c44ab7946fe63aa9676349e4b4f) Review URL: https://codereview.chromium.org/2289543002 . Cr-Commit-Position: refs/branch-heads/2840@{#11} Cr-Branched-From: 1ae106dbab4bddd85132d5b75c670794311f4c57-refs/heads/master@{#414607} [modify] https://crrev.com/2cf4e3e29b9caf2f734da7ca730c075aea246ea4/device/power_save_blocker/power_save_blocker_android.cc [modify] https://crrev.com/2cf4e3e29b9caf2f734da7ca730c075aea246ea4/ui/android/view_android.cc |
|||||||||||||||||||||
►
Sign in to add a comment |
|||||||||||||||||||||
Comment 1 by rmcilroy@chromium.org
, Aug 8 2016