Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
53 changes: 52 additions & 1 deletion README.md
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,8 @@
+ [Wiring the middleware](#wiring-the-middleware)
+ [Correlated logs](#correlated-logs)
+ [Customizing the clock](#customizing-the-clock)
+ [Ignoring paths](#ignoring-paths)
+ [Logging paths only on failure](#logging-paths-only-on-failure)
* [License](#license)
* [Contributing](#contributing)

Expand All @@ -16,7 +18,9 @@
Provides a PSR-15 middleware that records every inbound HTTP exchange. Before invoking the next handler, the
middleware logs the request method, URI, query parameters, and parsed body. After the handler runs, it logs the
response status code, decoded JSON body when present, and the elapsed duration in milliseconds. Successful
responses are logged at `info` level. Responses in the 4xx/5xx range are logged at `error` level.
responses are logged at `info` level. Responses in the 4xx/5xx range are logged at `error` level. Chosen paths can be
left out of the log entirely, or logged only when their response is an error, so health checks and routes called on
a schedule do not bury the entries that matter.

Duration is measured through a `TinyBlocks\Time\MonotonicClock` and a `Stopwatch`, so the reading is unaffected
by wall-clock adjustments. When the request carries a correlation identifier (under the `correlationId`
Expand Down Expand Up @@ -115,6 +119,53 @@ $middleware = LogMiddleware::create()
->build();
```

### Ignoring paths

Leaves the given paths out of the log entirely. Neither the `request` entry nor the `response` entry is written for
them, whatever the response status, which suits health checks that a load balancer or an orchestrator polls every few
seconds. Each path is compared by exact equality with the request URI path, so `/health` does not match
`/health/readiness`, and the query string plays no part in the comparison.

```php
<?php

declare(strict_types=1);

use TinyBlocks\Http\Logging\LogMiddleware;

# Requests to the health check paths never produce a log entry, whether they succeed or fail.
$middleware = LogMiddleware::create()
->withLogger(logger: $logger)
->withIgnoredPaths('/health/liveness', '/health/readiness')
->build();
```

### Logging paths only on failure

Logs the given paths only when their response is an error, meaning a status in the 4xx/5xx range. Any other response
produces no entry. An error response produces both the `request` entry and the `response` entry, with the same context
as on any other path, so the failure stays fully visible. This suits internal routes called on a schedule that almost
always succeed with nothing to report. Each path is compared by exact equality with the request URI path.

The outcome is known only once the handler returns, so on these paths the `request` entry is written after the handler
runs instead of before it. A handler that throws instead of returning a response leaves no entry on these paths. A
path that is also ignored is never logged.

```php
<?php

declare(strict_types=1);

use TinyBlocks\Http\Logging\LogMiddleware;

# Health checks are never logged, and the scheduled dispatch route is logged only when it fails.
$middleware = LogMiddleware::create()
->withLogger(logger: $logger)
->withIgnoredPaths('/health/readiness')
->withFailureOnlyPaths('/v1/outbox/dispatches')
->build();
```

## License

Http Logging is licensed under [MIT](LICENSE).
Expand Down
10 changes: 10 additions & 0 deletions phpstan.neon.dist
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,10 @@ parameters:
# log payload (decoded body) cannot be expressed there.
- identifier: missingType.iterableValue
path: src/Internal/LogResponse.php
# PHPDoc is prohibited inside src/Internal/; the path lookup keyed by path cannot
# carry its value type there.
- identifier: missingType.iterableValue
path: src/Internal/Paths.php
# The request context returned by LogRequest::toContext() is typed as `array`, so
# PHPStan cannot infer the shape consumed by the LogResponse factory.
- identifier: argument.type
Expand All @@ -21,4 +25,10 @@ parameters:
# value type, so PHPStan flags offset access on the assertions.
- identifier: offsetAccess.nonOffsetAccessible
path: tests/Unit/LogMiddlewareTest.php
# PHPDoc is prohibited inside tests/; the captured log entries and the data sets
# cannot carry a value type.
- identifier: missingType.iterableValue
paths:
- tests/Unit/CapturingLogger.php
- tests/Unit/LogMiddlewareTest.php
reportUnmatchedIgnoredErrors: true
51 changes: 51 additions & 0 deletions src/Internal/FailureOnlyLogExchange.php
Original file line number Diff line number Diff line change
@@ -0,0 +1,51 @@
<?php

declare(strict_types=1);

namespace TinyBlocks\Http\Logging\Internal;

use Psr\Http\Message\ResponseInterface;
use Psr\Http\Message\ServerRequestInterface;
use Psr\Log\LoggerInterface;
use TinyBlocks\Time\MonotonicClock;
use TinyBlocks\Time\Stopwatch;

final readonly class FailureOnlyLogExchange
{
private function __construct(
private LoggerInterface $logger,
private LogRequest $request,
private Stopwatch $stopwatch
) {
}

public static function start(
MonotonicClock $clock,
LoggerInterface $logger,
ServerRequestInterface $request
): FailureOnlyLogExchange {
return new FailureOnlyLogExchange(
logger: $logger,
request: LogRequest::from(request: $request),
stopwatch: Stopwatch::start(clock: $clock)
);
}

public function complete(ResponseInterface $response): ResponseInterface
{
$responseLog = LogResponse::from(
elapsed: $this->stopwatch->elapsed(),
request: $this->request,
response: $response
);

if (!$responseLog->isError()) {
return $response;
}

$this->request->writeTo(logger: $this->logger);
$responseLog->writeTo(logger: $this->logger);

return $response;
}
}
11 changes: 3 additions & 8 deletions src/Internal/LogExchange.php
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,7 @@ public static function start(
ServerRequestInterface $request
): LogExchange {
$requestLog = LogRequest::from(request: $request);
$logger->info('request', $requestLog->toContext());
$requestLog->writeTo(logger: $logger);

return new LogExchange(
logger: $logger,
Expand All @@ -36,16 +36,11 @@ public static function start(

public function complete(ResponseInterface $response): ResponseInterface
{
$responseLog = LogResponse::from(
LogResponse::from(
elapsed: $this->stopwatch->elapsed(),
request: $this->request,
response: $response
);

match ($responseLog->isError()) {
true => $this->logger->error('response', $responseLog->toContext()),
false => $this->logger->info('response', $responseLog->toContext())
};
)->writeTo(logger: $this->logger);

return $response;
}
Expand Down
6 changes: 6 additions & 0 deletions src/Internal/LogRequest.php
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
namespace TinyBlocks\Http\Logging\Internal;

use Psr\Http\Message\ServerRequestInterface;
use Psr\Log\LoggerInterface;
use TinyBlocks\Http\Server\Request;

final readonly class LogRequest
Expand All @@ -31,6 +32,11 @@ public static function from(ServerRequestInterface $request): LogRequest
);
}

public function writeTo(LoggerInterface $logger): void
{
$logger->info('request', $this->toContext());
}

public function toContext(): array
{
$context = [
Expand Down
11 changes: 10 additions & 1 deletion src/Internal/LogResponse.php
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
namespace TinyBlocks\Http\Logging\Internal;

use Psr\Http\Message\ResponseInterface;
use Psr\Log\LoggerInterface;
use TinyBlocks\Http\Code;
use TinyBlocks\Time\Elapsed;

Expand Down Expand Up @@ -38,7 +39,15 @@ public function isError(): bool
return Code::isErrorCode(code: $this->statusCode);
}

public function toContext(): array
public function writeTo(LoggerInterface $logger): void
{
match ($this->isError()) {
true => $logger->error('response', $this->toContext()),
false => $logger->info('response', $this->toContext())
};
}

private function toContext(): array
{
$context = [
'method' => $this->method,
Expand Down
22 changes: 22 additions & 0 deletions src/Internal/Paths.php
Original file line number Diff line number Diff line change
@@ -0,0 +1,22 @@
<?php

declare(strict_types=1);

namespace TinyBlocks\Http\Logging\Internal;

final readonly class Paths
{
private function __construct(private array $paths)
{
}

public static function from(string ...$paths): Paths
{
return new Paths(paths: array_flip($paths));
}

public function contains(string $path): bool
{
return isset($this->paths[$path]);
}
}
42 changes: 35 additions & 7 deletions src/LogMiddleware.php
Original file line number Diff line number Diff line change
Expand Up @@ -12,7 +12,9 @@
use TinyBlocks\Http\CorrelationId\CorrelatedLogger;
use TinyBlocks\Http\CorrelationId\CorrelationId;
use TinyBlocks\Http\CorrelationId\CorrelationIdMiddleware;
use TinyBlocks\Http\Logging\Internal\FailureOnlyLogExchange;
use TinyBlocks\Http\Logging\Internal\LogExchange;
use TinyBlocks\Http\Logging\Internal\Paths;
use TinyBlocks\Time\MonotonicClock;

/**
Expand All @@ -21,20 +23,38 @@
*/
final readonly class LogMiddleware implements MiddlewareInterface
{
private function __construct(private MonotonicClock $clock, private LoggerInterface $logger)
{
private function __construct(
private MonotonicClock $clock,
private LoggerInterface $logger,
private Paths $ignoredPaths,
private Paths $failureOnlyPaths
) {
}

/**
* Builds a LogMiddleware from a monotonic clock and a logger.
* Builds a LogMiddleware from a monotonic clock, a logger, and optional path filters.
*
* <p>Paths are compared by exact string equality with the request URI path. A path present in both lists is
* never logged.</p>
*
* @param MonotonicClock $clock The monotonic clock used to measure request duration.
* @param LoggerInterface $logger The logger to use for request and response logging.
* @param array<string> $ignoredPaths The request paths that are never logged.
* @param array<string> $failureOnlyPaths The request paths that are logged only when the response is an error.
* @return LogMiddleware The configured middleware instance.
*/
public static function build(MonotonicClock $clock, LoggerInterface $logger): LogMiddleware
{
return new LogMiddleware(clock: $clock, logger: $logger);
public static function build(
MonotonicClock $clock,
LoggerInterface $logger,
array $ignoredPaths = [],
array $failureOnlyPaths = []
): LogMiddleware {
return new LogMiddleware(
clock: $clock,
logger: $logger,
ignoredPaths: Paths::from(...$ignoredPaths),
failureOnlyPaths: Paths::from(...$failureOnlyPaths)
);
}

/**
Expand All @@ -49,12 +69,20 @@ public static function create(): LogMiddlewareBuilder

public function process(ServerRequestInterface $request, RequestHandlerInterface $handler): ResponseInterface
{
$path = $request->getUri()->getPath();

if ($this->ignoredPaths->contains(path: $path)) {
return $handler->handle($request);
}

$correlationId = $request->getAttribute(CorrelationIdMiddleware::ATTRIBUTE_NAME);
$logger = $correlationId instanceof CorrelationId
? CorrelatedLogger::from(logger: $this->logger, correlationId: $correlationId)
: $this->logger;

$exchange = LogExchange::start(clock: $this->clock, logger: $logger, request: $request);
$exchange = $this->failureOnlyPaths->contains(path: $path)
? FailureOnlyLogExchange::start(clock: $this->clock, logger: $logger, request: $request)
: LogExchange::start(clock: $this->clock, logger: $logger, request: $request);

$response = $handler->handle($request);

Expand Down
Loading
Loading