Issue metadata
Sign in to add a comment
|
8% regression in tracing_perftests at 483598:483687 |
||||||||||||||||||||||
Issue descriptionseems to be linux-only
,
Jul 17 2017
Started bisect job https://chromeperf.appspot.com/buildbucket_job_status/8973825896232875296
,
Jul 17 2017
Started bisect job https://chromeperf.appspot.com/buildbucket_job_status/8973825649874190048
,
Jul 17 2017
=== BISECT JOB RESULTS === NO Perf regression found, tests failed to produce values Bisect Details Configuration: linux_perf_bisect Benchmark : tracing_perftests Metric : TraceEventPerfTest.Submit_10000_TRACE_EVENT0_in_traceable_tasks/flush To Run This Test src/tools/perf/run_benchmark -v --browser=release --output-format=chartjson --upload-results --pageset-repeat=1 --also-run-disabled-tests --story-filter=flush tracing_perftests More information on addressing performance regressions: http://g.co/ChromePerformanceRegressions Debug information about this bisect: https://chromeperf.appspot.com/buildbucket_job_status/8973825649874190048 For feedback, file a bug with component Speed>Bisection
,
Jul 17 2017
=== BISECT JOB RESULTS === NO Perf regression found, tests failed to produce values Bisect Details Configuration: linux_perf_bisect Benchmark : tracing_perftests Metric : TraceEventPerfTest.Submit_10000_TRACE_EVENT0_in_traceable_tasks/flush To Run This Test src/tools/perf/run_benchmark -v --browser=release --output-format=chartjson --upload-results --pageset-repeat=1 --also-run-disabled-tests --story-filter=flush tracing_perftests More information on addressing performance regressions: http://g.co/ChromePerformanceRegressions Debug information about this bisect: https://chromeperf.appspot.com/buildbucket_job_status/8973825896232875296 For feedback, file a bug with component Speed>Bisection
,
Jul 17 2017
Based on pure speculation while scrolling the commit log, I think this might be due to https://codereview.chromium.org/2963223003 (Reland of Switch Chrome on Linux to libc++) as no other platform was affected. Started a bisect on https://chromeperf.appspot.com/buildbucket_job_status/8973825649874190048 , but I think bisect doesn't non-TBM tracing_perftests. +kraynov can you see if you can reproduce getting the build artifacts from the CL before and the same cl?
,
Jul 17 2017
Nice find, Primiano. I've got consistent numbers on my workstation. @805944 (after CL) TraceEventPerfTest.Submit_10000_TRACE_EVENT0_in_traceable_tasks: flush= 53 ms @7777a1 (right before the CL) TraceEventPerfTest.Submit_10000_TRACE_EVENT0_in_traceable_tasks: flush= 49 ms
,
Jul 17 2017
Thanks, moving this to thomasanderson as the theory is confirmed
,
Jul 18 2017
Thanks to cachegrind, I was able to find the source of the slowdown. Looks like libc++'s std::string::push_back is about 3.4x slower than libstdc++'s. Note that almost all tests seem to be 1-2% faster with libc++; this is just the one case that isn't :) I'll see if there are any optimizations that can be done here.
,
Jul 18 2017
out of curiosity, does that come from TraceEvent::AppendValueAsJSON ? If that's the case I think the most rationale thing to do is rewrite that using a stringbuf and not leverage on string's operator +=. WDYT? If that's the cause and the idea sgtm I can give a stab to that.
,
Jul 18 2017
c#10 Indeed it is! And that sgtm. But it would also be nice to fix the underlying issue
,
Jul 18 2017
If it's easy to write a standalone program using op+= that shows libc++'s version to be almost 3x slower than libstdc++'s, we could report that at bugs.llvm.org and upstream might be able to fix this for us.
,
Jul 18 2017
libc++ bug report: https://bugs.llvm.org/show_bug.cgi?id=33840
,
Jul 19 2017
primiano@ Actually, it is from AppendAsJSON, but indirectly (see the attached call graph). I think base::EscapeJSONStringImpl is the real culprit that needs to change
,
Jul 19 2017
Found a lazy stopgap with just .reserve(). Don't know why I suggested stringbuf yesterday, it was too late and coffeine level dropped down. Adding a capacity() reservation should bring us back to the original value (at least it does on my Z620*). One interesting thing I realized is that this is not about just capacity expansion policies. If I add the reservation, libstdc++ is still faster (see data below). So looks like push_back is really slower, regardless of the capacity expansion. libstdc++ without reserve(): 129ms libcxx without reserve(): 135ms libstdc++ with reserve(): 123ms libcxx with reserve(): 129ms (and when I say libstdc++ / libcxx I actually mean adding use_custom_libcxx=false to GN args.) * Using this trick to stabilize numbers: https://groups.google.com/a/chromium.org/d/msg/memory-dev/uhtD-UIvjLA/RtAd1k6KBQAJ
,
Jul 19 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/f0d3f8eb3974e36ebb8116c15df45fccacb580ff commit f0d3f8eb3974e36ebb8116c15df45fccacb580ff Author: Primiano Tucci <primiano@chromium.org> Date: Wed Jul 19 11:58:49 2017 tracing: string.reserve() before serializing to JSON After the switch to libc++, flush time of tracing regressed. A cachegrind analysis suggests most time is spent in std::string::push_back(). Pre-reserving the string capacity seems to alleviate the regression and bring us back to the old values (although libstdc++ would be still faster after this CL. Running on a Z620 TraceEventPerfTest.Submit_10000_TRACE_EVENT0_in_traceable_tasks libstdc++ before this CL: 129ms libcxx before this CL: 135ms libstdc++ after this CL: 123ms libcxx after this CL: 129ms BUG= 744555 Change-Id: I9ebcbf432a983307e508327da0de8c4b82c41208 Reviewed-on: https://chromium-review.googlesource.com/576176 Reviewed-by: Hector Dearman <hjd@chromium.org> Commit-Queue: Primiano Tucci <primiano@chromium.org> Cr-Commit-Position: refs/heads/master@{#487827} [modify] https://crrev.com/f0d3f8eb3974e36ebb8116c15df45fccacb580ff/base/trace_event/trace_log.cc
,
Jul 19 2017
Marking this as fixed since this specific regression is fixed, and upstream is aware of the issue
,
Oct 11 2017
Maybe EscapeJSONStringImpl itself should do a dest->reserve(str.length())? Because a call from somewhere else ( DevToolsUIBindings::DispatchProtocolMessage -> content::RenderFrameHostImpl::ExecuteJavaScript ) is slowing down android debugging for me (when there are lots of tabs, confirmed by ETW trace) |
|||||||||||||||||||||||
►
Sign in to add a comment |
|||||||||||||||||||||||
Comment 1 by 42576172...@developer.gserviceaccount.com
, Jul 17 2017