Added performance test for profilers

README.md

@@ -2,9 +2,9 @@
 
 This tool allows you to monitor performance and detect memory leaks as well as inconsistent performance behavior of your application over time.
 
-## Short-term profiling
+## Basic profiling
 
-For **short-term profiling** you can use a [profiling helper](./src/Profiling.php).
+For basic profiling you can use a profiling helper.
 The [`Profiling`](./src/Profiling.php) will allow you to profile between `start` and `finish` methods calls.
 
 ```php
@@ -17,20 +17,18 @@ $profile = $profiling->finish();
 printf('It took %.1f s to do something.', $profile->getDuration());
 ```
 
-The [`Profiling`](./src/Profiling.php) is simple - **cannot be turned on and off** easily.
-So a [profiler](./src/ProfilerInterface.php) was created for the purpose of hard-coded long-term profiling.
+The [`Profiling`](./src/Profiling.php) is simple and **cannot be turned on and off** easily.
+So a [profiler](./src/ProfilerInterface.php) was created for the purpose of hard-coded more complex profiling.
 
-## Long-term profiling
+## Complex profiling
 
 Request a [profiler](./src/ProfilerInterface.php) as a dependency and call a `profile` method on it.
 
 ```php
 namespace PetrKnap\Profiler;
 
 function doSomething(ProfilerInterface $profiler): string {
-    // do something without profiling
     return $profiler->profile(function (): string {
-        // do something
         return 'something';
     })->process(fn (ProfileInterface $profile) => printf(
         'It took %.1f s to do something.',
@@ -50,40 +48,62 @@ echo doSomething(new Profiler());
 echo doSomething(new NullProfiler());
 ```
 
-### Cascade profiling
+## Useful features
 
-The `profile` method provides you a nested [profiler](./src/ProfilerInterface.php) that you can use for more detailed cascade profiling.
+### Touching a profile
+
+If you need to **measure the current values**, just call the `touch` method on the [`Profiling`](./src/Profiling.php).
 
 ```php
 namespace PetrKnap\Profiler;
 
-echo (new Profiler())->profile(function (ProfilerInterface $profiler): string {
-    // do something before something
-    return doSomething($profiler);
-})->process(fn (ProfileInterface $profile) => printf(
-    'It took %.1f s to do something before something and something, there are %d children profiles.',
-    $profile->getDuration(),
-    count($profile->getChildren()),
-));
+$profiling = Profiling::start();
+// do something
+$profiling->touch();
+// do something more
+$profile = $profiling->finish();
+
+printf('There are %d memory usage records.', count($profile->getMemoryUsages()));
 ```
 
