{"action":"created","issue":{"url":"https://api.github.com/repos/golang/go/issues/23182","repository_url":"https://api.github.com/repos/golang/go","labels_url":"https://api.github.com/repos/golang/go/issues/23182/labels{/name}","comments_url":"https://api.github.com/repos/golang/go/issues/23182/comments","events_url":"https://api.github.com/repos/golang/go/issues/23182/events","html_url":"https://github.com/golang/go/issues/23182","id":283267291,"number":23182,"title":"runtime: high contention in mheap_.lock causing low CPU utilization on allocation-intensive workload","user":{"login":"bryanpkc","id":7143326,"avatar_url":"https://avatars3.githubusercontent.com/u/7143326?v=4","gravatar_id":"","url":"https://api.github.com/users/bryanpkc","html_url":"https://github.com/bryanpkc","followers_url":"https://api.github.com/users/bryanpkc/followers","following_url":"https://api.github.com/users/bryanpkc/following{/other_user}","gists_url":"https://api.github.com/users/bryanpkc/gists{/gist_id}","starred_url":"https://api.github.com/users/bryanpkc/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/bryanpkc/subscriptions","organizations_url":"https://api.github.com/users/bryanpkc/orgs","repos_url":"https://api.github.com/users/bryanpkc/repos","events_url":"https://api.github.com/users/bryanpkc/events{/privacy}","received_events_url":"https://api.github.com/users/bryanpkc/received_events","type":"User","site_admin":false},"labels":[{"id":373402289,"url":"https://api.github.com/repos/golang/go/labels/NeedsInvestigation","name":"NeedsInvestigation","color":"ededed","default":false},{"id":150880191,"url":"https://api.github.com/repos/golang/go/labels/Performance","name":"Performance","color":"ededed","default":false}],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":{"url":"https://api.github.com/repos/golang/go/milestones/6","html_url":"https://github.com/golang/go/milestone/6","labels_url":"https://api.github.com/repos/golang/go/milestones/6/labels","id":1055141,"number":6,"title":"Unplanned","description":"No plan to fix in any specific release.\r\n","creator":{"login":"rsc","id":104030,"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":1164,"closed_issues":906,"state":"open","created_at":"2015-04-06T20:47:19Z","updated_at":"2017-12-22T19:02:39Z","due_on":"2099-12-31T08:00:00Z","closed_at":null},"comments":1,"created_at":"2017-12-19T15:19:51Z","updated_at":"2017-12-22T20:53:00Z","closed_at":null,"author_association":"NONE","body":"Please answer these questions before submitting your issue. Thanks!\r\n\r\n\r\n### What version of Go are you using (`go version`)?\r\ngo 1.8.0\r\n\r\n### Does this issue reproduce with the latest release?\r\nIt is reproducible with 1.9.2. We haven't tested with tip.\r\n\r\n### What operating system and processor architecture are you using (`go env`)?\r\nlinux amd64\r\n\r\n### What did you do?\r\nWhile tuning our application, we observed that on a system with 38 cores, we could not get more than 3000% CPU utilization. Investigation with `go tool trace` showed that all processors were always busy executing goroutines with no obvious idle times. Since the application is designed to be parallel, we suspected that the lower-than-expected CPU utilization is due to unforeseen contention and blocking, but block profiling did not show any significant user-level blocking, so we turned our attention to runtime-level contention.\r\n\r\nWe instrumented `runtime.lock` to count the number of times threads have to call `futexsleep`, and record which locks they were waiting for. The hottest locks and the number of times they were contended within a 1-minute run time were:\r\n```\r\n6174 mheap_.lock\r\n1933 stackpoolmu\r\n 296 timers.lock\r\n 101 gcBitsArenas.lock\r\n```\r\n\r\nSampling the call sites of `runtime.lock` reveals that `mheap_.lock` is contended most in `runtime.(*mheap).alloc_m`, mostly called from `runtime.(*mcentral).grow`. By hacking `grow` to increase the number of pages reserved each time `mcentral` needs more space for a size class, we were able to reduce the contention of `mheap_.lock` by a significant amount, and actually improved the average request latency of our application."},"comment":{"url":"https://api.github.com/repos/golang/go/issues/comments/353672943","html_url":"https://github.com/golang/go/issues/23182#issuecomment-353672943","issue_url":"https://api.github.com/repos/golang/go/issues/23182","id":353672943,"user":{"login":"aclements","id":2688315,"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},"created_at":"2017-12-22T20:53:00Z","updated_at":"2017-12-22T20:53:00Z","author_association":"MEMBER","body":"Thanks for the analysis. Could you describe your allocation pattern a bit? Usually many spans stay in the mcentrals, so they don't have to grow that much outside of initialization and phase changes. But it sounds like the allocations in your application have very closely tied lifetimes, so entire spans are often freed together and returned to the heap.\r\n\r\n> By hacking grow to increase the number of pages reserved each time mcentral needs more space for a size class, we were able to reduce the contention of mheap_.lock by a significant amount, and actually improved the average request latency of our application.\r\n\r\nInteresting. With your modification, is `mcentral.grow` just allocating a span that's some multiple of the usual `class_to_allocnpages`? Did you also modify `mcentral.cacheSpan`'s call to `deductSweepCredit` accordingly?\r\n\r\n/cc @RLH "}}
{"actor":{"display_login":"aclements"}}