Skip to content

Commit

Permalink
feat: implemented support for adding snapshot to a profile
Browse files Browse the repository at this point in the history
  • Loading branch information
petrknap committed Oct 19, 2024
1 parent 8e845bd commit 677d045
Show file tree
Hide file tree
Showing 5 changed files with 89 additions and 32 deletions.
62 changes: 41 additions & 21 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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.',
Expand All @@ -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.
### Adding snapshot to a profile

If you need to **measure the current values**, just call the `snapshot` 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->snapshot();
// 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.
Expand Down
1 change: 0 additions & 1 deletion src/Exception/ProfilingHasBeenAlreadyFinished.php
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,6 @@
use LogicException;

/**
* @todo rename to `ProfilingCouldNotBeFinished`
* @todo remove implementation of {@see ProfilerException}
*/
final class ProfilingHasBeenAlreadyFinished extends LogicException implements ProfilerException, ProfilingException
Expand Down
30 changes: 24 additions & 6 deletions src/Profiling.php
Original file line number Diff line number Diff line change
Expand Up @@ -24,18 +24,26 @@ public static function start(
return new self($profile, $listenToTicks);
}

/**
* @throws Exception\ProfilingHasBeenAlreadyFinished
*/
public function snapshot(): 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;
}

/**
Expand Down Expand Up @@ -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();
}
}
}
21 changes: 20 additions & 1 deletion tests/ProfilingTest.php
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,26 @@ public function testProfiles(): void
self::assertEquals(1, round($profile->getDuration()));
}

public function testThrowsOnSecondFinishCall(): void
public function testAddsSnapshotToProfile(): void
{
$profiling = Profiling::start();
$profiling->snapshot();
$profile = $profiling->finish();

self::assertCount(2 + 1, $profile->getMemoryUsages());
}

public function testSnapshotThrowsOnFinishedProfile(): void
{
$profiling = Profiling::start();
$profiling->finish();

self::expectException(Exception\ProfilingHasBeenAlreadyFinished::class);

$profiling->snapshot();
}

public function testFinishThrowsOnFinishedProfile(): void
{
$profiling = Profiling::start();
$profiling->finish();
Expand Down
7 changes: 4 additions & 3 deletions tests/ReadmeTest.php
Original file line number Diff line number Diff line change
Expand Up @@ -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.',
];
}
}

0 comments on commit 677d045

Please sign in to comment.