Skip to content
This repository was archived by the owner on Nov 30, 2024. It is now read-only.

Refactor group profile to include before hooks #1971

Merged
merged 9 commits into from
Jun 3, 2015
Merged

Conversation

JonRowe
Copy link
Member

@JonRowe JonRowe commented May 27, 2015

This is #1942 refactored, fixes #1878 ping @myronmarston

@JonRowe JonRowe force-pushed the refactor_issue_1878 branch from 851bf84 to c67a168 Compare May 27, 2015 02:30
def profiler
@profiler ||=
begin
if value_for(:profile_examples) { @profile_examples }
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can't this use the profile_examples method instead of repeating its logic to get a value?

@JonRowe JonRowe force-pushed the refactor_issue_1878 branch 2 times, most recently from cd3b4f5 to ba8d295 Compare May 29, 2015 03:47
@JonRowe
Copy link
Member Author

JonRowe commented May 29, 2015

I updated this slightly

@JonRowe JonRowe force-pushed the refactor_issue_1878 branch from ba8d295 to 1079539 Compare May 29, 2015 04:20
@@ -31,6 +31,7 @@
option_parser
configuration_options
runner
profiler
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we avoid the cost of loading this file if the user isn't using --profile?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Originally we had both profilers in that file, which itself would have allowed a small cost reduction when not using --profile but in order to make config#profile_examples dynamic we must always have the profiler on (it's not actually doing much just capturing stats that aren't captured during run time normally)

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

but in order to make config#profile_examples dynamic we must always have the profiler on

A big reason tracking example group execution time in a registered formatter (even if you don't call it one but I do!) appealed to me is that we want the added runtime cost of tracking times for profiling to only be paid if the user has opted in via --profile. It makes me a sad panda to always pay the cost of tracking that when the user hasn't turned on profiling.

IMO, we don't need to support dynamic changes to config#profile_examples after the suite has started running. We can treat it like adding a formatter: it has to be done before the suite starts to take affect. (A user obviously can't expect to turn on profiling half way through the suite run and expect it to work).

My problem with what you had before is that config exposed the profile_examples option and a derived attribute, and it seems bad for an object to expose a derived attribute but then not keep it in sync with the source value. Now that you're not exposing the profiler object off of config, I'm not concerned about that anymore. Now I just view profile_examples as a boolean toggle that is checked once, when setting things up to start running the suite, and ignored the rest of the time. Users can toggle it back and forth all they want before the suite starts and it'll work fine still.

In effect, I think we should only load the profiler and register it with the reporter if we get here. That'll avoid the cost of loading and using it if the user hasn't opted-in to it.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A big reason tracking example group execution time in a registered formatter (even if you don't call it one but I do!)

In our terms a formatter is responsible for output to the user, in some cases they format the data themselves in others they use the presenter pattern to share workload between them, the Profiler does neither of these, it neither outputs anything or formats anything, it just captures values. It's no more a formatter than the reporter, or the runner or any other core component of RSpec.

The reporter follows (roughly) the event bus pattern, it sends out events when triggered to any registered listener of which the primary example are formatters I will admit, but this is not a formatter. In the same way your exception presenter wasn't a formatter. Naming is important.

appealed to me is that we want the added runtime cost of tracking times for profiling to only be paid if the user has opted in via --profile. It makes me a sad panda to always pay the cost of tracking that when the user hasn't turned on profiling.

IMO, we don't need to support dynamic changes to config#profile_examples after the suite has started running. We can treat it like adding a formatter: it has to be done before the suite starts to take affect. (A user obviously can't expect to turn on profiling half way through the suite run and expect it to work).

Thats fine but theres probably edge cases involved and I'd rather go back to setting it at the start, off or on, no half way ground (because otherwise the profiler has to go back to config, or we have to setup two way communication between the config and the reporter (to turn on and off the profiler), which I'd rather not do.