+If you want to automate it then use a [tick listening](#tick-listening).
+Or you can use a more practical [cascade profiling](#cascade-profiling).
+
 ### Tick listening
 
-For greater precision, you can use measurements at each `N` tick.
-This will result in **very detailed code tracking**, which can degrade the performance of the monitored application.
+For greater precision, you can use **measurements at each `N` tick**.
 
 ```php
-declare(ticks=3); // this declaration is important (N=3)
+declare(ticks=2); // this declaration is important (N=2)
 
 namespace PetrKnap\Profiler;
 
 $profiling = Profiling::start(listenToTicks: true);
-doSomething(new NullProfiler());
+(fn () => 'something')();
 $profile = $profiling->finish();
 
 printf('There are %d memory usage records.', count($profile->getMemoryUsages()));
 ```
 
+This will result in **very detailed code tracking**, which can degrade the performance of the monitored application.
+
+### Cascade profiling
+
+The `profile` method provides you a nested [profiler](./src/ProfilerInterface.php) that you can use for more detailed cascade profiling.
+
+```php
+namespace PetrKnap\Profiler;
+
+$profile = (new Profiler())->profile(function (ProfilerInterface $profiler): void {
+    // do something
+    $profiler->profile(function (): void {
+        // do something more
+    });
+});
+
+printf('There are %d memory usage records.', count($profile->getMemoryUsages()));
+```
+
 ---
 
 Run `composer require petrknap/profiler` to install it.

src/Exception/ProfilingHasBeenAlreadyFinished.php

@@ -7,7 +7,6 @@
 use LogicException;
 
 /**
- * @todo rename to `ProfilingCouldNotBeFinished`
  * @todo remove implementation of {@see ProfilerException}
  */
 final class ProfilingHasBeenAlreadyFinished extends LogicException implements ProfilerException, ProfilingException

src/Profiling.php

@@ -24,18 +24,26 @@ public static function start(
         return new self($profile, $listenToTicks);
     }
 
+    /**
+     * @throws Exception\ProfilingHasBeenAlreadyFinished
+     */
+    public function touch(): void
+    {
+        $this->checkProfileState();
+
+        $this->profile->tickHandler();
+    }
+
     /**
      * @throws Exception\ProfilingHasBeenAlreadyFinished
      */
     public function finish(): ProfileInterface
     {
-        try {
-            $this->profile->finish();
+        $this->checkProfileState();
 
-            return $this->profile;
-        } catch (Exception\ProfileException $profileException) {
-            throw new Exception\ProfilingHasBeenAlreadyFinished(previous: $profileException);
-        }
+        $this->profile->finish();
+
+        return $this->profile;
     }
 
     /**
@@ -74,4 +82,14 @@ public function profile(callable $callable): ProcessableProfileInterface & Profi
             }
         };
     }
+
+    /**
+     * @throws Exception\ProfilingHasBeenAlreadyFinished
+     */
+    private function checkProfileState(): void
+    {
+        if ($this->profile->getState() === ProfileState::Finished) {
+            throw new Exception\ProfilingHasBeenAlreadyFinished();
+        }
+    }
 }

tests/NullProfilerTest.php

@@ -4,16 +4,13 @@
 
 namespace PetrKnap\Profiler;
 
-use PHPUnit\Framework\TestCase;
-
-final class NullProfilerTest extends TestCase
+final class NullProfilerTest extends ProfilerTestCase
 {
     public function testCallsCallable(): void
     {
-        $profiler = new NullProfiler();
         $callableWasCalled = false;
 
-        $profiler->profile(static function () use (&$callableWasCalled): void {
+        self::getProfiler()->profile(static function () use (&$callableWasCalled): void {
             $callableWasCalled = true;
         });
 
@@ -22,23 +19,30 @@ public function testCallsCallable(): void
 
     public function testProfileReturnsCallablesOutput(): void
     {
-        $profiler = new NullProfiler();
-
-        $output = $profiler->profile(static fn (): string => 'output')->getOutput();
+        $output = self::getProfiler()->profile(static fn (): string => 'output')->getOutput();
 
         self::assertSame('output', $output);
     }
 
     public function testProfileDoesNotRunProcessorAndReturnsCallablesOutput(): void
     {
-        $profiler = new NullProfiler();
         $processorWasCalled = false;
 
-        $output = $profiler->profile(static fn (): string => 'output')->process(static function () use (&$processorWasCalled): void {
+        $output = self::getProfiler()->profile(static fn (): string => 'output')->process(static function () use (&$processorWasCalled): void {
             $processorWasCalled = true;
         });
 
         self::assertFalse($processorWasCalled);
         self::assertSame('output', $output);
     }
+
+    protected static function getProfiler(): ProfilerInterface
+    {
+        return new NullProfiler();
+    }
+
+    protected static function getAllowedTimePerProfile(): float
+    {
+        return 0.000000001;
+    }
 }

tests/ProfilerTest.php

@@ -4,16 +4,13 @@
 
 namespace PetrKnap\Profiler;
 
-use PHPUnit\Framework\TestCase;
-
-final class ProfilerTest extends TestCase
+final class ProfilerTest extends ProfilerTestCase
 {
     public function testCallsCallable(): void
     {
-        $profiler = new Profiler();
         $callableWasCalled = false;
 
-        $profiler->profile(static function () use (&$callableWasCalled) {
+        self::getProfiler()->profile(static function () use (&$callableWasCalled) {
             $callableWasCalled = true;
         });
 
@@ -22,19 +19,25 @@ public function testCallsCallable(): void
 
     public function testProfilesCallable(): void
     {
-        $profiler = new Profiler();
-
-        $profile = $profiler->profile(static fn ()  => sleep(1));
+        $profile = self::getProfiler()->profile(static fn ()  => sleep(1));
 
         self::assertEquals(1, round($profile->getDuration()));
     }
 
     public function testReturnsCallablesOutput(): void
     {
-        $profiler = new Profiler();
-
-        $profile = $profiler->profile(static fn ()  => 'output');
+        $profile = self::getProfiler()->profile(static fn ()  => 'output');
 
         self::assertSame('output', $profile->getOutput());
     }
+
+    protected static function getProfiler(): ProfilerInterface
+    {
+        return new Profiler();
+    }
+
+    protected static function getAllowedTimePerProfile(): float
+    {
+        return 0.005;
+    }
 }

tests/ProfilerTestCase.php

@@ -0,0 +1,35 @@
+<?php
+
+declare(strict_types=1);
+
+namespace PetrKnap\Profiler;
+
+use PHPUnit\Framework\TestCase;
+
+abstract class ProfilerTestCase extends TestCase
+{
+    public function testPerformanceIsOk(): void
+    {
+        $profileCounter = 1;
+        $callable = function (ProfilerInterface $profiler) use (&$callable, &$profileCounter) {
+            if ($profileCounter++ < 1000) {
+                $profiler->profile($callable);
+            }
+        };
+
+        $profile = static::getProfiler()->profile($callable);
+
+        self::assertSame(1001, $profileCounter);
+        self::assertLessThanOrEqual(
+            static::getAllowedTimePerProfile() * 1001,
+            $profile->getDuration(),
+        );
+    }
+
+    abstract protected static function getProfiler(): ProfilerInterface;
+
+    /**
+     * @return float seconds
+     */
+    abstract protected static function getAllowedTimePerProfile(): float;
+}

tests/ProfilingTest.php

@@ -17,7 +17,26 @@ public function testProfiles(): void
         self::assertEquals(1, round($profile->getDuration()));
     }
 
-    public function testThrowsOnSecondFinishCall(): void
+    public function testTouchesProfile(): void
+    {
+        $profiling = Profiling::start();
+        $profiling->touch();
+        $profile = $profiling->finish();
+
+        self::assertCount(2 + 1, $profile->getMemoryUsages());
+    }
+
+    public function testTouchThrowsOnFinishedProfile(): void
+    {
+        $profiling = Profiling::start();
+        $profiling->finish();
+
+        self::expectException(Exception\ProfilingHasBeenAlreadyFinished::class);
+
+        $profiling->touch();
+    }
+
+    public function testFinishThrowsOnFinishedProfile(): void
     {
         $profiling = Profiling::start();
         $profiling->finish();

tests/ReadmeTest.php

@@ -20,11 +20,12 @@ public static function getPathToMarkdownFile(): string
     public static function getExpectedOutputsOfPhpExamples(): iterable
     {
         return [
-            'short-term-profiling' => 'It took 0.0 s to do something.',
-            'long-term-profiling' => '',
+            'basic-profiling' => 'It took 0.0 s to do something.',
+            'complex-profiling' => '',
             'how-to-enable-disable-it' => 'It took 0.0 s to do something.' . 'something' . 'something',
-            'cascade-profiling' => 'It took 0.0 s to do something.' . 'It took 0.0 s to do something before something and something, there are 1 children profiles.' . 'something',
+            'touching-profile' => 'There are 3 memory usage records.',
             'tick-listening' => 'There are 3 memory usage records.',
+            'cascade-profiling' => 'There are 4 memory usage records.',
         ];
     }
 }