Repository: go
Issue: runtime: futex contention caused by memory allocation in goroutines
Labels: NeedsInvestigation,compiler/runtime

<!-- Please answer these questions before submitting your issue. Thanks! -->

### What version of Go are you using (`go version`)?

Go 1.13

<pre>
$ go version
go version go1.13 linux/amd64
</pre>

### Does this issue reproduce with the latest release?

I made similar obsverations with older Go versions (go 1.10.x,, go1.11.x, and go1.12.x).

### What operating system and processor architecture are you using (`go env`)?

System:      Ubuntu 18.04.3 LTS
Kernel:      Linux 4.15.0-60-generic
Processor:   Intel(R) Xeon(R) CPU E3-1230 V2 @ 3.30GHz (8 cores)

<details><summary><code>go env</code> Output</summary><br><pre>
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/felix/.cache/go-build"
GOENV="/home/felix/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/felix/.gvm/pkgsets/go1.13/global:/home/felix/regmatch"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/felix/.gvm/gos/go1.13"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/felix/.gvm/gos/go1.13/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
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-build193330363=/tmp/go-build -gno-record-gcc-switches"
</pre></details>

### What did you do?

Iteratively solving two tasks in parallel on a multi-core computer in two separate goroutines. The tasks are independent of each other. At the end of an iteration, the tasks' results are combined. Both tasks have similar running times, but they are not identical. Both tasks allocate local memory (this seems to be crucial for the problem!).

Whether using a wait group or channels at the end of an iteration does not seem to matter. The code below uses a wait group.  See also 
[main.txt](https://github.com/golang/go/files/3600480/main.txt).

* The main() function comprises a for loop with the iteration in which the tasks solved in each iteration.
* The two tasks are performed by the task() function.
* The main() function has also some flags, e.g., for setting the number of OS threads and for CPU profiling.

```
package main

import (
	"flag"
	"fmt"
	"math/rand"
	"os"
	"runtime"
	"runtime/pprof"
	"sync"
	"time"
)

func main() {
	profile := flag.Bool("profile", false, "cpu profile")
	cpu := flag.Int("cpu", runtime.GOMAXPROCS(-1), "number of OS threads")
	iterations := flag.Int("num", 100000, "number of iterations")
	//tasks    := flag.Int("tasks", 2, "number tasks per iteration")
	work := flag.Int("work", 20, "work in each task")
	flag.Parse()

	if *profile {
		var f *os.File
		var err error
		if f, err = os.Create(fmt.Sprintf("cpu%d.prof", *cpu)); err != nil {
			fmt.Printf("Failed to create file for CPU profiling (%s).\n", err)
			return
		}
		if err = pprof.StartCPUProfile(f); err != nil {
			fmt.Printf("Failed to start CPU profile (%s).\n", err)
			return
		}
		defer func() {
			pprof.StopCPUProfile()
			if err = f.Close(); err != nil {
				fmt.Printf("Failed to close file for CPU profiling (%s).\n", err)
			}
		}()
	}

	runtime.GOMAXPROCS(*cpu)
	fmt.Printf("Using %d OS threads...\n", runtime.GOMAXPROCS(-1))

	for i := 0; i < *iterations; i++ {
		n := *work - rand.Intn(8)
		in0, in1 := n+rand.Intn(4), n+rand.Intn(4)
		var out0, out1 int
		var dur0, dur1 time.Duration

		var wg sync.WaitGroup
		wg.Add(2)
		go task(in0, &out0, &dur0, &wg)
		go task(in1, &out1, &dur1, &wg)
		wg.Wait()

		fmt.Printf("%6d: %10s %10s %10s \t %d, %d\n", i, dur0, dur1, dur0-dur1, out0, out1)
	}
}

func task(in int, res *int, dur *time.Duration, wg *sync.WaitGroup) {
	stopwatch := time.Now()
	memory := make([]int, fib(in))
	for j := 0; j < len(memory); j++ {
		memory[j] = j
	}
	*res = memory[len(memory)-1]
	// Allocating some memory in the groroutine seems crucial for futex contention.
	// The bad performance behavior is not observable for *res = fib(n).
	*dur = time.Since(stopwatch)
	wg.Done()
}

func fib(n int) int {
	switch n {
	case 0:
		return 0
	case 1:
		return 1
	default:
		return fib(n-1) + fib(n-2)
	}
}
```

### What did you expect to see?

I expect that the program runs faster on >=2 CPU cores than on a single CPU core, since the tasks are carried out in parallel. I also expect that the running times are similar on 2 and 8 CPU cores. There might be some scheduling overhead when using 8 CPU cores.

Note that -work flag allows you to control the hardness of the problem in the iteration. This parameter will depend on the computer you are using. The default parameters worked well on my computer for the issue.

### What did you see instead?

The program runs indead faster with 2 CPU cores than with a single CPU core. However, on 8 CPU cores it runs significantly slower (9 seconds compared to 13 seconds; the system time as output by /usr/bin/time also increases significantly). See the file
[output.txt](https://github.com/golang/go/files/3600469/output.txt)/
for a summary of multiple runs.

Looking at the CPU profiles, one see a significant increase by runtime.futex. It seems that the goroutines are interrupted by a futex syscall, which originates from the memory allocation in one of the goroutines. Afterwards, the Go scheduler then tries to find a runnable goroutine. However, I am not very familiar with futexes and the Go scheduler. So, I might be completely wrong here.

Overall, I would have expected a far smaller scheduling overhead and unused resources (i.e., CPU cores) should not slow down the program.