Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

runtime: read scheduled on a different thread than a locked and associated with network namespace #34607

Open
difrost opened this issue Sep 30, 2019 · 2 comments
Open

runtime: read scheduled on a different thread than a locked and associated with network namespace #34607

difrost opened this issue Sep 30, 2019 · 2 comments
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone
Backlog

Comments

@difrost
Copy link

difrost commented Sep 30, 2019

What version of Go are you using (go version)?

Tested on 3 versions:

$ go version
go version go1.11.13 linux/amd64

$ go version
go version go1.12.9 linux/amd64

$ go version
go version go1.13 linux/amd64

Does this issue reproduce with the latest release?

Not tested with 1.13.1

What operating system and processor architecture are you using (go env)?

go env Output
$ go env
GOARCH="amd64"
GOBIN=""
GOCACHE="/root/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/root/go"
GOPROXY=""
GORACE=""
GOROOT="/root/golang/1.12.9"
GOTMPDIR=""
GOTOOLDIR="/root/golang/1.12.9/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/mnt/git/github/netns-go-proof/go.mod"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build717114236=/tmp/go-build -gno-record-gcc-switches"

What did you do?

While working on a tool that resolves socket IDs of processes running inside Docker container I've found that reading data from procfs when a locked thread is associated with process network namespace is not deterministic. Sometimes it was reading correct data but quite ofter it was reading data from host namespace.

With following code I was able to reproduce this issue on RHEL 7.2 - 7.6: https://github.com/difrost/netns-go-proof

Steps to reproduce using proof code:

  • Find a container with a process that opens a bunch of network connections:
$ docker ps --format "{{.ID}} {{.Ports}} {{.Names}}"
96cc2a87e368 0.0.0.0:1358->1358/tcp cranky_sutherland
b78274b8892f 0.0.0.0:80->80/tcp, 0.0.0.0:443->443/tcp rancher
  • Get the processes running in b78274b8892f:
$ docker top b78274b8892f -o pid,cmd
PID                 CMD
29724               tini -- rancher --http-listen-port=80 --https-listen-port=443 --audit-log-path=/var/log/auditlog/rancher-api-audit.log --audit-level=0 --audit-log-maxage=10 --audit-log-maxbackup=10 --audit-log-maxsize=100
29763               rancher --http-listen-port=80 --https-listen-port=443 --audit-log-path=/var/log/auditlog/rancher-api-audit.log --audit-level=0 --audit-log-maxage=10 --audit-log-maxbackup=10 --audit-log-maxsize=100
  • Use nsenter from util-linux package to count lines in /proc/net/tcp:
$ sudo nsenter -n -t 29763 cat /proc/net/tcp |wc -l
797
  • Run proof code on 29763:
$ sudo ./NetNSBug -pid 29763
INFO[0000] Analysing 29763 in TID: 28877 PID: 28877
INFO[0000] We are in TID: 28877
INFO[0000] Got data for 29763:
INFO[0000] Got 0 lines loaded for UDP6
INFO[0000] Got 796 lines loaded for TCP
INFO[0000] Got 0 lines loaded for UDP
INFO[0000] Got 30 lines loaded for TCP6
INFO[0000] Namespace for 29763: net:[4026532507]
INFO[0000] Namespace for tid 28877: net:[4026532507]
  • For reference host namespace TCP:
$ cat /proc/net/tcp | wc -l
5
  • Run proof code again but this time force execution on a thread other than main one. This is done by calling dummy goroutine and granting it a bit of juice with runtime.Gosched.
$ sudo ./NetNSBug -pid 29763 -f
INFO[0000] Analysing 29763 in TID: 29224 PID: 29224
INFO[0000] Forcing schedule on a proper thread.
INFO[0000] We are in TID: 29226
INFO[0000] Got data for 29763:
INFO[0000] Got 6 lines loaded for UDP6
INFO[0000] Got 4 lines loaded for TCP
INFO[0000] Got 4 lines loaded for UDP
INFO[0000] Got 4 lines loaded for TCP6
INFO[0000] Namespace for 29763: net:[4026532507]
INFO[0000] Namespace for tid 29226: net:[4026532507]

What did you expect to see?

Correct data read from procfs while associated with a network namespace.

What did you see instead?

