Xun Liu, Are you able to post the actual trace here? I appreciate that it contains information about your source code, so I can understand if you don't want to share it. But I would be very interested to look at the full trace.
Thanks Francis On Wednesday, 31 May 2017 21:02:33 UTC+2, Xun Liu wrote: > > > > On Wed, May 31, 2017 at 11:35 AM, Rick Hudson <r...@golang.org > <javascript:>> wrote: > >> gc 347 @6564.164s 0%: 0.89+518+1.0 ms clock, 28+3839/4091/3959+33 ms cpu, >> 23813->23979->12265 MB, 24423 MB goal, 32 P >> >> What I'm seeing here is that you have 32 HW threads and you spend >> .89+518+1 or 520 ms wall clock in the GC. You also spend >> 28+3839+4091+3959+33 >> or 11950 ms CPU time out of total of 520*32 or 16640 available CPU cycles >> while the GC is running. The GC will reserve 25% of the CPU to do its >> work. That's 16640*.25 or 4160 ms. If the GC finds any of the remaining 24 >> threads idle it will aggressively enlist them to do GC work. >> >> The graph only shows the 8 HW threads but not the other 24 so it is hard >> to tell what is going on with them. >> > > Other cpus are doing user level work. I pasted the whole trace pictures at > the end. > > >> >> This may well be related to issue 12812 >> <https://github.com/golang/go/issues/14812> so you might want to read >> that thread for more insight. >> >> > I read the issue before which seems to be related. Something special about > my trace is many goroutines are GCWaiting, what triggers gc waiting? > Also is there an easy way to turn off idle gc or assist gc? Not knowing > too much details about go gc, I wonder if it's worthy to test how much they > play a role in the latency increase -- it feels to me they are too > aggressive, e.g. the gc finishes using ~27% of the time it needs to finish: > 27% > = (23979 - 23813) / (24423 - 23813) > > gc 347 @6564.164s 0%: 0.89+518+1.0 ms clock, 28+3839/4091/3959+33 ms cpu, > 23813->23979->12265 MB, 24423 MB goal, 32 P > > > > > > > > >> On Wed, May 31, 2017 at 10:25 AM, Xun Liu <pas...@gmail.com <javascript:> >> > wrote: >> >>> $ go version >>> >>> go version go1.8 linux/amd64 >>> >>> On Wednesday, May 31, 2017 at 7:13:38 AM UTC-7, Ian Lance Taylor wrote: >>>> >>>> [ +rlh, austin ] >>>> >>>> Which version of Go are you running? >>>> >>>> Ian >>>> >>>> On Tue, May 30, 2017 at 10:01 PM, Xun Liu <pas...@gmail.com> wrote: >>>> >>>>> Hi, we see a clear correlation between GC and latency spike in our Go >>>>> server. The server uses fairly large amount of memory (20G) and does >>>>> mostly >>>>> CPU work. The server runs on a beefy box with 32 cores and the load is >>>>> pretty light (average CPU 20-30%). GC kicks in once every 10-20 seconds >>>>> and whenever it runs we observe pretty big latency spike ranging from 30% >>>>> to 100% across p50-p90 percentiles (e.g. p90 can jump from 100-120ms to >>>>> 160-250ms) >>>>> >>>>> I captured a trace of a gc and noticed the following: >>>>> >>>>> 1. user gorountines seem run longer during gc. This is through ad-hoc >>>>> check. I don't really know how to get stats to confirm this. >>>>> The gc log is as following (tiny pauses but is very aggressive in >>>>> assist and idle time) >>>>> gc 347 @6564.164s 0%: 0.89+518+1.0 ms clock, 28+3839/4091/3959+33 ms >>>>> cpu, 23813->23979->12265 MB, 24423 MB goal, 32 P >>>>> >>>>> 2. during gc, goroutines can queue up. In this particular case there >>>>> is a stretch of time (~20ms) where we see many goroutines are GCWaiting. >>>>> See below -- the second row is goroutines with light grey indicating >>>>> GCWaiting count and light green Runnable. >>>>> >>>>> >>>>> >>>>> <https://lh3.googleusercontent.com/-5NWj8HzrzyI/WS5Hg0c6WiI/AAAAAAAAqL8/_P-S9vXuGU0FVZV1tG_dHX-14tDHhTsnwCLcB/s1600/Screen%2BShot%2B2017-05-30%2Bat%2B9.32.27%2BPM.png> >>>>> >>>>> >>>>> <https://lh3.googleusercontent.com/-EdVRp4FjhPw/WS5MjjiwdrI/AAAAAAAAqMM/vE5Srmu9e9A5MV0d50NpDiqFsFrkn-E-QCLcB/s1600/Screen%2BShot%2B2017-05-30%2Bat%2B9.54.06%2BPM.png> >>>>> >>>>> Any idea what's going on here? What can I do to reduce the spikes? >>>>> >>>>> >>>>> >>>>> -- >>>>> You received this message because you are subscribed to the Google >>>>> Groups "golang-nuts" group. >>>>> To unsubscribe from this group and stop receiving emails from it, send >>>>> an email to golang-nuts...@googlegroups.com. >>>>> For more options, visit https://groups.google.com/d/optout. >>>>> >>>> >>>> >> > -- You received this message because you are subscribed to the Google Groups "golang-nuts" group. To unsubscribe from this group and stop receiving emails from it, send an email to golang-nuts+unsubscr...@googlegroups.com. For more options, visit https://groups.google.com/d/optout.
