Or… Call runtime.Gosched(). I seem to recall benchmarking it a while back and
found that it was very efficient.
John
John Souvestre - New Orleans LA
From: golang-nuts@googlegroups.com [mailto:golang-nuts@googlegroups.com] On
Behalf Of Jesper Louis Andersen
Sent: 2017 February 23, Thu 16:18
To: Austin Clements; Oliver Beattie
Cc: golang-nuts
Subject: Re: [go-nuts] Debugging long GC pauses
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.
--
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.
