What would happen if you inserted a dummy function call inside the non-preemptible loop and made an appropriate sacrifice on the altar of the SSA dead-code-eliminator so it doesn't trigger?
On Thu, Feb 23, 2017 at 8:46 PM 'Austin Clements' via golang-nuts < golang-nuts@googlegroups.com> wrote: > AFAIK, the only thing that can cause this in Go 1.8 is a non-preemptible > loop. It's not related to the heap size at all. > > To test this theory, you can set GOEXPERIMENT=preemptibleloops and rebuild > your Go tree (the compiler has to be built with this, so you can't just > turn it on to build your project). I wouldn't recommend running in > production with this, but if it eliminates the long pauses, we'll at least > know that's the culprit. > > Since these are quite long, the other thing you can do is run with the > execution tracer (https://godoc.org/runtime/trace). You'll be able to see > exactly what's happening at the beginning of each GC cycle. If you do have > non-preemptible loops, you should also see goroutines executing for much > longer than 10ms at a time, which is the default preemption bound. > > On Thu, Feb 23, 2017 at 1:46 PM, Oliver Beattie <oli...@obeattie.com> > wrote: > > I am looking for some advice about how I can debug some long GC pauses I > am observing in our production workloads under go 1.8 (the problem is not > specific to 1.8, though). This is a very simple network server – basically > a HTTP ping endpoint – but I regularly see tail request latencies of > >100ms. I have enabled GODEBUG=gctrace=1, and I can see some quite long > STW pauses amid lots of much less worrying pauses: > > gc 54 @348.007s 0%: 0.061+81+0.040 ms clock, 0.12+0.39/81/81+0.081 ms cpu, > 4->4->1 MB, 5 MB goal, 2 P > gc 55 @358.007s 0%: 0.21+83+0.019 ms clock, 0.43+80/2.7/81+0.039 ms cpu, > 4->4->1 MB, 5 MB goal, 2 P > *gc 56 @367.507s 0%: 80+1.3+0.065 ms clock, 161+0.080/1.2/82+0.13 ms cpu, > 4->4->1 MB, 5 MB goal, 2 P* > gc 57 @377.726s 0%: 0.054+63+0.023 ms clock, 0.10+0.68/61/0.44+0.046 ms > cpu, 4->4->1 MB, 5 MB goal, 2 P > gc 58 @388.007s 0%: 0.033+81+0.036 ms clock, 0.067+0.32/80/81+0.072 ms > cpu, 4->4->1 MB, 5 MB goal, 2 P > gc 59 @398.007s 0%: 0.021+82+0.019 ms clock, 0.043+0.17/80/82+0.038 ms > cpu, 4->4->1 MB, 5 MB goal, 2 P > gc 60 @407.630s 0%: 0.012+57+0.031 ms clock, 0.025+0.25/0.64/57+0.063 ms > cpu, 4->4->1 MB, 5 MB goal, 2 P > gc 61 @418.007s 0%: 0.19+1.0+79 ms clock, 0.38+0.28/0.69/0.98+159 ms cpu, > 4->4->1 MB, 5 MB goal, 2 P > gc 62 @427.507s 0%: 0.21+81+0.29 ms clock, 0.42+81/0.96/81+0.58 ms cpu, > 4->4->1 MB, 5 MB goal, 2 P > gc 63 @437.507s 0%: 0.015+81+0.053 ms clock, 0.031+0.29/0.98/80+0.10 ms > cpu, 4->4->1 MB, 5 MB goal, 2 P > *gc 64 @443.507s 0%: 81+1.2+0.032 ms clock, 162+0.040/1.2/0.44+0.065 ms > cpu, 4->4->1 MB, 5 MB goal, 2 P* > scvg2: inuse: 4, idle: 2, sys: 7, released: 0, consumed: 7 (MB) > gc 65 @453.507s 0%: 0.13+81+0.051 ms clock, 0.26+0.20/81/82+0.10 ms cpu, > 4->4->1 MB, 5 MB goal, 2 P > > If I am reading this correctly, some of these STW pauses are 80+ > milliseconds, in order to scan a minuscule heap. I am not experienced with > debugging the GC in Go, so I'd appreciate any pointers as to why this could > happening and what I can do to get to the bottom of the behaviour. Many > thanks :) > > -- > 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. > > > -- > 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. > -- 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.
