runtime: performance degradation with Go 1.5 #12228
Labels
Comments
adg
changed the title
|
I could be wrong but I have a feeling that it has to do something with the new GC. |
|
@tssajo You seem to have some real world code which can be used to help investigate the problem. The fact that it processes data fed as input and exits makes it ideal for debugging this performance issue. Can you also check if using Go 1.4.2 and Go 1.5 with GOMAXPROCS=1 makes any difference, please? |
|
@tssajo the new GC makes a tradeoff. It increases execution throughput and in exchange for reduced GC pause latency. You're seeing the raw end of the deal here. There is much more tuning to be done, however. cc @aclements @RLH |
|
I suspect you are bang on about the new GC trading CPU for less memory. Could you run it with GOGC=400? That should increase the size of the heap back to what it was in 1.4.x. |
|
@unclejack I did those tests you have suggested: Program compiled with Go 1.4.2 and GOMAXPROCS set to 1 completed the same task in 1m20s So there is still a difference, but much less than before when GOMAXPROCS was set to runtime.NumCPU(). |
|
@RLH You were right! GOGC it is! Running the Go 1.5 compiled program with GOGC=400 makes it complete the task in the exact same amount of time as the previous (Go 1.4.2 compiled) version: 32 seconds. Just out of curiosity, I tested the program with GOGC=800 but I didn't gain too much: completion time went down to about 30 seconds. I'm sure total memory usage went a bit up though. So it seems that for my case a value of about 400, maybe 500 is the most optimal, speed-wise. Should we close this issue now? |
|
@aclements We commented about the same time... It was GOGC. Do you still want me to do the GODEBUG runs? It's not a problem for me to do those if you think it is still useful for something. Please let me know. |
|
If you are happy we can close this issue. The runtime team is aware of the On Thu, Aug 20, 2015 at 9:23 AM, Zoltan notifications@github.com wrote:
|
|
Yes, I'm happy with it. Closing. |
Yes, I would like to have a look at the GODEBUG output if you don't mind. It would be better if you didn't have to set GOGC at all and the GODEBUG output should give us a sense of why 1.5 is collecting more aggressively, which may feed in to our plans for improving GC in 1.6. |
|
@aclements Sure, no problem at all. I'm glad if I can help! I send the full outputs: Go 1.4.2 Go 1.5 I hope this helps. |
|
Thanks! Another thing you could try if you care only about throughput is to set GODEBUG=gcstoptheworld=1. It looks like your heap sizes are pretty similar for most of the run, and you have a similar number of GC cycles, so it's not purely that 1.5 is collecting more aggressively. It does look like the 1.5 GC is running flat-out for much of the middle of your run, which means you're paying the various costs of running concurrently with the GC most of the time:
(15s to 20s of your 1.5 gctrace, created with https://github.com/aclements/go-gcstats. The green bar shows the heap size that triggers the GC and the red bar shows the heap size it's aiming to finish at.) There are some strange bits in here too, like when the trigger goes above the goal. I filed #12199 a few days ago to track that problem. |
|
@aclements Thanks for the suggestion of trying When While I'm sure the program uses more memory with the These are pretty consistent times too: I always ran at least 5-6 tests and I always saw pretty much the same execution times (with same environment variables set). |
tssajo
changed the title
|
@aclements I have some additional info for you: |
Sign up for free
to subscribe to this conversation on GitHub.
Already have an account?
Sign in.
Hello,
I wrote a program in Go which is a converter program. It parses quiet large HTML files (approx. 1.5MB each) and finds specific sections with the help of the goquery library. Then it saves the individual sections to separate files. Everything is parallelized as much as possible using several worker pools (go routines).
A lot of going on in the program (e.g. some fuzzy searching with the help of fuzzy) and unfortunately I cannot provide the source code because it is not a public project.
Note: The first line of func main() is:
so the program utilizes all CPU cores even when compiled with Go 1.4.2
When I run the above described program compiled by Go 1.4.2 then it completes a conversion task (converting several large HTML files) in about 32 seconds. Always.
When I run the exact same program absolutely unmodified but compiled with Go 1.5 it completes the exact same conversion task in about 50 seconds. Always.
I would call this a severe performance degradation. I can reproduce this every single time I run the converter program.
Platform: Windows 7 SP1 (x64)
CPU: Intel Core i7 4770k
RAM: 16GB DDR3
While I cannot provide the source code of my program (it is not public), I did some profiling:
Go 1.4.2 CPU profile:
Go 1.5 CPU profile:
Go 1.4.2 memory profile:
Go 1.5 memory profile:
(Sorry for providing only screenshots, but I do not know how to redirect output from
go tool pprofto a file under Windows.)The text was updated successfully, but these errors were encountered: