golang / go

The Go programming language
https://go.dev
BSD 3-Clause "New" or "Revised" License
123.86k stars 17.65k forks source link

time: AfterFunc doesn't inherit parent goroutine labels #67708

Open DmitriyMV opened 5 months ago

DmitriyMV commented 5 months ago

Go version

go version go1.22.3 or tip.

What did you do?

Run this code: https://go.dev/play/p/Yf7N3XhKsdF?v=gotip

What did you see happen?

goroutine profile: total 3
1 @ 0x42dcb1 0x4674fd 0x4b8a91 0x4b88c5 0x4b58eb 0x4ccf65 0x437d2b 0x46f581
# labels: {"myownlabel":"label"}
#   0x4b8a90    runtime/pprof.writeRuntimeProfile+0xb0  /usr/local/go-faketime/src/runtime/pprof/pprof.go:767
#   0x4b88c4    runtime/pprof.writeGoroutine+0x44   /usr/local/go-faketime/src/runtime/pprof/pprof.go:726
#   0x4b58ea    runtime/pprof.(*Profile).WriteTo+0x14a  /usr/local/go-faketime/src/runtime/pprof/pprof.go:368
#   0x4ccf64    main.main+0x1c4             /tmp/sandbox135271070/prog.go:24
#   0x437d2a    runtime.main+0x28a          /usr/local/go-faketime/src/runtime/proc.go:272

1 @ 0x46806e 0x46b4e5 0x4ccfbd 0x46f581
#   0x46b4e4    time.Sleep+0xe4     /usr/local/go-faketime/src/runtime/time.go:285
#   0x4ccfbc    main.main.func1+0x1c    /tmp/sandbox135271070/prog.go:18

1 @ 0x46806e 0x46b4e5 0x4ccffd 0x46f581
# labels: {"myownlabel":"label"}
#   0x46b4e4    time.Sleep+0xe4     /usr/local/go-faketime/src/runtime/time.go:285
#   0x4ccffc    main.main.func2+0x1c    /tmp/sandbox135271070/prog.go:20```

What did you expect to see?

goroutine profile: total 3
1 @ 0x42dcb1 0x4674fd 0x4b8a91 0x4b88c5 0x4b58eb 0x4ccf65 0x437d2b 0x46f581
# labels: {"myownlabel":"label"}
#   0x4b8a90    runtime/pprof.writeRuntimeProfile+0xb0  /usr/local/go-faketime/src/runtime/pprof/pprof.go:767
#   0x4b88c4    runtime/pprof.writeGoroutine+0x44   /usr/local/go-faketime/src/runtime/pprof/pprof.go:726
#   0x4b58ea    runtime/pprof.(*Profile).WriteTo+0x14a  /usr/local/go-faketime/src/runtime/pprof/pprof.go:368
#   0x4ccf64    main.main+0x1c4             /tmp/sandbox135271070/prog.go:24
#   0x437d2a    runtime.main+0x28a          /usr/local/go-faketime/src/runtime/proc.go:272

1 @ 0x46806e 0x46b4e5 0x4ccfbd 0x46f581
# labels: {"myownlabel":"label"}
#   0x46b4e4    time.Sleep+0xe4     /usr/local/go-faketime/src/runtime/time.go:285
#   0x4ccfbc    main.main.func1+0x1c    /tmp/sandbox135271070/prog.go:18

1 @ 0x46806e 0x46b4e5 0x4ccffd 0x46f581
# labels: {"myownlabel":"label"}
#   0x46b4e4    time.Sleep+0xe4     /usr/local/go-faketime/src/runtime/time.go:285
#   0x4ccffc    main.main.func2+0x1c    /tmp/sandbox135271070/prog.go:20

I think it's kinda confusing that this way you can bypass labels inheriting.

ruyi789 commented 5 months ago

use chan

DmitriyMV commented 5 months ago

use chan

That's creates unnecessary goroutines before we actually need them.

AndrewHarrisSPU commented 5 months ago

I think it's kinda confusing that this way you can bypass labels inheriting.

Is this an honest consequence of the more complicated truth about how the runtime handles timers? Part of the story seems like it's hinted at in this detail from AfterFunc:

AfterFunc waits for the duration to elapse and then calls f in its own goroutine.

Maybe it's a bit hand-wavy to say that this is enough documentation to reach a conclusion I think is fair (that this is an honest consequence).

mknyszek commented 5 months ago

How do other APIs that spawn goroutines on behalf of the caller behave? Do we propagate goroutine labels to them?

I could see this being the right behavior 90% of the time, but occasionally goroutines might be created on behalf of some other goroutine with other labels, and in that case it might be misleading. I don't really know what the right behavior should be for these kinds of APIs.