Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

testing: add Elapsed() method to testing.B #43620

Closed
mmcloughlin opened this issue Jan 11, 2021 · 16 comments
Closed

testing: add Elapsed() method to testing.B #43620

mmcloughlin opened this issue Jan 11, 2021 · 16 comments

Comments

@mmcloughlin
Copy link
Contributor

mmcloughlin commented Jan 11, 2021

Propose to add an Elapsed method to testing.B, as follows:

// Elapsed returns the measured elapsed time of the benchmark. If the timer is
// running, it will be stopped.
func (b *B) Elapsed() time.Duration {
    b.StopTimer()
    return b.duration
}

Motivation

Custom benchmark metrics are a powerful feature. Go introduced partial support with the testing.B.ReportMetric() API following #26037. However, this API seems to leave a gap in supporting rate metrics. Specifically, rate metrics are those that would be divided by the total benchmark time and reported with the /s suffix, such as the built-in MB/s. These cannot be reported using the existing API since there is no way to access the measured time.

Rate metrics have many use cases. The existence of MB/s proves at least one. You could also imagine reporting packets/s for a network benchmark, points/s for a geometry benchmark. I was just working on a benchmark for the avo assembler and wanted to report instructions/s.

Rate metrics are supported by other benchmark libraries, such as Google Benchmark, which has become somewhat of a de-facto standard for C++ benchmarking. Google Benchmark's user counters are configurable to support rate metrics with the kIsRate flag, along with many others. Google Benchmark also supports the special-case SetItemsProcessed to support examples like packets/s or points/s mentioned previously. As an example, the abseil library uses SetItemsProcessed to report the rate items are pushed to a vector.

I don't think there are satisfactory workarounds for this at the moment. You can measure the time yourself and use it to report a rate metric with ReportMetric. Alternatively, you can abuse SetBytes and post-process the output or inform your users to interpret it differently.

Propose extending the testing.B API such that this is possible. Ideas:

  • Add a ReportRate method, similar to ReportMetric but the value will be divided by time.
  • Add a SetItemsProcessed method similar to Google Benchmark.
  • Expose the measured time so users can compute the rate themselves and report it with the existing API.

Following discussion below, we propose the Elapsed() method given above.

@gopherbot gopherbot added this to the Proposal milestone Jan 11, 2021
@ianlancetaylor ianlancetaylor added this to Incoming in Proposals (old) Jan 11, 2021
@ianlancetaylor
Copy link
Contributor

CC @aclements

@josharian
Copy link
Contributor

You can measure the time yourself and use it to report a rate metric with ReportMetric.

This isn't too onerous a workaround; measuring elapsed time is both short and simple.

An alternative fix here is to add methods on testing.B that let you query the accumulated metrics, e.g. func (b *B) Elapsed() time.Duration). Sample usage:

  for i := 0; i < b.N; i++ {
    // do stuff
  }
  b.StopTimer()
  b.ReportMetric(customMetric / float64(b.Elapsed().Nanoseconds()), "custom/ns")

@mmcloughlin
Copy link
Contributor Author

This isn't too onerous a workaround; measuring elapsed time is both short and simple.

Sure, not onerous in terms of lines of code. However, it seems to me that timing code execution is a core responsibility of a benchmark framework, so it seems odd to cede that responsibility to your users.

I haven't even looked at the code under the hood, but you could imagine that the testing package wanted to use a higher precision timer than the time packages uses by default. It's nice that this is hidden from users and can be changed in the future if necessary.

An alternative fix here is to add methods on testing.B that let you query the accumulated metrics, e.g. func (b *B) Elapsed() time.Duration). Sample usage:

  for i := 0; i < b.N; i++ {
    // do stuff
  }
  b.StopTimer()
  b.ReportMetric(customMetric / float64(b.Elapsed().Nanoseconds()), "custom/ns")

Yes, this would be great. This is what I had in mind with the "Expose the measured time so users can compute the rate themselves and report it with the existing API" idea in the description. It does seem slightly awkward that you'd need some contract about calling StopTimer first.

@aclements
Copy link
Member

I wouldn't be opposed to exposing the measured elapsed time of the benchmark. While it's true that often this isn't hard to measure for yourself, it becomes much harder in benchmarks that use StopTimer and StartTimer, and having a way to retrieve the framework's own measured time would ensure that any custom time-rate measurements had exactly the same denominator as the built-in ns/op measurement. Having a consistent denominator does depend on calling StopTimer before retrieving the elapsed time, as Josh did.

@mmcloughlin
Copy link
Contributor Author

