Skip to content

Commit 3d019fc

Browse files
BruntyBrunty
authored
Merge pull request #6 from asgrim/feature/step-threshold-support
Adds step_threshold configuration to identify lengthy steps
2 parents 956c43a + 04fc271 commit 3d019fc

11 files changed

+353
-38
lines changed

‎README.md

+13-4
Original file line numberDiff line numberDiff line change
@@ -20,22 +20,31 @@ default:
2020
Brunty\Behat\SpeedtrapExtension: ~
2121
```
2222
23-
To configure the threshold for slow scenarios (default 2000ms) specify the configuration option:
23+
To configure the threshold for slow scenarios (default 2000ms) specify the `scenario_threshold` configuration option:
2424

2525
```yaml
2626
default:
2727
extensions:
2828
Brunty\Behat\SpeedtrapExtension:
29-
threshold: 500 # this is in ms
29+
scenario_threshold: 500 # this is in ms
3030
```
3131

32-
To configure the number of scenarios reported (default 10) specify the configuration option:
32+
To configure the number of scenarios reported (default 10) specify the `report_length` configuration option:
3333

3434
```yaml
3535
default:
3636
extensions:
3737
Brunty\Behat\SpeedtrapExtension:
38-
report_length: 2
38+
report_length: 2
39+
```
40+
41+
Optionally you may also set `step_threshold` for individual steps to be reported. When the step threshold is `0`, the step threshold is ignored. The step threshold defaults to `0` (ignored):
42+
43+
```yaml
44+
default:
45+
extensions:
46+
Brunty\Behat\SpeedtrapExtension:
47+
step_threshold: 100 # this is in ms
3948
```
4049

4150
## Contributing

‎features/bootstrap/FeatureContext.php

+28-4
Original file line numberDiff line numberDiff line change
@@ -137,6 +137,8 @@ public function iShouldNotSee(PyStringNode $expected)
137137

138138
/**
139139
* @Then I should see:
140+
* @throws \Symfony\Component\Process\Exception\LogicException
141+
* @throws \RuntimeException
140142
*/
141143
public function iShouldSee(PyStringNode $expected)
142144
{
@@ -154,7 +156,12 @@ public function iShouldSee(PyStringNode $expected)
154156
}
155157
}
156158

157-
private function outputContains(string $expected)
159+
/**
160+
* @param string $expected
161+
* @return bool
162+
* @throws \Symfony\Component\Process\Exception\LogicException
163+
*/
164+
private function outputContains(string $expected): bool
158165
{
159166
$output = $this->normaliseOutput($this->process->getOutput());
160167
$expected = $this->normaliseOutput($expected);
@@ -163,7 +170,7 @@ private function outputContains(string $expected)
163170
return false;
164171
}
165172

166-
return strstr($output, $expected);
173+
return strpos($output, $expected) !== false;
167174
}
168175

169176
private function runBehat()
@@ -187,12 +194,29 @@ private function runBehat()
187194
}
188195

189196
/**
190-
* @param string
197+
* Normalise output to remove whitespace, ANSI colour escape codes, and replaces the actual time to run with the
198+
* string TIME to run for substitutions in scenarios.
191199
*
200+
* @example
201+
* - 2005ms to run features/feature.feature:2 - This scenario should be logged
202+
* becomes
203+
* - TIME to run features/feature.feature:2 - This scenario should be logged
204+
*
205+
* @param string
192206
* @return string
193207
*/
194208
private function normaliseOutput(string $output): string
195209
{
196-
return trim(preg_replace('/[0-9ms.]+ \([0-9.GkMb]+\)/', 'TIME', preg_replace('/\\s+/', ' ', $output)));
210+
return trim(
211+
preg_replace(
212+
'/\d+ms to run/',
213+
'TIME to run',
214+
preg_replace(
215+
'#\\x1b[[][^A-Za-z]*[A-Za-z]#',
216+
'',
217+
preg_replace('/\\s+/', ' ', $output)
218+
)
219+
)
220+
);
197221
}
198222
}

‎features/scenario_speedtrap.feature

+89-2
Original file line numberDiff line numberDiff line change
@@ -33,12 +33,14 @@ Feature: Slow scenarios are logged at the end of the test suite running
3333
default:
3434
extensions:
3535
Brunty\Behat\SpeedtrapExtension:
36-
threshold: 500
36+
scenario_threshold: 500
37+
step_threshold: 3000
3738
"""
3839
When I run behat
3940
Then I should see:
4041
"""
4142
The following scenarios were above your configured threshold: 500ms
43+
TIME to run features/feature.feature:2 - This scenario should be logged
4244
"""
4345

4446
Scenario: Scenarios below the threshold are not logged
@@ -53,10 +55,95 @@ Feature: Slow scenarios are logged at the end of the test suite running
5355
default:
5456
extensions:
5557
Brunty\Behat\SpeedtrapExtension:
56-
threshold: 500
58+
scenario_threshold: 500
59+
step_threshold: 3000
5760
"""
5861
When I run behat
5962
Then I should not see:
6063
"""
6164
The following scenarios were above your configured threshold: 500ms
6265
"""
66+
67+
Scenario: Steps below the threshold are logged
68+
Given I have the feature:
69+
"""
70+
Feature: Slow steps are logged
71+
Scenario: This scenario should be logged
72+
When I wait for 2 seconds
73+
"""
74+
And I have the configuration:
75+
"""
76+
default:
77+
extensions:
78+
Brunty\Behat\SpeedtrapExtension:
79+
scenario_threshold: 3000
80+
step_threshold: 500
81+
"""
82+
When I run behat
83+
Then I should see:
84+
"""
85+
The following steps were above your configured threshold: 500ms
86+
TIME to run step in features/feature.feature:3 - When I wait for 2 seconds
87+
"""
88+
89+
Scenario: Steps below the threshold are logged
90+
Given I have the feature:
91+
"""
92+
Feature: Slow steps are logged
93+
Scenario: This scenario should be logged
94+
When I wait for 0.1 seconds
95+
"""
96+
And I have the configuration:
97+
"""
98+
default:
99+
extensions:
100+
Brunty\Behat\SpeedtrapExtension:
101+
scenario_threshold: 3000
102+
step_threshold: 500
103+
"""
104+
When I run behat
105+
Then I should not see:
106+
"""
107+
The following steps were above your configured threshold: 500ms
108+
"""
109+
110+
Scenario: Setting a step threshold of zero does not output long steps
111+
Given I have the feature:
112+
"""
113+
Feature: Slow scenarios are logged
114+
Scenario: This scenario should be logged
115+
When I wait for 2 seconds
116+
"""
117+
And I have the configuration:
118+
"""
119+
default:
120+
extensions:
121+
Brunty\Behat\SpeedtrapExtension:
122+
scenario_threshold: 500
123+
step_threshold: 0
124+
"""
125+
When I run behat
126+
Then I should not see:
127+
"""
128+
The following steps were above your configured threshold
129+
"""
130+
131+
Scenario: Omitting the step threshold (i.e. using default value) does not output long steps
132+
Given I have the feature:
133+
"""
134+
Feature: Slow scenarios are logged
135+
Scenario: This scenario should be logged
136+
When I wait for 2 seconds
137+
"""
138+
And I have the configuration:
139+
"""
140+
default:
141+
extensions:
142+
Brunty\Behat\SpeedtrapExtension:
143+
scenario_threshold: 500
144+
"""
145+
When I run behat
146+
Then I should not see:
147+
"""
148+
The following steps were above your configured threshold
149+
"""

‎src/Listener/SpeedtrapListener.php

+80-11
Original file line numberDiff line numberDiff line change
@@ -3,11 +3,15 @@
33
namespace Brunty\Behat\SpeedtrapExtension\Listener;
44

55
use Behat\Behat\EventDispatcher\Event\AfterScenarioTested;
6+
use Behat\Behat\EventDispatcher\Event\AfterStepTested;
67
use Behat\Behat\EventDispatcher\Event\BeforeScenarioTested;
8+
use Behat\Behat\EventDispatcher\Event\BeforeStepTested;
79
use Behat\Behat\EventDispatcher\Event\ScenarioTested;
10+
use Behat\Behat\EventDispatcher\Event\StepTested;
811
use Behat\Testwork\EventDispatcher\Event\SuiteTested;
12+
use Brunty\Behat\SpeedtrapExtension\Logger\StepLogger;
913
use Brunty\Behat\SpeedtrapExtension\ServiceContainer\Config;
10-
use Brunty\Behat\SpeedtrapExtension\Logger\SpeedtrapLogger;
14+
use Brunty\Behat\SpeedtrapExtension\Logger\ScenarioLogger;
1115
use Symfony\Component\EventDispatcher\EventSubscriberInterface;
1216

1317
class SpeedtrapListener implements EventSubscriberInterface
@@ -18,18 +22,25 @@ class SpeedtrapListener implements EventSubscriberInterface
1822
private $config;
1923

2024
/**
21-
* @var SpeedtrapLogger
25+
* @var ScenarioLogger
2226
*/
23-
private $speedtrapLogger;
27+
private $scenarioLogger;
2428

2529
/**
26-
* @param Config $config
27-
* @param SpeedtrapLogger $speedtrapLogger
30+
* @var StepLogger
2831
*/
29-
public function __construct(Config $config, SpeedtrapLogger $speedtrapLogger)
32+
private $stepLogger;
33+
34+
/**
35+
* @param Config $config
36+
* @param ScenarioLogger $scenarioLogger
37+
* @param StepLogger $stepLogger
38+
*/
39+
public function __construct(Config $config, ScenarioLogger $scenarioLogger, StepLogger $stepLogger)
3040
{
3141
$this->config = $config;
32-
$this->speedtrapLogger = $speedtrapLogger;
42+
$this->scenarioLogger = $scenarioLogger;
43+
$this->stepLogger = $stepLogger;
3344
}
3445

3546
/**
@@ -38,26 +49,44 @@ public function __construct(Config $config, SpeedtrapLogger $speedtrapLogger)
3849
public static function getSubscribedEvents(): array
3950
{
4051
return [
52+
StepTested::BEFORE => 'stepStarted',
53+
StepTested::AFTER => 'stepFinished',
4154
ScenarioTested::BEFORE => 'scenarioStarted',
4255
ScenarioTested::AFTER => 'scenarioFinished',
4356
SuiteTested::AFTER => 'suiteFinished'
4457
];
4558
}
4659

60+
/**
61+
* @param BeforeStepTested $event
62+
*/
63+
public function stepStarted(BeforeStepTested $event)
64+
{
65+
$this->stepLogger->logStepStarted($this->getFormattedStepName($event));
66+
}
67+
68+
/**
69+
* @param AfterStepTested $event
70+
*/
71+
public function stepFinished(AfterStepTested $event)
72+
{
73+
$this->stepLogger->logStepFinished($this->getFormattedStepName($event));
74+
}
75+
4776
/**
4877
* @param BeforeScenarioTested $event
4978
*/
5079
public function scenarioStarted(BeforeScenarioTested $event)
5180
{
52-
$this->speedtrapLogger->logScenarioStarted($this->getFormattedScenarioName($event));
81+
$this->scenarioLogger->logScenarioStarted($this->getFormattedScenarioName($event));
5382
}
5483

5584
/**
5685
* @param AfterScenarioTested $event
5786
*/
5887
public function scenarioFinished(AfterScenarioTested $event)
5988
{
60-
$this->speedtrapLogger->logScenarioFinished($this->getFormattedScenarioName($event));
89+
$this->scenarioLogger->logScenarioFinished($this->getFormattedScenarioName($event));
6190
}
6291

6392
/**
@@ -66,14 +95,38 @@ public function scenarioFinished(AfterScenarioTested $event)
6695
*/
6796
public function suiteFinished()
6897
{
69-
$avgTimes = $this->speedtrapLogger->getScenariosAboveThreshold($this->config->getThreshold());
70-
$this->speedtrapLogger->clear();
98+
$this->outputScenarios();
99+
$this->outputSteps();
100+
}
101+
102+
/**
103+
* @return void
104+
* @throws \Exception
105+
*/
106+
private function outputScenarios()
107+
{
108+
$avgTimes = $this->scenarioLogger->getScenariosAboveThreshold($this->config->getScenarioThreshold());
109+
$this->scenarioLogger->clear();
71110

72111
foreach ($this->config->getOutputPrinters() as $printer) {
73112
$printer->printLogs($avgTimes);
74113
}
75114
}
76115

116+
/**
117+
* @return void
118+
* @throws \Exception
119+
*/
120+
private function outputSteps()
121+
{
122+
$avgTimes = $this->stepLogger->getStepsAboveThreshold($this->config->getStepThreshold());
123+
$this->stepLogger->clear();
124+
125+
foreach ($this->config->getStepOutputPrinters() as $printer) {
126+
$printer->printLogs($avgTimes);
127+
}
128+
}
129+
77130
/**
78131
* @param ScenarioTested $event
79132
*
@@ -83,4 +136,20 @@ private function getFormattedScenarioName(ScenarioTested $event)
83136
{
84137
return "{$event->getFeature()->getFile()}:{$event->getNode()->getLine()} - {$event->getScenario()->getTitle()}";
85138
}
139+
140+
/**
141+
* @param StepTested $event
142+
* @return string
143+
*/
144+
private function getFormattedStepName(StepTested $event): string
145+
{
146+
$step = $event->getStep();
147+
return sprintf(
148+
'%s:%s - %s %s',
149+
$event->getFeature()->getFile(),
150+
$event->getNode()->getLine(),
151+
$step->getKeyword(),
152+
$step->getText()
153+
);
154+
}
86155
}

‎src/Logger/SpeedtrapLogger.php renamed to ‎src/Logger/ScenarioLogger.php

+1-1
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22

33
namespace Brunty\Behat\SpeedtrapExtension\Logger;
44

5-
class SpeedtrapLogger implements \Countable
5+
class ScenarioLogger implements \Countable
66
{
77
private $scenarioTimes = [];
88

0 commit comments

Comments
 (0)