package main
import (
"fmt"
"log"
"net/http"
_ "net/http/pprof"
"sync"
"time"
)
func main() {
go func() {
log.Println(http.ListenAndServe("localhost:6060", nil))
}()
wg := sync.WaitGroup{}
fmt.Println("see cpu profile")
ch := make(chan struct{})
time.AfterFunc(time.Second*60, func() {
close(ch)
})
for i := 0; i <= 1000000; i++ {
wg.Add(1)
go func() {
defer wg.Done()
ticker := time.NewTicker(time.Millisecond * 1000)
defer ticker.Stop()
for {
select {
case <-ticker.C:
// do something
case <-ch:
return
}
}
}()
}
fmt.Println("waiting...")
wg.Wait()
fmt.Println("all done")
}
The snippet demonstrate millions of workers do something in parallel.
Everyone hold a time ticker to check job per second. Though it is kind of
ridiculous in real life.
The code works well a few days ago in Linux Mint 19(Ubuntu 18.04). It take
60-70% CPU usage of six-core Intel I5-8500T.
Once I run the code, I see the kernel take about 85% CPU(RED bar in htop)
and left 15% for user(GREEN bar in htop).
I try to debug using pprof.
Type: cpu
Time: Nov 29, 2018 at 8:56pm (CST)
Duration: 45.20s, Total samples = 1.55mins (206.39%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 90.80s, 97.34% of 93.28s total
Dropped 38 nodes (cum <= 0.47s)
Showing top 10 nodes out of 16
flat flat% sum% cum cum%
83.20s 89.19% 89.19% 83.25s 89.25% time.now
3.58s 3.84% 93.03% 3.58s 3.84% runtime.procyield
1.44s 1.54% 94.58% 1.44s 1.54% runtime._VDSO
1.04s 1.11% 95.69% 1.04s 1.11% runtime.siftdownTimer
0.69s 0.74% 96.43% 4.46s 4.78% runtime.lock
0.41s 0.44% 96.87% 5.49s 5.89% runtime.selectgo
0.16s 0.17% 97.04% 0.51s 0.55% runtime.schedule
0.11s 0.12% 97.16% 0.85s 0.91% runtime.chansend
0.10s 0.11% 97.27% 4.34s 4.65% runtime.sellock
0.07s 0.075% 97.34% 5.58s 5.98% main.main.func3
(pprof) list time.now
Total: 1.55mins
ROUTINE ======================== time.now in
/usr/local/go/src/runtime/timestub.go
1.39mins 1.39mins (flat, cum) 89.25% of Total
. . 11:
. . 12:import _ "unsafe" // for go:linkname
. . 13:
. . 14://go:linkname time_now time.now
. . 15:func time_now() (sec int64, nsec int32, mono
int64) {
47.56s 47.58s 16: sec, nsec = walltime()
35.64s 35.67s 17: return sec, nsec, nanotime() - startNano
. . 18:}
Here you can see *time.now* take almost CPU time.
After reboot it is work well as usually. see profile below.
Type: cpu
Time: Nov 28, 2018 at 11:07pm (CST)
Duration: 30.13s, Total samples = 58.85s (195.33%)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 47840ms, 81.29% of 58850ms total
Dropped 110 nodes (cum <= 294.25ms)
Showing top 10 nodes out of 67
flat flat% sum% cum cum%
26080ms 44.32% 44.32% 26080ms 44.32% runtime.procyield
6050ms 10.28% 54.60% 6050ms 10.28% runtime.futex
3990ms 6.78% 61.38% 31100ms 52.85% runtime.lock
2640ms 4.49% 65.86% 36480ms 61.99% runtime.selectgo
2290ms 3.89% 69.75% 3080ms 5.23% runtime.unlock
2070ms 3.52% 73.27% 2080ms 3.53% runtime.siftdownTimer
1450ms 2.46% 75.73% 1450ms 2.46% runtime.casgstatus
1230ms 2.09% 77.82% 1280ms 2.18% runtime.gopark
1120ms 1.90% 79.73% 1120ms 1.90% runtime.(*waitq).dequeue
920ms 1.56% 81.29% 940ms 1.60% time.now
I also run the code in MacOS 10.13 and Windows 10 as I expected. It works
well.
So is it a bug belongs to kernel or golang? even hardware?
Hardware: Dell OptiPlex 7060 micro, Intel Core I5 8500T, 8G RAM
Linux Mint 19(Ubuntu 18.04) with shipped kernel: Linux HOSTNAME
4.15.0-20-generic #21-Ubuntu SMP Tue Apr 24 06:16:15 UTC 2018 x86_64 x86_64
x86_64 GNU/Linux
Go version: go version go1.11.2 linux/amd64
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/USER/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/USER/go"
GOPROXY=""
GORACE=""
GOROOT="/usr/local/go"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
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-build427891521=/tmp/go-build
-gno-record-gcc-switches"
--
You received this message because you are subscribed to the Google Groups
"golang-nuts" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to golang-nuts+unsubscr...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
