runtime: sysmon looping when idle

[james4k]

sysmon does not go to sleep when 1 proc blocks on a syscall and all other Ps remain idle
(GOMAXPROCS>1). In the simple case of a C.sleep(forever), the process wakes up 100
times a second until a GC occurs much later and sysmon gets put back to sleep. At least,
this is what appears to be happening from looking at debug.schedtrace output.

In the case of an app that idles often, this is giving the process a lot of unnecessary
wakeups.

go version devel +2d1e1adf8ece Tue Oct 22 10:37:33 2013 -0400 darwin/amd64

$ cat sleep.go
package main

/*
#include "unistd.h"
*/
import "C"

func main() {
        C.sleep(1000)
}

$ GOMAXPROCS=2 GODEBUG="schedtrace=1,scheddetail=1" go run sleep.go 2>
schedtrace

At the 2 minute mark we can see that the GC happens, and notice idleprocs value before
the GC.

SCHED 119996ms: gomaxprocs=2 idleprocs=1 threads=6 idlethreads=2 runqueue=0 gcwaiting=0
nmidlelocked=1 nmspinning=0 stopwait=0 sysmonwait=0
  P0: status=2 schedtick=2 syscalltick=1 m=-1 runqsize=0/128 gfreecnt=0
  P1: status=0 schedtick=2 syscalltick=1 m=-1 runqsize=0/128 gfreecnt=0
  M5: p=-1 curg=3 mallocing=0 throwing=0 gcing=0 locks=0 dying=0 helpgc=0 spinning=0 lockedg=3
  M4: p=-1 curg=-1 mallocing=0 throwing=0 gcing=0 locks=0 dying=0 helpgc=0 spinning=0 lockedg=-1
  M3: p=-1 curg=-1 mallocing=0 throwing=0 gcing=0 locks=0 dying=0 helpgc=0 spinning=0 lockedg=-1
  M2: p=-1 curg=2 mallocing=0 throwing=0 gcing=0 locks=0 dying=0 helpgc=0 spinning=0 lockedg=-1
  M1: p=-1 curg=-1 mallocing=0 throwing=0 gcing=0 locks=1 dying=0 helpgc=0 spinning=0 lockedg=-1
  M0: p=0 curg=1 mallocing=0 throwing=0 gcing=0 locks=0 dying=0 helpgc=0 spinning=0 lockedg=1
  G1: status=3(stack unsplit) m=0 lockedm=0
  G2: status=3(stack split) m=2 lockedm=-1
  G3: status=3() m=-1 lockedm=5
SCHED 120009ms: gomaxprocs=2 idleprocs=2 threads=6 idlethreads=2 runqueue=0 gcwaiting=0
nmidlelocked=1 nmspinning=0 stopwait=0 sysmonwait=0
  P0: status=0 schedtick=3 syscalltick=1 m=-1 runqsize=0/128 gfreecnt=1
  P1: status=0 schedtick=3 syscalltick=3 m=-1 runqsize=0/128 gfreecnt=0
  M5: p=-1 curg=3 mallocing=0 throwing=0 gcing=0 locks=0 dying=0 helpgc=0 spinning=0 lockedg=3
  M4: p=-1 curg=-1 mallocing=0 throwing=0 gcing=0 locks=0 dying=0 helpgc=0 spinning=0 lockedg=-1
  M3: p=-1 curg=-1 mallocing=0 throwing=0 gcing=0 locks=0 dying=0 helpgc=0 spinning=0 lockedg=-1
  M2: p=-1 curg=2 mallocing=0 throwing=0 gcing=0 locks=0 dying=0 helpgc=0 spinning=0 lockedg=-1
  M1: p=-1 curg=-1 mallocing=0 throwing=0 gcing=0 locks=1 dying=0 helpgc=0 spinning=0 lockedg=-1
  M0: p=0 curg=1 mallocing=0 throwing=0 gcing=0 locks=0 dying=0 helpgc=0 spinning=0 lockedg=1
  G1: status=3(stack unsplit) m=0 lockedm=0
  G2: status=3(stack split) m=2 lockedm=-1
  G3: status=3() m=-1 lockedm=5
  G4: status=6(garbage collection) m=-1 lockedm=-1

[dvyukov]

Comment 1:

Labels changed: added go1.3, removed priority-triage.

Owner changed to @dvyukov.

Status changed to Accepted.

[james4k]

Comment 2:

For what it's worth, this is the solution I am finding useful for now:
https://golang.org/cl/18080043

[rsc]

Comment 3:

Labels changed: added release-go1.3.

[rsc]

Comment 4:

Labels changed: removed go1.3.

[rsc]

Comment 5:

Labels changed: added repo-main.

[dvyukov]

Comment 6:

sysmon is especially not go to sleep when schedtrace is enabled, because it is the
thread that prints schedtrace
if schedtrace is not enabled, then it must sleep

Status changed to WorkingAsIntended.

[james4k]

Comment 7:

The schedtrace is there to demonstrate that the conditions are not met
for sysmon to sleep (until the GC occurs).

[dvyukov]

Comment 8:

OK, sorry, I will take a closer look

Status changed to Accepted.

[dvyukov]

Comment 9:

This issue was closed by revision 179d41f.

Status changed to Fixed.