{"action":"created","issue":{"url":"https://api.github.com/repos/golang/go/issues/28979","repository_url":"https://api.github.com/repos/golang/go","labels_url":"https://api.github.com/repos/golang/go/issues/28979/labels{/name}","comments_url":"https://api.github.com/repos/golang/go/issues/28979/comments","events_url":"https://api.github.com/repos/golang/go/issues/28979/events","html_url":"https://github.com/golang/go/issues/28979","id":385053801,"node_id":"MDU6SXNzdWUzODUwNTM4MDE=","number":28979,"title":"runtime: OS thread appears to be re-used despite never releasing runtime.LockOSThread()","user":{"login":"sipsma","id":30126853,"node_id":"MDQ6VXNlcjMwMTI2ODUz","avatar_url":"https://avatars3.githubusercontent.com/u/30126853?v=4","gravatar_id":"","url":"https://api.github.com/users/sipsma","html_url":"https://github.com/sipsma","followers_url":"https://api.github.com/users/sipsma/followers","following_url":"https://api.github.com/users/sipsma/following{/other_user}","gists_url":"https://api.github.com/users/sipsma/gists{/gist_id}","starred_url":"https://api.github.com/users/sipsma/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/sipsma/subscriptions","organizations_url":"https://api.github.com/users/sipsma/orgs","repos_url":"https://api.github.com/users/sipsma/repos","events_url":"https://api.github.com/users/sipsma/events{/privacy}","received_events_url":"https://api.github.com/users/sipsma/received_events","type":"User","site_admin":false},"labels":[{"id":373399998,"node_id":"MDU6TGFiZWwzNzMzOTk5OTg=","url":"https://api.github.com/repos/golang/go/labels/NeedsFix","name":"NeedsFix","color":"ededed","default":false},{"id":626114820,"node_id":"MDU6TGFiZWw2MjYxMTQ4MjA=","url":"https://api.github.com/repos/golang/go/labels/release-blocker","name":"release-blocker","color":"b60205","default":false}],"state":"open","locked":false,"assignee":{"login":"aclements","id":2688315,"node_id":"MDQ6VXNlcjI2ODgzMTU=","avatar_url":"https://avatars0.githubusercontent.com/u/2688315?v=4","gravatar_id":"","url":"https://api.github.com/users/aclements","html_url":"https://github.com/aclements","followers_url":"https://api.github.com/users/aclements/followers","following_url":"https://api.github.com/users/aclements/following{/other_user}","gists_url":"https://api.github.com/users/aclements/gists{/gist_id}","starred_url":"https://api.github.com/users/aclements/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/aclements/subscriptions","organizations_url":"https://api.github.com/users/aclements/orgs","repos_url":"https://api.github.com/users/aclements/repos","events_url":"https://api.github.com/users/aclements/events{/privacy}","received_events_url":"https://api.github.com/users/aclements/received_events","type":"User","site_admin":false},"assignees":[{"login":"aclements","id":2688315,"node_id":"MDQ6VXNlcjI2ODgzMTU=","avatar_url":"https://avatars0.githubusercontent.com/u/2688315?v=4","gravatar_id":"","url":"https://api.github.com/users/aclements","html_url":"https://github.com/aclements","followers_url":"https://api.github.com/users/aclements/followers","following_url":"https://api.github.com/users/aclements/following{/other_user}","gists_url":"https://api.github.com/users/aclements/gists{/gist_id}","starred_url":"https://api.github.com/users/aclements/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/aclements/subscriptions","organizations_url":"https://api.github.com/users/aclements/orgs","repos_url":"https://api.github.com/users/aclements/repos","events_url":"https://api.github.com/users/aclements/events{/privacy}","received_events_url":"https://api.github.com/users/aclements/received_events","type":"User","site_admin":false}],"milestone":{"url":"https://api.github.com/repos/golang/go/milestones/65","html_url":"https://github.com/golang/go/milestone/65","labels_url":"https://api.github.com/repos/golang/go/milestones/65/labels","id":3072996,"node_id":"MDk6TWlsZXN0b25lMzA3Mjk5Ng==","number":65,"title":"Go1.12","description":"","creator":{"login":"rsc","id":104030,"node_id":"MDQ6VXNlcjEwNDAzMA==","avatar_url":"https://avatars1.githubusercontent.com/u/104030?v=4","gravatar_id":"","url":"https://api.github.com/users/rsc","html_url":"https://github.com/rsc","followers_url":"https://api.github.com/users/rsc/followers","following_url":"https://api.github.com/users/rsc/following{/other_user}","gists_url":"https://api.github.com/users/rsc/gists{/gist_id}","starred_url":"https://api.github.com/users/rsc/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/rsc/subscriptions","organizations_url":"https://api.github.com/users/rsc/orgs","repos_url":"https://api.github.com/users/rsc/repos","events_url":"https://api.github.com/users/rsc/events{/privacy}","received_events_url":"https://api.github.com/users/rsc/received_events","type":"User","site_admin":false},"open_issues":502,"closed_issues":523,"state":"open","created_at":"2018-01-29T21:17:52Z","updated_at":"2018-12-06T22:34:56Z","due_on":"2019-01-31T08:00:00Z","closed_at":null},"comments":6,"created_at":"2018-11-28T00:57:41Z","updated_at":"2018-12-07T00:16:56Z","closed_at":null,"author_association":"NONE","body":"#### What did you do?\r\nIn 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](https://golang.org/pkg/runtime/#LockOSThread).\r\n\r\nHowever, 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()`.\r\n\r\nThis behavior was originally observed in a larger piece of software, but I was able to reproduce it using the code below. The code:\r\n- Creates two files\r\n  - `/tmp/test-go-thread-leak/source`, with file contents \"source\"\r\n  - `/tmp/test-go-thread-leak/dest`, with file contents \"dest\"\r\n- From main, starts a goroutine that checks every second that the contents of `/tmp/test-go-thread-leak/dest` have not changed. If the contents changed from the expected value \"dest\" to \"source\", it panics, crashing the program.\r\n- From main, runs in an infinite loop a function that spins off a separate goroutine that:\r\n  - Calls `runtime.LockOSThread()`\r\n  - Enters a new mount namespace with Unshare\r\n  - Bind mounts `/tmp/test-go-thread-leak/source` to `/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\".\r\n\r\nThe 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.\r\n\r\nCode was compiled with just `go build main.go` and then run with `sudo ./main` (`sudo` needed to make the unshare call).\r\n\r\n```\r\npackage main\r\n\r\nimport (\r\n    \"fmt\"\r\n    \"io/ioutil\"\r\n    \"os\"\r\n    \"path/filepath\"\r\n    \"runtime\"\r\n    \"syscall\"\r\n    \"time\"\r\n)\r\n\r\nvar (\r\n    // Files created will be under this tmpRoot.\r\n    // Any existing path at tmpRoot will be deleted\r\n    // on start.\r\n    tmpRoot = \"/tmp/test-go-thread-leak\"\r\n\r\n    sourcePath = filepath.Join(tmpRoot, \"source\")\r\n    sourceContents = \"source\"\r\n\r\n    destPath = filepath.Join(tmpRoot, \"dest\")\r\n    destContents = \"dest\"\r\n)\r\n\r\nfunc init() {\r\n    // Set up the directories used to test and print some debugging information\r\n    if err := os.RemoveAll(tmpRoot); err != nil {\r\n        panic(err.Error())\r\n    }\r\n\r\n    if err := os.Mkdir(tmpRoot, 0777); err != nil {\r\n        panic(err.Error())\r\n    }\r\n\r\n    if err := ioutil.WriteFile(sourcePath, []byte(sourceContents), 0777); err != nil {\r\n        panic(err.Error())\r\n    }\r\n\r\n    if err := ioutil.WriteFile(destPath, []byte(destContents), 0777); err != nil {\r\n        panic(err.Error())\r\n    }\r\n\r\n    fmt.Printf(\"Running on Go version: %s\\n\", runtime.Version())\r\n    fmt.Printf(\"Initial mount namespace: %s\\n\\n\", currentMountNsName())\r\n}\r\n\r\n// Returns the name of the mount namespace used by the thread of the calling go routine\r\nfunc currentMountNsName() string {\r\n    mountNsName, err := os.Readlink(\"/proc/thread-self/ns/mnt\")\r\n    if err != nil {\r\n        panic(fmt.Sprintf(\"failed to get mount ns name: %v\", err))\r\n    }\r\n\r\n    return mountNsName\r\n}\r\n\r\n// The function that appears to cause unexpected leaks of threads.\r\n// It creates a separate go routine, locks to its OS thread, enters\r\n// a new mount namespace and creates a bind mount in that new namespace.\r\n//\r\n// runtime.UnlockOSThread is never called, so it's expected that the OS\r\n// thread on which this go routine executes is never re-used by other\r\n// go-routines. That appears to not be the case though.\r\nfunc tryLeak() {\r\n    done := make(chan interface{})\r\n    go func() {\r\n        defer close(done)\r\n\r\n        runtime.LockOSThread()\r\n\r\n        // create the new namespace after locking to the os thread\r\n        err := syscall.Unshare(syscall.CLONE_NEWNS)\r\n        if err != nil {\r\n            panic(err.Error())\r\n        }\r\n\r\n        // make sure mounts don't propagate to the previous mount namespace\r\n        err = syscall.Mount(\"\", \"/\", \"\", syscall.MS_REC|syscall.MS_PRIVATE, \"\")\r\n        if err != nil {\r\n            panic(err.Error())\r\n        }\r\n\r\n        // Bind mount the source file to the dest file. This means any thread in\r\n        // this mount namespace will now see that \"destPath\" has the same\r\n        // contents as \"sourcePath\"\r\n        err = syscall.Mount(sourcePath, destPath, \"\", syscall.MS_BIND|syscall.MS_PRIVATE, \"\")\r\n        if err != nil {\r\n            panic(err.Error())\r\n        }\r\n    }()\r\n\r\n    <-done\r\n}\r\n\r\nfunc main() {\r\n    // This go routine checks in a loop that the contents of \"destPath\" have not\r\n    // changed to the contents of \"sourcePath\". If the contents did change, that\r\n    // means this go routine is now executing on an OS thread created by the\r\n    // tryLeak function above (even though tryLeak never calls UnlockOSThread\r\n    // and should thus never leak threads for re-use).\r\n    go func() {\r\n        ticker := time.Tick(time.Second)\r\n        for range ticker {\r\n            runtime.LockOSThread()\r\n            readDestContents, err := ioutil.ReadFile(destPath)\r\n            if err != nil {\r\n                panic(err.Error())\r\n            }\r\n\r\n            if string(readDestContents) == sourceContents {\r\n                panic(fmt.Sprintf(\"unexpectedly able to view bind mounted file. current mount namespace: %s\", currentMountNsName()))\r\n            } else {\r\n                fmt.Printf(\"found file contents: %s\\n\", readDestContents)\r\n            }\r\n            runtime.UnlockOSThread()\r\n        }\r\n    }()\r\n\r\n    // Try leaking an os thread every 50ms\r\n    ticker := time.Tick(50 * time.Millisecond)\r\n    for range ticker {\r\n        tryLeak()\r\n    }\r\n}\r\n```\r\n\r\n#### What did you expect to see?\r\nThat 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.\r\n\r\n#### What did you see instead?\r\nA 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:\r\n```\r\nRunning on Go version: go1.11.2\r\nInitial mount namespace: mnt:[4026531840]\r\n\r\nfound file contents: dest\r\nfound file contents: dest\r\nfound file contents: dest\r\npanic: unexpectedly able to view bind mounted file. current mount namespace: mnt:[4026532292]\r\n\r\ngoroutine 18 [running, locked to thread]:\r\nmain.main.func1()\r\n        /home/sipsma/tmp/goleak/main.go:112 +0x31b\r\ncreated by main.main\r\n        /home/sipsma/tmp/goleak/main.go:102 +0x39\r\n```\r\n\r\n#### System details\r\n\r\n```\r\ngo version go1.11.2 linux/amd64\r\nGOARCH=\"amd64\"\r\nGOBIN=\"\"\r\nGOEXE=\"\"\r\nGOFLAGS=\"\"\r\nGOHOSTARCH=\"amd64\"\r\nGOHOSTOS=\"linux\"\r\nGOOS=\"linux\"\r\nGOPATH=\"\"\r\nGOPROXY=\"\"\r\nGORACE=\"\"\r\nGOTMPDIR=\"\"\r\nGCCGO=\"gccgo\"\r\nCC=\"gcc\"\r\nCXX=\"g++\"\r\nCGO_ENABLED=\"1\"\r\nGOMOD=\"\"\r\nGOROOT/bin/go version: go version go1.11.2 linux/amd64\r\nGOROOT/bin/go tool compile -V: compile version go1.11.2\r\nuname -sr: Linux 4.9.124-0.1.ac.198.71.329.metal1.x86_64\r\n/lib64/libc.so.6: GNU C Library stable release version 2.12, by Roland McGrath et al.\r\ngdb --version: GNU gdb (GDB) Amazon Linux (7.2-50.11.amzn1)\r\n```"},"comment":{"url":"https://api.github.com/repos/golang/go/issues/comments/445077902","html_url":"https://github.com/golang/go/issues/28979#issuecomment-445077902","issue_url":"https://api.github.com/repos/golang/go/issues/28979","id":445077902,"node_id":"MDEyOklzc3VlQ29tbWVudDQ0NTA3NzkwMg==","user":{"login":"gopherbot","id":8566911,"node_id":"MDQ6VXNlcjg1NjY5MTE=","avatar_url":"https://avatars1.githubusercontent.com/u/8566911?v=4","gravatar_id":"","url":"https://api.github.com/users/gopherbot","html_url":"https://github.com/gopherbot","followers_url":"https://api.github.com/users/gopherbot/followers","following_url":"https://api.github.com/users/gopherbot/following{/other_user}","gists_url":"https://api.github.com/users/gopherbot/gists{/gist_id}","starred_url":"https://api.github.com/users/gopherbot/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/gopherbot/subscriptions","organizations_url":"https://api.github.com/users/gopherbot/orgs","repos_url":"https://api.github.com/users/gopherbot/repos","events_url":"https://api.github.com/users/gopherbot/events{/privacy}","received_events_url":"https://api.github.com/users/gopherbot/received_events","type":"User","site_admin":false},"created_at":"2018-12-07T00:16:56Z","updated_at":"2018-12-07T00:16:56Z","author_association":"NONE","body":"Change https://golang.org/cl/153078 mentions this issue: `runtime: don't clear lockedExt on locked M when G exits`"}}
{"actor":{"display_login":"gopherbot"}}