time: Ticker CPU behavior with for-range and for-select

[echoface]

What version of Go are you using (go version)?

$ go version
go version go1.13 darwin/amd64

Does this issue reproduce with the latest release?

yes

What operating system and processor architecture are you using (go env)?

go env Output

$ go env
GO111MODULE="on"
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/xiao/Library/Caches/go-build"
GOENV="/Users/xiao/Library/Application Support/go/env"
GOEXE=""
GOFLAGS=" -mod="
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GONOPROXY=""
GONOSUMDB=""
GOOS="darwin"
GOPATH="/Users/xiao/.go"
GOPRIVATE=""
GOPROXY="https://goproxy.cn,https://goproxy.io,direct"
GOROOT="/usr/local/Cellar/go/1.13/libexec"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/Cellar/go/1.13/libexec/pkg/tool/darwin_amd64"
GCCGO="gccgo"
AR="ar"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD="/Users/xiao/fancy/Code/ad_go/go-app/go.mod"
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 -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/9d/7xkt00_57_z5jc0vc334wd080000gn/T/go-build401848648=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

The following code is a simplified version of the online service, after long time running(>a week), CaseOne will cause much more CPU usage than CaseTwo, (online service cpu problem be fixed after modifying to caseTwo);

package main

import (
	"fmt"
	"github.com/labstack/echo/v4"
	"time"
)

func CaseOne() {
	ticker := time.NewTicker(time.Millisecond * 10)
	i := 0
	for range ticker.C {
		if i % 100000 == 0{
			fmt.Println("i:", i)
		}
		i++
	}
}

func CaseTwo() {
	ticker := time.NewTicker(time.Millisecond * 10)
	i := 0
	for {
		select {
		case <- ticker.C:
			if i % 100000 == 0{
				fmt.Println("i:", i)
			}
			i++
		}
	}
}

func main()  {

	go CaseOne()

	//go CaseTwo()

	e := echo.New()
	e.GET("/ping", func(context echo.Context) error {
		context.String(200, "pong")
		return nil
	})
	e.Start("0.0.0.0:8888")
}

What did you expect to see?

same behavior, normal cpu usage.

What did you see instead?

after long time running, CaseOne cause service much more CPU usage than CaseTwo. (500% CPU : 10% CPU in average)

[ALTree]

It would probably help if you could try with a recent release (Go1.15) and maybe tip too, as there has been some work on timers-related stuff recently.

[davecheney]

@huangong please upgrade to Go 1.15.2 and confirm if the problem still exists.

Also, is it necessary to run a http server to demonstrate this issue? This program

package main

import (
        "fmt"
        "time"
)

func CaseOne() {
        ticker := time.NewTicker(time.Millisecond * 10)
        i := 0
        for range ticker.C {
                if i%100000 == 0 {
                        fmt.Println("i:", i)
                }
                i++
        }
}

func CaseTwo() {
        ticker := time.NewTicker(time.Millisecond * 10)
        i := 0
        for {
                select {
                case <-ticker.C:
                        if i%100000 == 0 {
                                fmt.Println("i:", i)
                        }
                        i++
                }
        }
}

func main() {

        go CaseOne()

        CaseTwo()
}

consumes a low amount of CPU under Go 1.15.2

[echoface]

thanks for your reply, http server is not the must, just for simulating the closest environment to online service.

[davecheney]

@huangong using the program I supplied above, can you reproduce the problem?

[echoface]

@davecheney seems fixed.