My problem with what you had before is that config exposed the profile_examples option and a derived attribute, and it seems bad for an object to expose a derived attribute but then not keep it in sync with the source value. Now that you're not exposing the profiler object off of config, I'm not concerned about that anymore. Now I just view profile_examples as a boolean toggle that is checked once, when setting things up to start running the suite, and ignored the rest of the time. Users can toggle it back and forth all they want before the suite starts and it'll work fine still.

They won't be able to do that if the Profiler / NoProfiler is initialised in the reporter unless we somehow hook into the repoter from the config, I'd rather we set it once.

In effect, I think we should only load the profiler and register it with the reporter if we get here. That'll avoid the cost of loading and using it if the user hasn't opted-in to it.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In our terms a formatter is responsible for output to the user, in some cases they format the data themselves in others they use the presenter pattern to share workload between them, the Profiler does neither of these, it neither outputs anything or formats anything, it just captures values. It's no more a formatter than the reporter, or the runner or any other core component of RSpec.

The reporter follows (roughly) the event bus pattern, it sends out events when triggered to any registered listener of which the primary example are formatters I will admit, but this is not a formatter. In the same way your exception presenter wasn't a formatter. Naming is important.

What you're saying makes sense, but reveals that I totally misunderstood your request on the other PR to rename the thing form ExceptionFormatter to something else. You're right that the things we register with the reporter are "listeners" (not necessarily output formatters) but unfortunately, our public API speaks only of formatters. The public API is add_formatter, not add_listener. It might be worth changing that in RSpec 4 (since registering a listener is the generic way to be notified of events...and it's always bothered me that a user has to register a "formatter" for that...) to add_listener. Although, that might not be worth the pain it could cause for users...who knows.

I've been thinking of the "formatters" directory as the place where all the listener class definitions are, but we just happen to keep calling them "formatters" since that's what they've been called for years. It feels really odd to me to split where the listener classes are defined (since they feel natural to be grouped to me) but you're right that it's also odd to put a non-formatting listener in formatters. I wish the directory was called "listeners", frankly :(.

Anyhow, I think we've been talking past each other a bit and our different usage of "formatter" is largely why, I think.

Thats fine but theres probably edge cases involved and I'd rather go back to setting it at the start, off or on, no half way ground (because otherwise the profiler has to go back to config, or we have to setup two way communication between the config and the reporter (to turn on and off the profiler), which I'd rather not do.

We've been treating the profile_examples option in the way I'm suggesting for all RSpec 3 release -- after all, the ProfileFormatter is only registered if profile_examples is set when setup_default is executing. If the ProfileFormatter is registered, it's essential that this new listener is also registered, right? Otherwise the ProfileFormatter won't work properly. On the flip side, if the ProfileFormatter isn't registered, then this new listener serves no purpose, and it's wasted computation to register it and have it listen to the events.

So why not register them both together at the same time based on the value of the config option at that point?

I don't understand what the two way communication issue you refer to is or why this would necessitate moving it back onto the config object (where it doesn't belong, IMO).

One thing that might help is to consider having the reporter always initialize (and expose) a profile_results hash. When instantiating the Profile listener we can then pass that to it so that it can populate it as it listens. That way, the reporter always has a valid profile_results object that it can provide to the notification regardless of whether or not the profiler listener was actually used. It's just that it'll be empty if the profile listener wasn't used, which makes sense, IMO.

They won't be able to do that if the Profiler / NoProfiler is initialised in the reporter unless we somehow hook into the repoter from the config, I'd rather we set it once.

Not following you here again. I thought we did away with NoProfiler? Why does this necessitate bringing that back?

Sorry if it seems like I'm being argumentative here...I'm not intending to be. I just care a lot about organizing RSpec's code in such a way that for optional features like the profiling, users only pay the runtime cost of that extra computation if they've opted-in to use the feature (kinda like how you care so much about stdlib usage!). I think such an approach is essential to keeping RSpec fast even as we add and refine features.

