Any tools to measure time spent in cgo calling?

[Lslightly (Lqw)]

I wonder some tools to measure time cost of each function called in cgo.

my go version is 1.16.6 linux/amd64

As I know, the process of C calling Go func will use the function in _obj/_cgo_export.c. First, _cgo_wait_runtime_init_done will be called. Then, crosscall2 will be called.

The process above is in C side.

After crosscall2, we will enter asm side, using cgocallback in src/runtime/asm_amd64.s

After cgocallback is cgocallbackg in Go side. Then, cgocallbackg, cgocallbackg1. Finally, by cb(frame)(src/runtime/cgocall.go), we enter the real go func.

So

My question is how can I measure the time cost in each function of the whole process, since the process is split into two different language.

I have heard of pprof, but it can’t give situation of time consuming in C side.
I have used clock()(time.h) to calculate the time spent in the whole process of C using Go func, but still I don’t know the situation in Go side.

I have tried

//caller.c
entern int sum(int a, int b);// go func

void caller(void)
{
    start = clock();
    {
	    result = sum(1, 2); // C calls go func
    }
    end = clock();
    time = end - start;
}

//callee.go
import "C"

//export sum
func sum(a, b C.int) C.int {
	return a + b
}

I use go build -o sum.so -buildmode=c-archive callee.go and then gcc -g -o caller.c sum.so -lpthread to get the executable file. go tool cgo callee.go to get _obj files for the convenience of gdb debug

but certainly, the measurement is not fine enough.

I have one idea:
modify the _cgo_export.c in _obj directory(i.e. add start,end in each important function) and recompile.

But actually, I don’t know how to do it.

So, could someone recommend some tools to measure the timing of cgo calling or provide some help on how to realise my daydreaming(maybe )? Any guidance is appreciated

[Lslightly (Lqw)]

How can I know time in runtime package since I could not import time? (I couldn’t modify the above question so I create a reply)

[geosoft1 (George Calianu)]

You can use the time package like in the following example.

start := time.Now().UTC()
...
fmt.Println(time.Since(start))

[Lslightly (Lqw)]

import "time" will cause import cycle(Sorry. I haven’t made the cause clear in my last reply)

you can try adding time.Now().UTC() in any place of source code in runtime package and when you use go build to build cgo related package, you will receive the import cycle message from the compiler.

fmt is the same. maybe both of them depend on runtime package

Anyway, thanks for your help! @geosoft1

[Lslightly (Lqw)]

After 2 days’ searching, I think I’ve figure out how to measure the time cost in runtime package(like in cgocallback func in runtime/cgocall.go file.

nanotime() can be used in runtime package since nanotime() itself is coded in rumtime package. Therefore, there will be no import cycle problems.

Attention! nanotime in some platforms uses fake time(runtime/time_fake.go). In linux/amd64, nanotime is nofake(runtime/time_nofake.go)

// runtime/cgocall.go
func cgocallback() {
   start := nanotime()
   // ...
   end := nanotime()
}

Besides, printint, println or print can be used in runtime package(they are also written in runtime package)

In func cgocallback in runtime/cgocall.go, however, printint, println, print can’t be used directly because it will cause stack split

I think the cause of stack split is that func cgocallback runs in g0 's stack, while print will use another stack. So stack splitting occurs and it’s not allowed in func cgocallback(I’m not sure. It’s my guess)

Anyway, using the following code solves the print problem

func cgocallback() {
    start := nanotime()
    //...
    end := nanotime()
    systemstack(func() {
        printint(end - start)
    }
}

call the printint function in system stack
It will not cause the stack split and it can really print time

I’m not really sure what I say is correct.

[Lslightly (Lqw)]

If there are any other tools with higher efficiency, please tell me. I really appreciate any ideas.