From 59da4b7fc102e9abdeda19ec2e0e6a4950b6cb57 Mon Sep 17 00:00:00 2001 From: Barney Laurance Date: Sun, 23 May 2021 16:23:23 +0100 Subject: [PATCH 1/5] Add test for basic output from one slow test --- .gitignore | 1 + tests/SpeedTrapListenerTest.php | 55 +++++++++++++++++++++++++++++++++ 2 files changed, 56 insertions(+) create mode 100644 tests/SpeedTrapListenerTest.php diff --git a/.gitignore b/.gitignore index 238a9c6..6ec2886 100644 --- a/.gitignore +++ b/.gitignore @@ -1,3 +1,4 @@ /phpunit.xml /vendor /composer.lock +/.phpunit.result.cache \ No newline at end of file diff --git a/tests/SpeedTrapListenerTest.php b/tests/SpeedTrapListenerTest.php new file mode 100644 index 0000000..d1c9153 --- /dev/null +++ b/tests/SpeedTrapListenerTest.php @@ -0,0 +1,55 @@ +speedTrapListener = new SpeedTrapListener([]); + } + + public function testItPrintsSpeedData(): void + { + $testSuite = new TestSuite(); + $this->speedTrapListener->startTestSuite($testSuite); + $this->speedTrapListener->startTest($this); + + $oneSecond = 1; + $this->speedTrapListener->endTest($this, $oneSecond); + + $output = $this->captureOutput(function () use ($testSuite) { + $this->speedTrapListener->endTestSuite($testSuite); + }); + + self::assertSame( + ' + +You should really speed up these slow tests (>500ms)... + 1. 1000ms to run JohnKary\\\\PHPUnit\\\\Listener\\\\Tests\\\\SpeedTrapListenerTest::testItPrintsSpeedData +' + , + $output + ); + } + + private function captureOutput(\Closure $closure): string + { + ob_start(); + $closure(); + return ob_get_clean(); + } +} \ No newline at end of file From cfdc51a1ad02453abdbee241cc5faa3280009f8d Mon Sep 17 00:00:00 2001 From: Barney Laurance Date: Sun, 23 May 2021 16:30:17 +0100 Subject: [PATCH 2/5] Add test for reporting on results from two tests --- tests/SpeedTrapListenerTest.php | 32 ++++++++++++++++++++++++++++++++ 1 file changed, 32 insertions(+) diff --git a/tests/SpeedTrapListenerTest.php b/tests/SpeedTrapListenerTest.php index d1c9153..b91b80a 100644 --- a/tests/SpeedTrapListenerTest.php +++ b/tests/SpeedTrapListenerTest.php @@ -46,6 +46,38 @@ public function testItPrintsSpeedData(): void ); } + + public function testItDisplaysTotalSlowTestTime(): void + { + $testSuite = new TestSuite(); + + $test1 = new self('test one'); + $test2 = new self('test two'); + + $this->speedTrapListener->startTestSuite($testSuite); + $this->speedTrapListener->startTest($test1); + $this->speedTrapListener->endTest($test1, 2 /* duration in seconds */); + + + $this->speedTrapListener->startTest($test2); + $this->speedTrapListener->endTest($test2, 1.5); + + $output = $this->captureOutput(function () use ($testSuite) { + $this->speedTrapListener->endTestSuite($testSuite); + }); + + self::assertSame( + ' + +You should really speed up these slow tests (>500ms)... + 1. 2000ms to run JohnKary\\\\PHPUnit\\\\Listener\\\\Tests\\\\SpeedTrapListenerTest::test one + 2. 1500ms to run JohnKary\\\\PHPUnit\\\\Listener\\\\Tests\\\\SpeedTrapListenerTest::test two +' + , + $output + ); + } + private function captureOutput(\Closure $closure): string { ob_start(); From fead3cd9707c710039ffbb16d7857fbe2219a655 Mon Sep 17 00:00:00 2001 From: Barney Laurance Date: Sun, 23 May 2021 17:04:53 +0100 Subject: [PATCH 3/5] Output stats on total of fast and slow tests --- src/SpeedTrapListener.php | 37 +++++++++++++++++++++++++++++++-- tests/SpeedTrapListenerTest.php | 7 ++++++- 2 files changed, 41 insertions(+), 3 deletions(-) diff --git a/src/SpeedTrapListener.php b/src/SpeedTrapListener.php index 310631e..b8410c7 100644 --- a/src/SpeedTrapListener.php +++ b/src/SpeedTrapListener.php @@ -63,6 +63,12 @@ class SpeedTrapListener implements TestListener */ protected $slow = []; + /** + * Total test execution time so far, in milliseconds + * @var int + */ + protected $totalTime = 0; + public function __construct(array $options = []) { $this->enabled = getenv('PHPUNIT_SPEEDTRAP') === 'disabled' ? false : true; @@ -87,6 +93,8 @@ public function endTest(Test $test, float $time): void if ($this->isSlow($timeInMilliseconds, $threshold)) { $this->addSlowTest($test, $timeInMilliseconds); } + + $this->totalTime += $timeInMilliseconds; } /** @@ -117,7 +125,8 @@ public function endTestSuite(TestSuite $suite): void $this->renderHeader(); $this->renderBody(); - $this->renderFooter(); + $this->renderAnyHiddenSlowTest(); + $this->renderStats(); } } @@ -225,7 +234,7 @@ protected function renderBody() /** * Renders slowness report footer. */ - protected function renderFooter() + protected function renderAnyHiddenSlowTest() { if ($hidden = $this->getHiddenCount()) { printf("...and there %s %s more above your threshold hidden from view\n", $hidden == 1 ? 'is' : 'are', $hidden); @@ -264,4 +273,28 @@ protected function getSlowThreshold(TestCase $test): int return isset($ann['method']['slowThreshold'][0]) ? (int) $ann['method']['slowThreshold'][0] : $this->slowThreshold; } + + private function renderStats(): void + { + + $totalSlowTimeMs = array_sum($this->slow); + $totalFastTimeMs = $this->totalTime - $totalSlowTimeMs; + + $totalFastTimeSeconds = $totalFastTimeMs / 1000; + $totalSlowTimeSeconds = $totalSlowTimeMs / 1000; + + echo PHP_EOL; + + printf( + " Fast tests: %.1f seconds (%.2f%%)\n", + $totalFastTimeSeconds, + 100 * $totalFastTimeMs / $this->totalTime + ); + + printf( + " Slow tests: %.1f seconds (%.2f%%)\n", + $totalSlowTimeSeconds, + 100 * $totalSlowTimeMs / $this->totalTime + ); + } } diff --git a/tests/SpeedTrapListenerTest.php b/tests/SpeedTrapListenerTest.php index b91b80a..b7d0820 100644 --- a/tests/SpeedTrapListenerTest.php +++ b/tests/SpeedTrapListenerTest.php @@ -8,7 +8,6 @@ use PHPUnit\Framework\TestCase; use PHPUnit\Framework\TestListener; use PHPUnit\Framework\TestSuite; -use PHPUnit\Util\Test; final class SpeedTrapListenerTest extends TestCase { @@ -40,6 +39,9 @@ public function testItPrintsSpeedData(): void You should really speed up these slow tests (>500ms)... 1. 1000ms to run JohnKary\\\\PHPUnit\\\\Listener\\\\Tests\\\\SpeedTrapListenerTest::testItPrintsSpeedData + + Fast tests: 0.0 seconds (0.00%) + Slow tests: 1.0 seconds (100.00%) ' , $output @@ -72,6 +74,9 @@ public function testItDisplaysTotalSlowTestTime(): void You should really speed up these slow tests (>500ms)... 1. 2000ms to run JohnKary\\\\PHPUnit\\\\Listener\\\\Tests\\\\SpeedTrapListenerTest::test one 2. 1500ms to run JohnKary\\\\PHPUnit\\\\Listener\\\\Tests\\\\SpeedTrapListenerTest::test two + + Fast tests: 0.0 seconds (0.00%) + Slow tests: 3.5 seconds (100.00%) ' , $output From adb29b418eb02eb18ca5bed64efe8ebc4e43b483 Mon Sep 17 00:00:00 2001 From: Barney Laurance Date: Sun, 23 May 2021 17:14:38 +0100 Subject: [PATCH 4/5] Add test for combination of slow and fast tests --- tests/SpeedTrapListenerTest.php | 50 +++++++++++++++++++++++++++++---- 1 file changed, 45 insertions(+), 5 deletions(-) diff --git a/tests/SpeedTrapListenerTest.php b/tests/SpeedTrapListenerTest.php index b7d0820..978fcd4 100644 --- a/tests/SpeedTrapListenerTest.php +++ b/tests/SpeedTrapListenerTest.php @@ -18,7 +18,7 @@ public function setUp(): void { parent::setUp(); - $this->speedTrapListener = new SpeedTrapListener([]); + $this->speedTrapListener = new SpeedTrapListener(['slowThreshold' => 500]); } public function testItPrintsSpeedData(): void @@ -27,8 +27,7 @@ public function testItPrintsSpeedData(): void $this->speedTrapListener->startTestSuite($testSuite); $this->speedTrapListener->startTest($this); - $oneSecond = 1; - $this->speedTrapListener->endTest($this, $oneSecond); + $this->speedTrapListener->endTest($this, 1 /*second*/); $output = $this->captureOutput(function () use ($testSuite) { $this->speedTrapListener->endTestSuite($testSuite); @@ -58,8 +57,7 @@ public function testItDisplaysTotalSlowTestTime(): void $this->speedTrapListener->startTestSuite($testSuite); $this->speedTrapListener->startTest($test1); - $this->speedTrapListener->endTest($test1, 2 /* duration in seconds */); - + $this->speedTrapListener->endTest($test1, 2); $this->speedTrapListener->startTest($test2); $this->speedTrapListener->endTest($test2, 1.5); @@ -83,6 +81,48 @@ public function testItDisplaysTotalSlowTestTime(): void ); } + public function testItDisplaysTotalSlowAndFastTestTime(): void + { + $testSuite = new TestSuite(); + + $test1 = new self('slow test one'); + $test2 = new self('slow test two'); + + $fastTest = new self('this one is fast'); + + $this->speedTrapListener->startTestSuite($testSuite); + $this->speedTrapListener->startTest($test1); + $this->speedTrapListener->endTest($test1, 2 /* duration in seconds */); + + + $this->speedTrapListener->startTest($test2); + $this->speedTrapListener->endTest($test2, 1.5); + + $this->speedTrapListener->startTest($fastTest); + $this->speedTrapListener->endTest($fastTest, 0.4); + + $output = $this->captureOutput(function () use ($testSuite) { + $this->speedTrapListener->endTestSuite($testSuite); + }); + + self::assertSame( + ' + +You should really speed up these slow tests (>500ms)... + 1. 2000ms to run JohnKary\\\\PHPUnit\\\\Listener\\\\Tests\\\\SpeedTrapListenerTest::slow test one + 2. 1500ms to run JohnKary\\\\PHPUnit\\\\Listener\\\\Tests\\\\SpeedTrapListenerTest::slow test two + + Fast tests: 0.4 seconds (10.26%) + Slow tests: 3.5 seconds (89.74%) +' + , + $output + ); + + self::assertEqualsWithDelta(10.26, 100*0.4/(0.4+3.5), 0.01); + self::assertEqualsWithDelta(89.74, 100*3.5/(0.4+3.5), 0.01); + } + private function captureOutput(\Closure $closure): string { ob_start(); From 5aded4e3235fbcc470bf8fb8ed0aa0b71cfc4a89 Mon Sep 17 00:00:00 2001 From: Barney Laurance Date: Sun, 23 May 2021 20:12:03 +0100 Subject: [PATCH 5/5] Use distinct speed threshold in test to avoid coincidence with default setting --- tests/SpeedTrapListenerTest.php | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/tests/SpeedTrapListenerTest.php b/tests/SpeedTrapListenerTest.php index 978fcd4..b1ce9c9 100644 --- a/tests/SpeedTrapListenerTest.php +++ b/tests/SpeedTrapListenerTest.php @@ -18,7 +18,7 @@ public function setUp(): void { parent::setUp(); - $this->speedTrapListener = new SpeedTrapListener(['slowThreshold' => 500]); + $this->speedTrapListener = new SpeedTrapListener(['slowThreshold' => 444]); } public function testItPrintsSpeedData(): void @@ -36,7 +36,7 @@ public function testItPrintsSpeedData(): void self::assertSame( ' -You should really speed up these slow tests (>500ms)... +You should really speed up these slow tests (>444ms)... 1. 1000ms to run JohnKary\\\\PHPUnit\\\\Listener\\\\Tests\\\\SpeedTrapListenerTest::testItPrintsSpeedData Fast tests: 0.0 seconds (0.00%) @@ -69,7 +69,7 @@ public function testItDisplaysTotalSlowTestTime(): void self::assertSame( ' -You should really speed up these slow tests (>500ms)... +You should really speed up these slow tests (>444ms)... 1. 2000ms to run JohnKary\\\\PHPUnit\\\\Listener\\\\Tests\\\\SpeedTrapListenerTest::test one 2. 1500ms to run JohnKary\\\\PHPUnit\\\\Listener\\\\Tests\\\\SpeedTrapListenerTest::test two @@ -108,7 +108,7 @@ public function testItDisplaysTotalSlowAndFastTestTime(): void self::assertSame( ' -You should really speed up these slow tests (>500ms)... +You should really speed up these slow tests (>444ms)... 1. 2000ms to run JohnKary\\\\PHPUnit\\\\Listener\\\\Tests\\\\SpeedTrapListenerTest::slow test one 2. 1500ms to run JohnKary\\\\PHPUnit\\\\Listener\\\\Tests\\\\SpeedTrapListenerTest::slow test two