Maybe what I'm asking for isn't easily possible for a reason I'm not yet seeing. But I'd like to at least understand why if that's the case.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What you're saying makes sense, but reveals that I totally misunderstood your request on the other PR to rename the thing form ExceptionFormatter to something else. You're right that the things we register with the reporter are "listeners" (not necessarily output formatters) but unfortunately, our public API speaks only of formatters. The public API is add_formatter, not add_listener. It might be worth changing that in RSpec 4 (since registering a listener is the generic way to be notified of events...and it's always bothered me that a user has to register a "formatter" for that...) to add_listener. Although, that might not be worth the pain it could cause for users...who knows.

The reporter does have add_listener, add_formatter does something else, it sets up output streams, instantiates a formatter and then registers it as a listener on the reporter. It's possible already for extensions to utilise that hook without going through the process of registering a formatter, the reason we do that for formatters is they need a way to be distinguished from legacy formatters and it makes it easier to specify them from the command line etc.

I've been thinking of the "formatters" directory as the place where all the listener class definitions are, but we just happen to keep calling them "formatters" since that's what they've been called for years. It feels really odd to me to split where the listener classes are defined (since they feel natural to be grouped to me) but you're right that it's also odd to put a non-formatting listener in formatters. I wish the directory was called "listeners", frankly :(.

I don't, it'd be ok with having two directories though.

We've been treating the profile_examples option in the way I'm suggesting for all RSpec 3 release -- after all, the ProfileFormatter is only registered if profile_examples is set when setup_default is executing. If the ProfileFormatter is registered, it's essential that this new listener is also registered, right? Otherwise the ProfileFormatter won't work properly. On the flip side, if the ProfileFormatter isn't registered, then this new listener serves no purpose, and it's wasted computation to register it and have it listen to the events.

So why not register them both together at the same time based on the value of the config option at that point?

This I could do.

I don't understand what the two way communication issue you refer to is or why this would necessitate moving it back onto the config object (where it doesn't belong, IMO).

Theres no two way communication required as long as you're ok with:

config.profile_examples = true
config.profile_examples = false

Not actually removing the profiler or the profile formatter.

One thing that might help is to consider having the reporter always initialize (and expose) a profile_results hash. When instantiating the Profile listener we can then pass that to it so that it can populate it as it listens. That way, the reporter always has a valid profile_results object that it can provide to the notification regardless of whether or not the profiler listener was actually used. It's just that it'll be empty if the profile listener wasn't used, which makes sense, IMO.

Thats what NoProfiler was for, I didn't want to conflate the reporter with responsibility it didn't need.

Not following you here again. I thought we did away with NoProfiler? Why does this necessitate bringing that back?

It's a null object version of the profiler... if you have a way to turn profiling off you need one or you have to add if statements or unrelated state to the reporter, both of which I'd rather not do.

Sorry if it seems like I'm being argumentative here...I'm not intending to be. I just care a lot about organizing RSpec's code in such a way that for optional features like the profiling, users only pay the runtime cost of that extra computation if they've opted-in to use the feature (kinda like how you care so much about stdlib usage!). I think such an approach is essential to keeping RSpec fast even as we add and refine features.

I care too which is why it seems like we're being argumentative ;)

Maybe what I'm asking for isn't easily possible for a reason I'm not yet seeing. But I'd like to at least understand why if that's the case.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Theres no two way communication required as long as you're ok with:

config.profile_examples = true
config.profile_examples = false

Not actually removing the profiler or the profile formatter.

I'm 100% OK with this. In fact, I thought it was so obvious that I didn't think to mention it!

If the user toggles profile_examples from true to false, the correct user-facing behavior will still happen because we only notify the dump_profile event if the flag is set to true. They'll still be paying the run-time cost of the profile stuff being tracked in memory but not output, but that's not a big deal, IMO. The important things are that if profile_examples is set to true we produce the profile output and that if it is never set to true we don't waste time and resources loading and using the profiling logic.

@myronmarston
Copy link
Member

Thanks, @JonRowe, this is looking good.

module RSpec
module Core
# @private
class Profiler
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Given that this really only provides profiling for example groups (since each individual example profiles itself), do you think it should be called ExampleGroupProfiler? That would also help differentiate it from the ProfileFormatter.

