go pprof includes cpu and syscall time

cpu8_server.go

package main

import (
	"fmt"
	"log"
	"os"
	"runtime/pprof"
	"sync"
)

func main() {
	f, err := os.Create("cpuprof.prof")
	if err != nil {
		log.Fatalln(err)
	}
	pprof.StartCPUProfile(f)
	defer pprof.StopCPUProfile()

	var wg sync.WaitGroup
	numGoroutines := 10000000 // 10 MILLION
	wg.Add(numGoroutines)
	protected := 0
	var lock sync.Mutex
	for i := 0; i < numGoroutines; i++ {
		go func() { // func1
			lock.Lock()
			protected++
			lock.Unlock()
			wg.Done()
		}()
	}
	lock.Lock()
	fmt.Println("main Got lock")
	fmt.Println("protected value", protected)
	lock.Unlock()
	wg.Wait()
}

cpu8_server.txt

time GOMAXPROCS=8 ./server
main Got lock
protected value 10000000

real	0m2.658s
user	0m7.512s
sys	0m0.286s

(pprof) top10
5860ms of 7010ms total (83.59%)
Dropped 11 nodes (cum <= 35.05ms)
Showing top 10 nodes out of 35 (cum >= 260ms)
      flat  flat%   sum%        cum   cum%
    1150ms 16.41% 16.41%     1770ms 25.25%  runtime.gfget
     780ms 11.13% 27.53%      780ms 11.13%  runtime.cas
     770ms 10.98% 38.52%     6420ms 91.58%  runtime.newproc1
     690ms  9.84% 48.36%      690ms  9.84%  runtime.usleep
     500ms  7.13% 55.49%      500ms  7.13%  runtime.cas64
     480ms  6.85% 62.34%      490ms  6.99%  runtime.atomicload
     430ms  6.13% 68.47%      430ms  6.13%  runtime.gostartcallfn
     410ms  5.85% 74.32%      410ms  5.85%  runtime.atomicstore
     390ms  5.56% 79.89%     1170ms 16.69%  runtime.casgstatus
     260ms  3.71% 83.59%      260ms  3.71%  runtime.mach_semaphore_signal

cpu_server.go

package main

import (
	"fmt"
	"log"
	"os"
	"runtime/pprof"
	"sync"
)

func main() {
	f, err := os.Create("cpuprof.prof")
	if err != nil {
		log.Fatalln(err)
	}
	pprof.StartCPUProfile(f)
	defer pprof.StopCPUProfile()

	var wg sync.WaitGroup
	numGoroutines := 1000000 // 1 MILLION
	wg.Add(numGoroutines)
	protected := 0
	var lock sync.Mutex
	for i := 0; i < numGoroutines; i++ {
		go func() { // func1
			lock.Lock()
			protected++
			lock.Unlock()
			wg.Done()
		}()
	}
	lock.Lock()
	fmt.Println("main Got lock")
	fmt.Println("protected value", protected)
	lock.Unlock()
	wg.Wait()
}

cpu_server.txt

time GOMAXPROCS=1 ./server
main Got lock
protected value 1000000

real	0m2.863s
user	0m1.067s
sys	0m1.787s

top10
2.25s of 2.25s total (  100%)
Showing top 10 nodes out of 41 (cum >= 0.03s)
      flat  flat%   sum%        cum   cum%
     1.07s 47.56% 47.56%      1.44s 64.00%  runtime.stackpoolalloc
     0.37s 16.44% 64.00%      0.44s 19.56%  runtime.mCentral_Grow
     0.34s 15.11% 79.11%      0.34s 15.11%  runtime.mmap
     0.23s 10.22% 89.33%      0.23s 10.22%  runtime.mach_semaphore_wait
     0.09s  4.00% 93.33%      0.45s 20.00%  runtime.mHeap_Grow
     0.07s  3.11% 96.44%      0.07s  3.11%  runtime.memclr
     0.03s  1.33% 97.78%      0.48s 21.33%  runtime.mHeap_AllocSpanLocked
     0.02s  0.89% 98.67%      0.02s  0.89%  runtime.memmove
     0.02s  0.89% 99.56%      0.02s  0.89%  runtime.recordspan
     0.01s  0.44%   100%      0.03s  1.33%  runtime.allgadd

long_sleep_server.go

package main

import (
	"fmt"
	"log"
	"os"
	"runtime/pprof"
	"sync"
	"time"
)

func main() {
	f, err := os.Create("cpuprof.prof")
	if err != nil {
		log.Fatalln(err)
	}
	pprof.StartCPUProfile(f)
	defer pprof.StopCPUProfile()

	var wg sync.WaitGroup
	var lock sync.Mutex
	wg.Add(1)
	go func() { // func1
		lock.Lock()
		fmt.Println("goroutine")
		lock.Unlock()
		wg.Done()
	}()
	lock.Lock()
	time.Sleep(30 * time.Second)
	fmt.Println("main Got lock")
	lock.Unlock()
	wg.Wait()
}

long_sleep_server.txt

time GOMAXPROCS=1 ./server
main Got lock
goroutine

real	0m30.017s
user	0m0.002s
sys	0m0.007s

(pprof) top10
profile is empty

sleep_server.go

package main

import (
	"fmt"
	"log"
	"os"
	"runtime/pprof"
	"sync"
	"time"
)

func main() {
	f, err := os.Create("cpuprof.prof")
	if err != nil {
		log.Fatalln(err)
	}
	pprof.StartCPUProfile(f)
	defer pprof.StopCPUProfile()

	var wg sync.WaitGroup
	numGoroutines := 1000000 // 1 MILLION
	wg.Add(numGoroutines)
	protected := 0
	var lock sync.Mutex
	for i := 0; i < numGoroutines; i++ {
		go func() { // func1
			lock.Lock()
			//protected++
			time.Sleep(1 * time.Nanosecond)
			lock.Unlock()
			wg.Done()
		}()
	}
	lock.Lock()
	fmt.Println("main Got lock")
	fmt.Println("protected value", protected)
	lock.Unlock()
	wg.Wait()
}

sleep_server.txt

time GOMAXPROCS=1 ./server
main Got lock
protected value 0

real	0m8.045s
user	0m6.182s
sys	0m1.832s

top10
7.01s of 7.07s total (99.15%)
Dropped 13 nodes (cum <= 0.04s)
Showing top 10 nodes out of 32 (cum >= 7.07s)
      flat  flat%   sum%        cum   cum%
     5.26s 74.40% 74.40%      5.26s 74.40%  runtime.mach_semaphore_wait
     1.05s 14.85% 89.25%      1.39s 19.66%  runtime.stackpoolalloc
     0.30s  4.24% 93.49%      0.30s  4.24%  runtime.mmap
     0.29s  4.10% 97.60%      0.32s  4.53%  runtime.mCentral_Grow
     0.10s  1.41% 99.01%      0.39s  5.52%  runtime.mHeap_Grow
     0.01s  0.14% 99.15%      0.41s  5.80%  runtime.mHeap_AllocSpanLocked
         0     0% 99.15%      1.81s 25.60%  main.main
         0     0% 99.15%      5.26s 74.40%  runtime.(*cpuProfile).getprofile
         0     0% 99.15%      5.26s 74.40%  runtime.CPUProfile
         0     0% 99.15%      7.07s   100%  runtime.goexit