Peeking at the internals, this could be as simple as adding a Duration() time.Duration method that returns the b.duration field. The nuance is just what it should do if it's called when the timer is running. Should it:

  • Compute duration at that instant and return it, leaving the timer running
  • Return 0 if timerOn is true
  • panic if timerOn is true

@aclements
Copy link
Member

Returning 0 seems like it would invite bugs, but I'm not sure between the other two options.

@josharian
Copy link
Contributor

The nuance is just what it should do if it's called when the timer is running.

A fourth option: stop the timer. Easy to document, yields the correct outcome in most situations with a minimum of fuss.

Duration() time.Duration

I would advocate for Elapsed over Duration, because duration could also mean the target duration of the benchmark run.

@mmcloughlin
Copy link
Contributor Author

How do we progress this proposal through the process to get a decision? Based on the discussion I think the simplest concrete proposal is the addition of the following method to *testing.B:

// Elapsed returns the measured elapsed time of the benchmark. If the timer is
// running, it will be stopped.
func (b *B) Elapsed() time.Duration {
    b.StopTimer()
    return b.duration
}

Perhaps an additional note in the documentation for ReportMetric would be in order?

@mmcloughlin mmcloughlin changed the title proposal: testing: support benchmark rate metrics proposal: testing: add Elapsed() method to testing.B May 19, 2021
@rsc
Copy link
Contributor

rsc commented Jun 22, 2022

Leaving the timer running seems much less surprising than silently stopping the timer.
Otherwise this seems fine to me.

@rsc
Copy link
Contributor

rsc commented Jun 22, 2022

This proposal has been added to the active column of the proposals project
and will now be reviewed at the weekly proposal review meetings.
— rsc for the proposal review group

@rsc rsc moved this from Incoming to Active in Proposals (old) Jun 22, 2022
@mmcloughlin
Copy link
Contributor Author

Great to see this taken up!

Leaving the timer running seems much less surprising than silently stopping the timer.

Yes, I can see the argument for that.

@rsc
Copy link
Contributor

rsc commented Jun 29, 2022

Assuming Elapsed reports elapsed time but does not change the running state of the timer, does anyone object to adding Elapsed?

@rsc
Copy link
Contributor

rsc commented Jul 13, 2022

Based on the discussion above, this proposal seems like a likely accept.
— rsc for the proposal review group

@rsc rsc moved this from Active to Likely Accept in Proposals (old) Jul 13, 2022
@rsc rsc moved this from Likely Accept to Accepted in Proposals (old) Jul 20, 2022
@rsc
Copy link
Contributor

rsc commented Jul 20, 2022

No change in consensus, so accepted. 🎉
This issue now tracks the work of implementing the proposal.
— rsc for the proposal review group

@rsc rsc changed the title proposal: testing: add Elapsed() method to testing.B testing: add Elapsed() method to testing.B Jul 20, 2022
@rsc rsc modified the milestones: Proposal, Backlog Jul 20, 2022
@gopherbot
Copy link

Change https://go.dev/cl/420254 mentions this issue: testing: add Elapsed() method to testing.B

rajbarik pushed a commit to rajbarik/go that referenced this issue Sep 1, 2022
Elapsed returns the measured elapsed time of the benchmark,
but does not change the running state of the timer.

Fixes golang#43620.

Change-Id: Idd9f64c4632518eec759d2ffccbf0050d84fcc03
Reviewed-on: https://go-review.googlesource.com/c/go/+/420254
Reviewed-by: Dmitri Shuralyov <dmitshur@golang.org>
TryBot-Result: Gopher Robot <gobot@golang.org>
Auto-Submit: Bryan Mills <bcmills@google.com>
Reviewed-by: Dmitri Shuralyov <dmitshur@google.com>
Run-TryBot: hopehook <hopehook@qq.com>
Reviewed-by: Bryan Mills <bcmills@google.com>
@gopherbot
Copy link

Change https://go.dev/cl/449077 mentions this issue: doc/go1.20: add a release note for (*testing.B).Elapsed

gopherbot pushed a commit that referenced this issue Nov 14, 2022
Updates #43620.

Change-Id: If2b6f37d79c055ca5799071bf70fcc9d12b8a2a0
Reviewed-on: https://go-review.googlesource.com/c/go/+/449077
Reviewed-by: Russ Cox <rsc@golang.org>
Run-TryBot: Bryan Mills <bcmills@google.com>
Auto-Submit: Bryan Mills <bcmills@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
@golang golang locked and limited conversation to collaborators Nov 9, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
No open projects
Development

No branches or pull requests

6 participants