Go: doc: runtime/pprof: block profiler documentation needs some love

[pwaller]

Reading https://golang.org/pkg/runtime/pprof/ does not make clear how to use the blocking profiler in an application.

The blog post at http://blog.golang.org/profiling-go-programs (2011) finishes with:

The goroutine blocking profile will be explained in a future post. Stay tuned.

But I cannot find any follow up.

In a post to the mailing list someone said that Brad mentioned it briefly in a talk, but he only mentions go test -blockprofile, and I'm not running tests.

I have used several search engines to look for materials but they all point at runtime/pprof and other not-useful-to-me blog posts. Getting creative, I just thought I would dive in and try to use it:

    f, err := os.Create("block.pprof")
    if err != nil {
        log.Fatal(err)
    }
    p := pprof.Lookup("block")
    defer func() {
        err := p.WriteTo(f, 0)
        if err != nil {
            log.Fatalf("Error writing block profile: %v", err)
        }
    }()

Which results in a file with contents which don't look useful:

--- contention:
cycles/second=2494323129

Finally, I searched github for "pprof lookup block". This appears to show some examples of its use and reveals the function runtime.SetBlockProfile. However, this function is also quite confusingly documented.

func SetBlockProfileRate(rate int)

SetBlockProfileRate controls the fraction of goroutine blocking events that are reported in the blocking profile. The profiler aims to sample an average of one blocking event per rate nanoseconds spent blocked.

To include every blocking event in the profile, pass rate = 1. To turn off profiling entirely, pass rate <= 0.

Is rate really a fraction, between 0 and 1? If so, since it is an int, it would seem my options are to either pass it 0 or 1, but the suggestion that it is a fraction seems contradictory. Is it necessary to call this function to start the profiler?

To conclude, the documentation at runtime/pprof really needs to make it clear how to use the block profiler. Some facts which are still not clear to me, even after reading code found elsewhere:

• What kind of questions can be answered with a block profile?
  
  
  
  • Will it help me identify contention on a channel write?
  
  
  • Will it tell me where in my program is contending?
  
  
• How do I use the block profiler in my application?
• Is there something one must do to start the block profiler?
• How often can one write a block profile? Once at the end of a running program?
• Why is there not a StartBlockProfiler function?
• How does one interpret the results of a block profile?

P.S. I did eventually find Debugging performance issues in Go programs, which answers some of these questions. But unfortunately it was not easy to find for some reason.

[rhysh]

runtime.SetBlockProfileRate has two special values: 0 to disable, and 1 to catch every single event. You can also set it to e.g. 1,000,000,000 (aka int(time.Second.Nanoseconds())) to record one sample per second that a goroutine is blocked at a particular location. If your program does not set the rate to something > 0, the block profile will contain no data.

What I'd be most interested to learn from a blog post on the blocking profiler is what to expect in terms of performance overhead. I've taken the fact that it's not enabled by default (compared with e.g. the heap profiler) to mean that it may have a significant impact on runtime performance. On the other hand, its instrumentation points seem to be a subset of what's covered by runtime/trace, which is automatically accessible via net/http/pprof. Dmitry Vyukov's article mentions that it interferes with the scheduler trace, which could be part of the answer.

[pwaller]

Thanks @rhysh, that clears up the units a little. I found this sentence is quite hard to read. With the example @rhysh gave of set it to 1G and it samples all blocked goroutines once per second and suddenly it's easy to read. Maybe an example would help?

The profiler aims to sample an average of one blocking event per rate nanoseconds spent blocked.

[anacrolix]

Any progress on this?

[bradfitz]

No progress on this. (Progress would be posted here, and nothing is posted here)

Help wanted.

[hawkinsw]

I have reason to use this in a non-server context. I will attempt to provide/contribute some documentation but I can't make any guarantees that it will be interesting or useful. I will update here as I get information.

[hawkinsw]

I would really like to add this function:

func WriteBlockProfile(w io.Writer) error {
    return writeBlock(w, 0)
}

to src/runtime/pprof/pprof.go. I think that would make the Block profile API more consistent with the memory and CPU profile APIs. I know that this is not the place to get code reviews, but I wanted to get everyone's gut reaction before I started with the gerrit code review, etc.

I have already integrated this into a few test applications and it works pretty well, actually.

I look forward to hearing your feedback!

Thanks!
Will

@bradfitz

[bradfitz]

@whh8b, it's too late to add anything new to Go 1.9. This CL is marked Go 1.9Maybe because it's a documentation-only change. To propose new API changes, open a new bug.

[pwaller]

Just came across a comment from @rsc on reddit about this:

We do believe that the blocking profiler does what it is advertised to do, because there are tests for it. That said, I have never found the profiles particularly useful, and maybe that's what you meant by "I get stuck". To me, the fundamental issue is that what you really want is to distinguish good blocking (like a goroutine waiting for the next network request; that time is not the application's fault) from bad blocking (like excessive delay due to mutex contention). It's difficult to do that without some knowledge of the application, although perhaps we could do better by having just a mutex contention profile; that would be most useful if all the other kinds of blocking are "good" for your program.

[Swarup-git]

More than 3 years has gone since this post is initiated as today's date is 19/08/2019 and still credible information is unavailable on GoLang Blocking profiler.
I'm a performance engineer and novice in GoLang. Been doing some basic CPU and Memory related profiling on Go Testapps and having a check on this blocking profiler for last 6 months. However it's heartbroken to not find any useful information around this Blocking Profile anywhere. All we could find is some high level description and how to enable this profiler. Without any doubt, those bit of information are helpful and we could enable this and get the profiling data available with browser. However, we're entirely clueless on how to analyze the output or rather in lay man term how to even read through the report (As vast amount of details are available).
Lastly being a novice in GoLang (as I've mentioned earlier), I might be completely wrong about the whole and one might ask me to be an expert in Go first and then come and post here. In such cases my humble request would be to kindly help out by pointing helpful resources in understanding and analyzing this Blocking Profiling.