On a side note, I think I'd prefer to see this in the formatters directory. No, it's not an object that formats output, but it gets registered as a formatter with the reporter and that's where we generally put those classes. Plus it's nice not to increase the file count in the already crowded rspec/core dir.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm strongly against polluting the formatters namespace with more things that are not formatters. The reporter is not in the formatters namespace ergo this isn't.

@JonRowe JonRowe force-pushed the refactor_issue_1878 branch 2 times, most recently from 554ea25 to 72a2b60 Compare June 2, 2015 02:02
@JonRowe
Copy link
Member Author

JonRowe commented Jun 2, 2015

I updated this some more, I'm not so convinced about the last commit but all the other stuff was good feedback :)

@myronmarston
Copy link
Member

LGTM. The build is failing due to rspec-expecations failures on 1.8.7, which I've attempted to address in rspec/rspec-expectations#798.

We can kick the build once that is merged but I think I'd rather just merge this w/o rebuilding since I referenced the failing build in the commit message of that other PR.

@JonRowe
Copy link
Member Author

JonRowe commented Jun 2, 2015

Turns out this needs a rebase anyway, and I've merged rspec/rspec-expectations#798 so lets give this us a go hey

@JonRowe JonRowe force-pushed the refactor_issue_1878 branch from 3441f20 to 2e59a6e Compare June 2, 2015 23:38
@JonRowe
Copy link
Member Author

JonRowe commented Jun 3, 2015

This is still failing on 1.8.7 when combined with rspec-expectations despite the merging of the other PR, want to take a look @myronmarston?

@myronmarston
Copy link
Member

This is still failing on 1.8.7 when combined with rspec-expectations despite the merging of the other PR, want to take a look @myronmarston?

Done: rspec/rspec-mocks#963.

JonRowe added a commit that referenced this pull request Jun 3, 2015
Refactor group profile to include before hooks
@JonRowe JonRowe merged commit d37db19 into master Jun 3, 2015
@JonRowe JonRowe deleted the refactor_issue_1878 branch June 3, 2015 12:18
JonRowe added a commit that referenced this pull request Jun 3, 2015
myronmarston added a commit that referenced this pull request Jun 12, 2015
Regressions fixed by this commit:

- We only considered top-level groups before, but #1971
  made it consider nested groups as well.  However, the
  example count was only incremented on the top-level
  group, which meant the output said “Inf seconds”
  since `float / 0` returns `Infinity`.
- We were wrongly listing the example group class name
  rather than the location. This is because we changed from
  locations to groups in the hash.

Fixes #1989.
@JonRowe JonRowe mentioned this pull request Jun 12, 2015
myronmarston added a commit that referenced this pull request Jun 12, 2015
Regressions fixed by this commit:

- We only considered top-level groups before, but #1971
  made it consider nested groups as well.  However, the
  example count was only incremented on the top-level
  group, which meant the output said “Inf seconds”
  since `float / 0` returns `Infinity`.
- We were wrongly listing the example group class name
  rather than the location. This is because we changed from
  locations to groups in the hash.

Fixes #1989.
MatheusRich pushed a commit to MatheusRich/rspec-core that referenced this pull request Oct 30, 2020
Refactor group profile to include before hooks
MatheusRich pushed a commit to MatheusRich/rspec-core that referenced this pull request Oct 30, 2020
MatheusRich pushed a commit to MatheusRich/rspec-core that referenced this pull request Oct 30, 2020
Regressions fixed by this commit:

- We only considered top-level groups before, but rspec#1971
  made it consider nested groups as well.  However, the
  example count was only incremented on the top-level
  group, which meant the output said “Inf seconds”
  since `float / 0` returns `Infinity`.
- We were wrongly listing the example group class name
  rather than the location. This is because we changed from
  locations to groups in the hash.

Fixes rspec#1989.
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

"Top N Slowest Example Group" from --profile does not account for time spent in before(:context) hooks
3 participants