Data from host namespace.
@difrost
Copy link
Author

difrost commented Sep 30, 2019

Below is the schedtrace both for good and a bad read - I can't find anything that would help to spot the root cause:
Good

SCHED 1ms: gomaxprocs=2 idleprocs=1 threads=6 spinningthreads=0 idlethreads=2 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=2 schedtick=1 syscalltick=18 m=-1 runqsize=0 gfreecnt=0
  P1: status=0 schedtick=2 syscalltick=0 m=-1 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=-1 curg=5 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=5
  G1: status=4(semacquire) m=-1 lockedm=-1
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G4: status=4(finalizer wait) m=-1 lockedm=-1
  G5: status=3() m=0 lockedm=0 // performing syscall, Thread M0 (Processor P0?)
SCHED 2ms: gomaxprocs=2 idleprocs=1 threads=6 spinningthreads=0 idlethreads=2 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=2 schedtick=1 syscalltick=30 m=-1 runqsize=0 gfreecnt=0
  P1: status=0 schedtick=2 syscalltick=0 m=-1 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=-1 curg=5 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=5
  G1: status=4(semacquire) m=-1 lockedm=-1
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G4: status=4(finalizer wait) m=-1 lockedm=-1
  G5: status=3() m=0 lockedm=0 // performing syscall, Thread M0 (Processor P0?)
SCHED 3ms: gomaxprocs=2 idleprocs=1 threads=6 spinningthreads=0 idlethreads=2 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=2 schedtick=1 syscalltick=41 m=-1 runqsize=0 gfreecnt=0
  P1: status=0 schedtick=2 syscalltick=0 m=-1 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=-1 curg=5 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=5
  G1: status=4(semacquire) m=-1 lockedm=-1
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G4: status=4(finalizer wait) m=-1 lockedm=-1
  G5: status=2() m=0 lockedm=0 // running, Thread M0 (Processor P0?)
SCHED 4ms: gomaxprocs=2 idleprocs=1 threads=6 spinningthreads=0 idlethreads=2 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=1 schedtick=1 syscalltick=47 m=0 runqsize=0 gfreecnt=0
  P1: status=0 schedtick=2 syscalltick=0 m=-1 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=0 curg=5 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=5
  G1: status=4(semacquire) m=-1 lockedm=-1 // wg.Wait
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G4: status=4(finalizer wait) m=-1 lockedm=-1
  G5: status=2() m=0 lockedm=0 // running, Thread M0 (Processor P0?)

Bad

SCHED 1ms: gomaxprocs=2 idleprocs=0 threads=6 spinningthreads=0 idlethreads=1 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=2 schedtick=2 syscalltick=1 m=-1 runqsize=0 gfreecnt=0
  P1: status=1 schedtick=3 syscalltick=7 m=0 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=-1 curg=19 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=19
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=1 curg=20 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=-1
  G1: status=4(semacquire) m=-1 lockedm=-1 // wg.Wait
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G18: status=4(finalizer wait) m=-1 lockedm=-1
  G19: status=3() m=4 lockedm=4  // performing syscall, Thread M4 (Processor 0?) - locked to M4
  G20: status=2() m=0 lockedm=-1 // running dummy goroutine, Thread M0 (Processor 1);
SCHED 2ms: gomaxprocs=2 idleprocs=0 threads=6 spinningthreads=0 idlethreads=1 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=2 schedtick=3 syscalltick=15 m=-1 runqsize=0 gfreecnt=0
  P1: status=1 schedtick=3 syscalltick=7 m=0 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=-1 curg=19 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=19
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=1 curg=20 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=-1
  G1: status=4(semacquire) m=-1 lockedm=-1 // wg.Wait
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G18: status=4(finalizer wait) m=-1 lockedm=-1
  G19: status=3() m=4 lockedm=4  // performing syscall, Thread M4 (Processor 0?) - locked to M4
  G20: status=2() m=0 lockedm=-1 // running dummy goroutine, Thread M0 (Processor 1);
