Repository: go
Issue: time: timer gets significantly delayed during long time GC
Labels: NeedsInvestigation

<!--
Please answer these questions before submitting your issue. Thanks!
For questions please use one of our forums: https://github.com/golang/go/wiki/Questions
-->

### What version of Go are you using (`go version`)?
go1.15.8
<pre>
$ go version

</pre>

### Does this issue reproduce with the latest release?
Yes


### What operating system and processor architecture are you using (`go env`)?

<details><summary><code>go env</code> Output</summary><br><pre>
$ go env
set GO111MODULE=
set GOARCH=amd64
set GOBIN=
set GOCACHE=C:\Users\xxx\AppData\Local\go-build
set GOENV=C:\Users\xxx\AppData\Roaming\go\env
set GOEXE=.exe
set GOFLAGS=
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOINSECURE=
set GOMODCACHE=C:\Users\xxx\go\pkg\mod
set GONOPROXY=
set GONOSUMDB=
set GOOS=windows
set GOPATH=C:\Users\xxx\go
set GOPRIVATE=
set GOPROXY=https://proxy.golang.org,direct
set GOROOT=C:\Program Files\Go
set GOSUMDB=sum.golang.org
set GOTMPDIR=
set GOTOOLDIR=C:\Program Files\Go\pkg\tool\windows_amd64
set GCCGO=gccgo
set AR=ar
set CC=gcc
set CXX=g++
set CGO_ENABLED=1
set GOMOD=
set CGO_CFLAGS=-g -O2
set CGO_CPPFLAGS=
set CGO_CXXFLAGS=-g -O2
set CGO_FFLAGS=-g -O2
set CGO_LDFLAGS=-g -O2
set PKG_CONFIG=pkg-config
set GOGCCFLAGS=-m64 -mthreads -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=C:\Users\xxx\AppData\Local\Temp\go-build791935606=/tmp/go-build -gno-record-gcc-switches
</pre></details>

### What did you do?
First, I initialized a large number of objects that will not be released during the running of my program. These objects will cause a long GC time.
Then I started 6 goroutines:
- 1 goroutine blocked on a ticker with 200ms period, it will print the ticker time received from the channel tick.C;
- 4 goroutines with busy task, just infinite loop;
- 1 goroutine for trigging GC every second.

After that, the main goroutine sleeps for 20 seconds, and waits for the ticker goroutine's printing.

The source codes of my program are also posted:

```go
package main

import (
	"fmt"
	"runtime"
	"time"
)

var x [][]*int

func prepareGarbage() {
	x = make([][]*int, 100)
	for i := range x {
		x[i] = make([]*int, 10000000)
	}
}

func main() {
	fmt.Println(runtime.Version())
	// GOMAXPROCS should be at least 4, so dedicated GC will be enabled.
	runtime.GOMAXPROCS(4) 

	// prepareGarbage for long GC mark time
	prepareGarbage()

	go ticker(200)

	// for keeping all P busy
	for i := 0; i < 4; i++ {
		go busyTask()
	}

	go func() {
		for {
			time.Sleep(time.Second)
			runtime.GC()
		}
	}()

	// sleep enough time for the timer wakeup delay happening
	time.Sleep(time.Second * 20)
}

func ticker(periodms int64) {
	tc := time.NewTicker(time.Duration(periodms) * time.Millisecond)
	fmt.Printf("timer with %v ms period started...\n", periodms)
	var ticks uint64
	var last time.Time
	for t := range tc.C {
		if ticks == 0 {
			last = t
		} else {
			elapsedTime := t.Sub(last).Milliseconds()
			if elapsedTime > periodms*2 {
				fmt.Printf("\n%v ms=========== WAKE UP TOO LATE!!!\n", elapsedTime)
			} else {
				fmt.Printf("%v, ", elapsedTime)
			}
			last = t
		}
		ticks++
	}
}

func busyTask() {
	for {
		task()
	}
}

//go:noinline
func task() {
	do()
}

//go:noinline
func do() {}
```


### What did you expect to see?
I expect to see all the elapsed time will be around 200 with small deviation.

go1.15.8
timer with 200 ms period started...
200, 200, 200, 200, 200, 200, 200, 200, 200, 200, 200, 200, 200, 200, 190, 200, 200, 200, 200, 200, 200, 200, 200, 200, .......
Process finished with exit code 0

### What did you see instead?
I actually found the timer will be randomly delayed with a large delta. In some test, the 200 ms ticker can be unbelievably delayed for more than one second. The result is posted:

go1.15.8
timer with 200 ms period started...
200, 200, 200, 200, 200, 200, 200, 200, 200, 200, 200, 200, 200, 190, 200, 200, 200, 200, 200, 201, 200, 200, 200, 
541 ms=========== WAKE UP TOO LATE!!!
59, 200, 200, 200, 200, 
1516 ms=========== WAKE UP TOO LATE!!!
84, 200, 200, 200, 200, 
1458 ms=========== WAKE UP TOO LATE!!!
142, 200, 200, 200, 200, 
1403 ms=========== WAKE UP TOO LATE!!!
197, 200, 200, 200, 200, 
1378 ms=========== WAKE UP TOO LATE!!!
22, 200, 200, 200, 200, 
1528 ms=========== WAKE UP TOO LATE!!!
72, 200, 200, 200, 200, 
1511 ms=========== WAKE UP TOO LATE!!!
89, 200, 
Process finished with exit code 0