profile: How to profile a go program base on wall time instead of cpu time?

[ppggff]

As I know, go profile use SIGPROF to sample call stacks N times per second in cpu time.
It will ignore idle time, waiting time since these time doesn’t consume cpu.

To profile a go program with mix load, I want to profile it base on wall time: samples
call stacks N times per second in wall time. And it will show the result in same UI of cpu time.

For example, poor man’s profiler (https://poormansprofiler.org/) sampling program by running gdb per second(or minute).

How to do it with current go prof? or some others tools?

[ppggff]

And I am trying to make it work by:

• Set cpu sample rate to 1Hz
• Start a time ticker (100Hz) to send SIGPROF to self

[geosoft1 (George Calianu)]

Perhaps you are looking for time.Since

package main

import (
	"time"
)

func main() {
	start := time.Now()
	time.Sleep(3)
	println(time.Since(start))
}

[ppggff]

It works, but there are so many function in my program…

[geosoft1 (George Calianu)]

Start measuring the relevant ones. I’m think that is not important to know the execution time for every function of your program.

[johandalabacka (Johan Dahl)]

You could make a package like this. Now I just put it in package main. Which counts calls and time taken for every function

package main

import (
	"fmt"
	"io"
	"time"
)

type called struct {
	count     int
	totalTime time.Duration
}

var func2called map[string]*called

func init() {
	func2called = make(map[string]*called, 100)
}

func Measure(funcName string, start time.Time) {
	timeTaken := time.Since(start)
	c, ok := func2called[funcName]
	if ok {
		c.count++
		c.totalTime += timeTaken
	} else {
		func2called[funcName] = &called{count: 1, totalTime: timeTaken}
	}
}

func WriteCalled(w io.Writer) {
	for k, v := range func2called {
		fmt.Fprintf(w, "%s: called %d times, %s total time, %s average\n",
			k, v.count, v.totalTime, v.totalTime/time.Duration(v.count))
	}
}

and then you can call it like this. The only function you can’t measure with defer is main

package main

import (
	"os"
	"time"
)

func f() {
	defer Measure("f", time.Now())

	time.Sleep(3 * time.Second)
}

func g() {
	defer Measure("g", time.Now())

	time.Sleep(time.Second)
}

func main() {
	start := time.Now()
	f()

	for i := 0; i < 5; i++ {
		g()
	}

	Measure("main", start)
	WriteCalled(os.Stdout)
}

I leave it as an exercise for you to make the function safe to call from multiple go routines, sort the output on some useful variable and also write a program which adds the defer line in every function body in your project