SCHED 3ms: gomaxprocs=2 idleprocs=0 threads=6 spinningthreads=0 idlethreads=1 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=2 schedtick=3 syscalltick=16 m=-1 runqsize=0 gfreecnt=0
  P1: status=1 schedtick=3 syscalltick=7 m=0 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=-1 curg=19 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=19
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=1 curg=20 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=-1
  G1: status=4(semacquire) m=-1 lockedm=-1 // wg.Wait
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G18: status=4(finalizer wait) m=-1 lockedm=-1
  G19: status=3() m=4 lockedm=4  // performing syscall, Thread M4 (Processor 0?) - locked to M4
  G20: status=2() m=0 lockedm=-1 // running dummy goroutine, Thread M0 (Processor 1);
SCHED 4ms: gomaxprocs=2 idleprocs=0 threads=6 spinningthreads=0 idlethreads=1 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=2 schedtick=3 syscalltick=17 m=-1 runqsize=0 gfreecnt=0
  P1: status=1 schedtick=3 syscalltick=7 m=0 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=-1 curg=19 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=19
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=1 curg=20 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=-1
  G1: status=4(semacquire) m=-1 lockedm=-1 // wg.Wait
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G18: status=4(finalizer wait) m=-1 lockedm=-1
  G19: status=3() m=4 lockedm=4  // performing syscall, Thread M4 (Processor 0?) - locked to M4
  G20: status=2() m=0 lockedm=-1 // running dummy goroutine, Thread M0 (Processor 1);
SCHED 5ms: gomaxprocs=2 idleprocs=0 threads=6 spinningthreads=0 idlethreads=1 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=2 schedtick=3 syscalltick=18 m=-1 runqsize=0 gfreecnt=0
  P1: status=1 schedtick=3 syscalltick=7 m=0 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=-1 curg=19 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=19
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=1 curg=20 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=-1
  G1: status=4(semacquire) m=-1 lockedm=-1 // wg.Wait
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G18: status=4(finalizer wait) m=-1 lockedm=-1
  G19: status=3() m=4 lockedm=4  // performing syscall, Thread M4 (Processor 0?) - locked to M4
  G20: status=2() m=0 lockedm=-1 // running dummy goroutine, Thread M0 (Processor 1);
SCHED 6ms: gomaxprocs=2 idleprocs=0 threads=6 spinningthreads=0 idlethreads=1 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=2 schedtick=3 syscalltick=19 m=-1 runqsize=0 gfreecnt=0
  P1: status=1 schedtick=3 syscalltick=7 m=0 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=-1 curg=19 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=19
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=1 curg=20 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=-1
  G1: status=4(semacquire) m=-1 lockedm=-1 // wg.Wait
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G18: status=4(finalizer wait) m=-1 lockedm=-1
  G19: status=3() m=4 lockedm=4  // performing syscall, Thread M4 (Processor 0?) - locked to M4
  G20: status=2() m=0 lockedm=-1 // running dummy goroutine, Thread M0 (Processor 1);
SCHED 7ms: gomaxprocs=2 idleprocs=0 threads=6 spinningthreads=0 idlethreads=1 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=2 schedtick=3 syscalltick=20 m=-1 runqsize=0 gfreecnt=0
  P1: status=1 schedtick=3 syscalltick=7 m=0 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=-1 curg=19 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=19
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=1 curg=20 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=-1
  G1: status=4(semacquire) m=-1 lockedm=-1 // wg.Wait
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G18: status=4(finalizer wait) m=-1 lockedm=-1
  G19: status=3() m=4 lockedm=4  // performing syscall, Thread M4 (Processor 0?) - locked to M4
  G20: status=2() m=0 lockedm=-1 // running dummy goroutine, Thread M0 (Processor 1);
SCHED 8ms: gomaxprocs=2 idleprocs=0 threads=6 spinningthreads=0 idlethreads=1 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=2 schedtick=3 syscalltick=26 m=-1 runqsize=0 gfreecnt=0
  P1: status=1 schedtick=3 syscalltick=7 m=0 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=-1 curg=19 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=19
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=1 curg=20 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=-1
  G1: status=4(semacquire) m=-1 lockedm=-1 // wg.Wait
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G18: status=4(finalizer wait) m=-1 lockedm=-1
  G19: status=3() m=4 lockedm=4  // performing syscall, Thread M4 (Processor 0?) - locked to M4
  G20: status=2() m=0 lockedm=-1 // running dummy goroutine, Thread M0 (Processor 1);
SCHED 9ms: gomaxprocs=2 idleprocs=0 threads=6 spinningthreads=0 idlethreads=1 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=2 schedtick=3 syscalltick=37 m=-1 runqsize=0 gfreecnt=0
  P1: status=1 schedtick=3 syscalltick=7 m=0 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=-1 curg=19 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=19
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=1 curg=20 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=-1
  G1: status=4(semacquire) m=-1 lockedm=-1 // wg.Wait
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G18: status=4(finalizer wait) m=-1 lockedm=-1
  G19: status=3() m=4 lockedm=4  // performing syscall, Thread M4 (Processor 0?) - locked to M4
  G20: status=2() m=0 lockedm=-1 // running dummy goroutine, Thread M0 (Processor 1);
SCHED 10ms: gomaxprocs=2 idleprocs=0 threads=6 spinningthreads=0 idlethreads=1 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=2 schedtick=3 syscalltick=46 m=-1 runqsize=0 gfreecnt=0
  P1: status=1 schedtick=3 syscalltick=7 m=0 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=-1 curg=19 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=19
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=1 curg=20 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=-1
  G1: status=4(semacquire) m=-1 lockedm=-1 // wg.Wait
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G18: status=4(finalizer wait) m=-1 lockedm=-1
  G19: status=3() m=4 lockedm=4  // performing syscall, Thread M4 (Processor 0?) - locked to M4
  G20: status=2() m=0 lockedm=-1 // running dummy goroutine, Thread M0 (Processor 1);
SCHED 11ms: gomaxprocs=2 idleprocs=1 threads=6 spinningthreads=0 idlethreads=1 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=0 schedtick=3 syscalltick=49 m=-1 runqsize=0 gfreecnt=0
  P1: status=1 schedtick=3 syscalltick=7 m=0 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=-1 curg=19 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=19
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=1 curg=20 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=-1
  G1: status=4(semacquire) m=-1 lockedm=-1 // wg.Wait
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G18: status=4(finalizer wait) m=-1 lockedm=-1
  G19: status=3() m=4 lockedm=4  // performing syscall, Thread M4 (Processor 0?) - locked to M4
  G20: status=2() m=0 lockedm=-1 // running dummy goroutine, Thread M0 (Processor 1);
SCHED 12ms: gomaxprocs=2 idleprocs=0 threads=6 spinningthreads=0 idlethreads=1 runqueue=0 gcwaiting=0 nmidlelocked=0 stopwait=0 sysmonwait=0
  P0: status=1 schedtick=3 syscalltick=50 m=4 runqsize=0 gfreecnt=0
  P1: status=1 schedtick=3 syscalltick=7 m=0 runqsize=0 gfreecnt=0
  M5: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M4: p=0 curg=19 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=19
  M3: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=true lockedg=-1
  M2: p=-1 curg=-1 mallocing=0 throwing=0 preemptoff= locks=1 dying=0 spinning=false blocked=false lockedg=-1
  M1: p=-1 curg=17 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=17
  M0: p=1 curg=20 mallocing=0 throwing=0 preemptoff= locks=0 dying=0 spinning=false blocked=false lockedg=-1
  G1: status=4(semacquire) m=-1 lockedm=-1 // wg.Wait
  G17: status=6() m=1 lockedm=1
  G2: status=4(force gc (idle)) m=-1 lockedm=-1
  G3: status=4(GC sweep wait) m=-1 lockedm=-1
  G18: status=4(finalizer wait) m=-1 lockedm=-1
  G19: status=2() m=4 lockedm=4  // running, Thread M4 (Processor 0) - locked to M4
  G20: status=2() m=0 lockedm=-1 // running dummy goroutine, Thread M0 (Processor 1);

@bcmills bcmills added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Sep 30, 2019
@bcmills bcmills added this to the Go1.14 milestone Sep 30, 2019
@bcmills
Copy link
Contributor

bcmills commented Sep 30, 2019

CC @aclements

@rsc rsc modified the milestones: Go1.14, Backlog Oct 9, 2019
@gopherbot gopherbot added the compiler/runtime Issues related to the Go compiler and/or runtime. label Jul 7, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
Go Compiler / Runtime
Status: Triage Backlog
Milestone
Backlog
Development

No branches or pull requests
4 participants
@rsc @bcmills @gopherbot @difrost