Measuring cpu usage for a tree of goroutines

[Steven Canfield]

Hi,

I have an RPC server which has heterogenous requests, e.g. some calls hit cache and are cheaper to serve while others need to compute a result.

Is there any way to keep track of the cpu used just by one particular goroutine[1]? It seems like there's not a straightforward way today without adding logic around every single blocking piece (to start/stop a timer), and in the future will become completely impossible with "Non-cooperative goroutine preemption".

I would be happy with only knowing this number when a goroutine finishes.

I'm familiar with using pprof for measuring the entire process, but it's not clear to me how to go from there to what was used by a particular RPC, and I also can't enable profiling for every request.

Thanks,

-Steve

1: I really want a goroutine and its children, but I create new goroutines in few enough places that I could do some context mgmt to manage this.

[Robert Engels]

Look at pprof labels. 

On May 11, 2020, at 6:29 PM, Steven Canfield <stevenc...@gmail.com> wrote:



--
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...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/e2d7e3d7-c678-4515-9cdb-060d29b14500%40googlegroups.com.

[Steve Canfield]

Thanks, but what about the "I can't enable profiling for every request" bit? Assume it's actually important for me to know the cpu consumption on a per request basis.

[robert engels]

You don’t need to do it this way. see https://rakyll.org/profiler-labels/

You label the work. The work will be recorded with the labels for analysis. The labels can be nested. This will allow you to use the execution trace to profile wall time, see https://talks.golang.org/2015/dynamic-tools.slide#30

The standard pprof/profile will do cpu time profiling.

This is all you really need to do the profiling.

[robert engels]

Also, you may be interested in github.com/robaho/goanalyzer - I feel it makes latency analysis much easier.

To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/A1D870A7-ADFD-4F00-B678-E7C6C0FE80FD%40ix.netcom.com.

[Steve Canfield]

I feel like I must be really dense, but it doesn't seem like you are answering my question.

Again, assume I have good reasons to want to know the cpu usage for every request. Let's say I want to do isolation or billing or whatever on the basis of cpu usage.

Is this possible in Go?

-Steve

[Ian Lance Taylor]

On Tue, May 12, 2020 at 10:31 AM Steve Canfield
<stevenc...@gmail.com> wrote:
>
> I feel like I must be really dense, but it doesn't seem like you are answering my question.
>
> Again, assume I have good reasons to want to know the cpu usage for every request. Let's say I want to do isolation or billing or whatever on the basis of cpu usage.
>
> Is this possible in Go?

Use context labels (https://golang.org/pkg/runtime/pprof/#WithLabels)
and CPU profiling. The profile should let you attribute CPU usage per
label.

However, that approach would only do sampling. I do not know of an
approach that would let you get fairly precise CPU usage for every
request, as when multiple goroutines are running in parallel there is
no good way to separate out the CPU usage of each goroutine.

Ian

> To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/CANLJsyBF9BezZVYtoFcGCTNYQrTuVVAQoEgBC2CWVRJOxb8P-A%40mail.gmail.com.

[Steve Canfield]

Thanks Ian. Are there limits on how many such labels exist for the life of the process, or can be active at once? Would labeling by rpc_guid be acceptable?

[Ian Lance Taylor]

On Tue, May 12, 2020 at 1:01 PM Steve Canfield <stevenc...@gmail.com> wrote:
>
> Thanks Ian. Are there limits on how many such labels exist for the life of the process, or can be active at once? Would labeling by rpc_guid be acceptable?

There are no limits on labels other than memory usage.

Ian

[Robert Engels]

In my first response I said to use labels and referred you to a document on how to do it. I guess Ian’s wording was clearer :)

> On May 12, 2020, at 3:53 PM, Ian Lance Taylor <ia...@golang.org> wrote:

> To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/CAOyqgcVknCuT8e8KSwR1VQa%2BQSnBzZ9RUdBLC1PQfAYDVJzPtQ%40mail.gmail.com.

[Steve Canfield]

It's not that Ian's response was clearer, it's that he actually answered the question of if I can do $thing in Go; given that I can't he pointed me to the same reference as you.

It's okay that Go can't do some things, but being opaque about it isn't helpful.

Thanks for your help both of you!

-Steve

[robert engels]

You can do it - just create a label for each request that you want timed individually. These will be treated as distinct events.

The OS threads are shared across Go routines - so using OS thread CPU counters, or thread monitoring won’t work.

So you use labels to track “events” - in this case an event is a “request process”. The inner labels can be wrapped around calls to the db, etc. - so you can get a wholistic view of an events processing time.

Unless there is something else you are asking for… CPU profiling can identify “slow/hogs processing”. Event labels can identify “slow” wall-time events.

To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/CANLJsyD30-02N5OSQrwKbnJQ99EGy0XY3HKgJDyNtacB_EWN6A%40mail.gmail.com.

[robert engels]

To clarify, I assume you have an internal request id that is tracked (if not, I am not sure how your logging would work). Create a label that matches the request ID at the top handle request layer.

Then you can use pprof/trace, find that request, and do a detailed trace analysis on the event handling.

To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/202AFDD6-D6A0-4DD0-84D2-572BBE450111%40ix.netcom.com.