Understanding go lang scheding behaviour

Getting Help
1

Hi All,
I was hoping we could get some pointers or suggestion to solve a performance problem we have been having.

We have a server which starts a goroutine to handle every request. Within each request handler (go-routine) it issues another request to another ‘upstream’ server on the local host (which is usually very fast), over a udp channel. The read on the udp socket seems to be taking much longer than expected. e.g the upstream server takes 300 microsecs to return a response, but the read on the socket takes as much as 10 milli secs. After looking at pprof output and ruling out several things we are feeling that it could be due to time taken for the goroutine to get scheduled back again after it blocks on the read.

Here is the output from 'GODEBUG=scheddetail=1,schedtrace=1000’
P0: status=1 schedtick=85975 syscalltick=205078 m=15 runqsize=16 gfreecnt=42
P1: status=1 schedtick=88090 syscalltick=195469 m=11 runqsize=0 gfreecnt=55
P2: status=1 schedtick=78348 syscalltick=193827 m=8 runqsize=0 gfreecnt=49
P3: status=2 schedtick=81384 syscalltick=197765 m=-1 runqsize=0 gfreecnt=38
P4: status=2 schedtick=77978 syscalltick=199689 m=-1 runqsize=39 gfreecnt=11
P5: status=1 schedtick=85777 syscalltick=201910 m=4 runqsize=0 gfreecnt=58
P6: status=1 schedtick=100552 syscalltick=201247 m=2 runqsize=1 gfreecnt=56
P7: status=1 schedtick=90465 syscalltick=201659 m=16 runqsize=0 gfreecnt=48

i am curious about the imbalance in the runqsize between differernt processors. Is this something which could be causing this. If yes how can we fix/avoid this situation ?

2

A block profile is the right tool for this job. It will tell you when a goroutine could run, but was not able to because it was blocked waiting on another resource.

1 Like
3

Actually we did that and eliminated all possible places which came up in profiling for calls getting blocked but it hasn’t helped. I guess my point is that if the bottleneck is goroutine getting scheduled in time it probably will not come up in block profiling.

1 Like
4

Thanks for your reply, that would probably show up as a large run queue. You have goroutines ready to run, but there are no p’s (CPUs) available to run them right now, so they sit on a queue, increasing their latency.

That says to me it’s probably not lock contention.

5

Thanks. I think your reply gives us more confidence that we are in the right direction.

But why would there be goroutines lining up only on few processors. If you look at the schedtrace output i posted it seems that more than half the processors are sitting with an empty runqueue. We increased the nice value of the go application and that hasn’t helped so i don’t think that goroutines not getting scheduled on the actual physical cpu should be the problem (but thats just speculation).

Again i think our hunch is that the imbalance in the runqueue (in our schedtrace output) is the problem. But we don’t know where we can go from here.

6

Which version of Go ?

7

go version go1.6.2 linux/amd64

8

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.