-
Notifications
You must be signed in to change notification settings - Fork 17.9k
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
cmd/compile: recent allocs regression #16897
Comments
@josharian You're probably right but I suggest not jumping to fixing this right now. The fmt.go cleanup is not finished yet, it's just a start. Let's complete the transition and cleanups and then revisit. |
Sounds good. Just wanted to flag it, since this is a known performance hot spot. |
@josharian How did you obtain the results above? I like to re-measure. |
$ # Make sure you're using the tip compiler for this go get! It memorizes GOROOT.
$ go get -u rsc.io/compilebench
$ git checkout c85b77c
$ ./make.bash
$ compilebench -short -count 30 -alloc | tee before
$ git checkout master
$ ./make.bash
$ compilebench -short -count 30 -alloc | tee after
$ benchstat before after I now get from that (with master at d6098e4):
The alloc numbers are the ones that I think are probably due to the gc/fmt changes. The CPU numbers may be because I'm running a browser, etc., but I hope they're real! :) |
@josharian Thanks. My pending change ( https://go-review.googlesource.com/28072 ) reduces the allocations again somewhat. Following the same script, I now get:
|
Internal objects that satisfy the Printable interface can print directly to a printer w/o going through the conversion to a string first. Made printer.f understand and special-case %v so that Printable objects use the printer directly. This is work in progress and we may end up doing something else eventually (perhaps using fmt.Formatter) - or even undo these changes if this exploration doesn't get us to a significantly better place. Allocations numbers relative to commit c85b77c (still up, but reduced from most recent change): name old time/op new time/op delta Template 307ms ± 4% 315ms ± 4% +2.55% (p=0.000 n=29+29) Unicode 164ms ± 4% 165ms ± 4% ~ (p=0.057 n=30+30) GoTypes 1.01s ± 3% 1.03s ± 3% +1.72% (p=0.000 n=30+30) Compiler 5.49s ± 1% 5.62s ± 2% +2.31% (p=0.000 n=30+28) name old user-ns/op new user-ns/op delta Template 397M ± 3% 406M ± 6% +2.21% (p=0.000 n=28+30) Unicode 225M ± 4% 226M ± 3% ~ (p=0.230 n=29+30) GoTypes 1.31G ± 3% 1.34G ± 5% +2.79% (p=0.000 n=30+30) Compiler 7.39G ± 2% 7.50G ± 2% +1.43% (p=0.000 n=30+29) name old alloc/op new alloc/op delta Template 46.8MB ± 0% 47.5MB ± 0% +1.48% (p=0.000 n=29+28) Unicode 37.8MB ± 0% 38.1MB ± 0% +0.64% (p=0.000 n=30+28) GoTypes 143MB ± 0% 145MB ± 0% +1.72% (p=0.000 n=30+30) Compiler 683MB ± 0% 706MB ± 0% +3.31% (p=0.000 n=30+29) name old allocs/op new allocs/op delta Template 444k ± 0% 481k ± 0% +8.38% (p=0.000 n=30+30) Unicode 369k ± 0% 379k ± 0% +2.74% (p=0.000 n=30+30) GoTypes 1.35M ± 0% 1.50M ± 0% +10.78% (p=0.000 n=30+30) Compiler 5.66M ± 0% 6.25M ± 0% +10.31% (p=0.000 n=29+29) For #16897. Change-Id: I37f95ab60508018ee6d29a98d238482b60e3e4b5 Reviewed-on: https://go-review.googlesource.com/28072 Reviewed-by: Matthew Dempsky <mdempsky@google.com>
Just as a data point. I've been keeping my benchmarks up to date and as of On Wed, 31 Aug 2016, 04:05 Robert Griesemer notifications@github.com
|
@davecheney I wouldn't be surprised if some of it is due to these changes. I'm playing a bit more with it but if I cannot make it net-negative, I'll undo all the fmt changes that didn't explicitly remove code. |
@robert I don't think the formatting changes had any effect for or against, On Wed, Aug 31, 2016 at 9:12 AM, Robert Griesemer notifications@github.com
|
If you give up on it, Robert, please let me know before reverting everything. Dave, if you could identify when the 2% regression started, that'd be useful. But let's leave this bug specifically for the gc/fmt changes. |
I'm going to assume it was when the dev.ssa branch was merged in. To be go version go1.7 linux/amd64 real 1m2.428s go version devel +b2e0e96 Tue Aug 30 23:10:43 2016 +0000 linux/amd64 real 1m4.310s I don't think it's worth alerting the national guard at this early stage of On Wed, Aug 31, 2016 at 9:23 AM, Josh Bleecher Snyder <
|
@josharian I'm trying to use fmt.Formatter instead of the local printer - that would be nicer and more flexible. So far it looks good. |
@josharian I have now implemented fmt.Formatters for all types handled by fmt.go and also converted all source code to use formatted printing. For instance, an Running the above benchmark above against commit c85b77c and current tip (commit cd0ba4c, excl. my new changes) results in:
This is about what we had yesterday. Running the above benchmark above against commit c85b77c and and my local tip (incl. my new changes) results in:
This shows an improvement - albeit not as much as I hoped. But the changes should have removed many function calls to the various Xconv routines all over the place. There should also much fewer strings be allocated and concatenated. For final comparison: Current master tip as above against my local tip:
I'm going to send out a series of CLs (about one dozen in total) with the respective changes. |
CL https://golang.org/cl/29087 mentions this issue. |
For the record: With (pending) https://go-review.googlesource.com/29089, we are now at or below the original levels:
(Most of the benefits came from https://go-review.googlesource.com/29087.) Considering this particular issue fully resolved at this point. |
Thanks, Robert. |
CL https://golang.org/cl/29089 mentions this issue. |
Also: update fmt_test.go. Together with the previous commits, we are now at or below c85b77c levels in terms of allocation for the benchmark described in #16897 (old = c85b77c, new = this commit): name old time/op new time/op delta Template 297ms ± 5% 284ms ± 3% -4.53% (p=0.000 n=27+29) Unicode 159ms ± 5% 151ms ± 5% -4.91% (p=0.000 n=28+30) GoTypes 985ms ± 5% 935ms ± 2% -5.13% (p=0.000 n=28+29) name old alloc/op new alloc/op delta Template 46.8MB ± 0% 45.7MB ± 0% -2.37% (p=0.000 n=30+30) Unicode 37.8MB ± 0% 37.9MB ± 0% +0.29% (p=0.000 n=29+30) GoTypes 143MB ± 0% 138MB ± 0% -3.64% (p=0.000 n=29+30) name old allocs/op new allocs/op delta Template 444k ± 0% 440k ± 0% -0.94% (p=0.000 n=30+30) Unicode 369k ± 0% 369k ± 0% +0.19% (p=0.000 n=29+30) GoTypes 1.35M ± 0% 1.34M ± 0% -1.24% (p=0.000 n=30+30) For #16897. Change-Id: Iedbeb408e2f1e68dd4a3201bf8813c8066ebf7ed Reviewed-on: https://go-review.googlesource.com/29089 Reviewed-by: Matthew Dempsky <mdempsky@google.com>
Going from commit c85b77c (just before the introduction of a printer type to cmd/compile/internal/gc/fmt.go) to 0d23c28 (current tip), I see:
I haven't dug into why, but I suspect that it is because formatting routines that used to simply return a constant string now append that constant string to a byte slice and then convert that byte slice back into a string. If this guess is correct, it could probably be reversed by adding a string field to printer and doing some careful special-casing code in the printer methods.
cc @griesemer @mdempsky
The text was updated successfully, but these errors were encountered: