runtime: OS thread appears to be re-used despite never releasing runtime.LockOSThread() #28979
Description
What did you do?
In Go 1.11.2, spawned a goroutine, called runtime.LockOSThread() and entered a new mount namespace via syscall.Unshare. runtime.UnlockOSThread() was never called, which according to the docs should mean that the locked thread is never re-used.
However, it appears that a separate goroutine started at the beginning of the process (which never calls unshare or does anything with mounts) will after some time be executing in a mount namespace that was created by the independent goroutine mentioned above (which is not expected to be leaking OS threads). This seems to indicate that the OS thread is somehow leaking for re-use by other goroutines despite never calling runtime.UnlockOSThread().
This behavior was originally observed in a larger piece of software, but I was able to reproduce it using the code below. The code:
- Creates two files
/tmp/test-go-thread-leak/source, with file contents "source"/tmp/test-go-thread-leak/dest, with file contents "dest"
- From main, starts a goroutine that checks every second that the contents of
/tmp/test-go-thread-leak/desthave not changed. If the contents changed from the expected value "dest" to "source", it panics, crashing the program. - From main, runs in an infinite loop a function that spins off a separate goroutine that:
- Calls
runtime.LockOSThread() - Enters a new mount namespace with Unshare
- Bind mounts
/tmp/test-go-thread-leak/sourceto/tmp/test-go-thread-leak/dest. This means that any threads/processes in the newly created mount namespace will now see the contents of "dest" have changed to be "source".
- Calls
The goroutine that checks the contents of /tmp/test-go-thread-leak/dest should never read the contents as "source" unless it has suddenly begun executing on an OS thread using one of the mount namespaces created by the other goroutine. However, after 1-10s of execution, the program will crash due to the goroutine reading "source" instead of destination, indicating the OS thread leaked.
Code was compiled with just go build main.go and then run with sudo ./main (sudo needed to make the unshare call).
package main
import (
"fmt"
"io/ioutil"
"os"
"path/filepath"
"runtime"
"syscall"
"time"
)
var (
// Files created will be under this tmpRoot.
// Any existing path at tmpRoot will be deleted
// on start.
tmpRoot = "/tmp/test-go-thread-leak"
sourcePath = filepath.Join(tmpRoot, "source")
sourceContents = "source"
destPath = filepath.Join(tmpRoot, "dest")
destContents = "dest"
)
func init() {
// Set up the directories used to test and print some debugging information
if err := os.RemoveAll(tmpRoot); err != nil {
panic(err.Error())
}
if err := os.Mkdir(tmpRoot, 0777); err != nil {
panic(err.Error())
}
if err := ioutil.WriteFile(sourcePath, []byte(sourceContents), 0777); err != nil {
panic(err.Error())
}
if err := ioutil.WriteFile(destPath, []byte(destContents), 0777); err != nil {
panic(err.Error())
}
fmt.Printf("Running on Go version: %s\n", runtime.Version())
fmt.Printf("Initial mount namespace: %s\n\n", currentMountNsName())
}
// Returns the name of the mount namespace used by the thread of the calling go routine
func currentMountNsName() string {
mountNsName, err := os.Readlink("/proc/thread-self/ns/mnt")
if err != nil {
panic(fmt.Sprintf("failed to get mount ns name: %v", err))
}
return mountNsName
}
// The function that appears to cause unexpected leaks of threads.
// It creates a separate go routine, locks to its OS thread, enters
// a new mount namespace and creates a bind mount in that new namespace.
//
// runtime.UnlockOSThread is never called, so it's expected that the OS
// thread on which this go routine executes is never re-used by other
// go-routines. That appears to not be the case though.
func tryLeak() {
done := make(chan interface{})
go func() {
defer close(done)
runtime.LockOSThread()
// create the new namespace after locking to the os thread
err := syscall.Unshare(syscall.CLONE_NEWNS)
if err != nil {
panic(err.Error())
}
// make sure mounts don't propagate to the previous mount namespace
err = syscall.Mount("", "/", "", syscall.MS_REC|syscall.MS_PRIVATE, "")
if err != nil {
panic(err.Error())
}
// Bind mount the source file to the dest file. This means any thread in
// this mount namespace will now see that "destPath" has the same
// contents as "sourcePath"
err = syscall.Mount(sourcePath, destPath, "", syscall.MS_BIND|syscall.MS_PRIVATE, "")
if err != nil {
panic(err.Error())
}
}()
<-done
}
func main() {
// This go routine checks in a loop that the contents of "destPath" have not
// changed to the contents of "sourcePath". If the contents did change, that
// means this go routine is now executing on an OS thread created by the
// tryLeak function above (even though tryLeak never calls UnlockOSThread
// and should thus never leak threads for re-use).
go func() {
ticker := time.Tick(time.Second)
for range ticker {
runtime.LockOSThread()
readDestContents, err := ioutil.ReadFile(destPath)
if err != nil {
panic(err.Error())
}
if string(readDestContents) == sourceContents {
panic(fmt.Sprintf("unexpectedly able to view bind mounted file. current mount namespace: %s", currentMountNsName()))
} else {
fmt.Printf("found file contents: %s\n", readDestContents)
}
runtime.UnlockOSThread()
}
}()
// Try leaking an os thread every 50ms
ticker := time.Tick(50 * time.Millisecond)
for range ticker {
tryLeak()
}
}
What did you expect to see?
That the program executed indefinitely, never crashing due to the a goroutine unexpectedly executing in a mount namespace created by a different goroutine locked to its os thread.
What did you see instead?
A mount namespace leaks to the separate go routine, causing the program to crash. The time it takes for this to occur is variable but between 1 and 10 seconds. One example:
Running on Go version: go1.11.2
Initial mount namespace: mnt:[4026531840]
found file contents: dest
found file contents: dest
found file contents: dest
panic: unexpectedly able to view bind mounted file. current mount namespace: mnt:[4026532292]
goroutine 18 [running, locked to thread]:
main.main.func1()
/home/sipsma/tmp/goleak/main.go:112 +0x31b
created by main.main
/home/sipsma/tmp/goleak/main.go:102 +0x39
System details
go version go1.11.2 linux/amd64
GOARCH="amd64"
GOBIN=""
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH=""
GOPROXY=""
GORACE=""
GOTMPDIR=""
GCCGO="gccgo"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
GOROOT/bin/go version: go version go1.11.2 linux/amd64
GOROOT/bin/go tool compile -V: compile version go1.11.2
uname -sr: Linux 4.9.124-0.1.ac.198.71.329.metal1.x86_64
/lib64/libc.so.6: GNU C Library stable release version 2.12, by Roland McGrath et al.
gdb --version: GNU gdb (GDB) Amazon Linux (7.2-50.11.amzn1)