Code Coverage
 
Lines
Functions and Methods
Classes and Traits
Total
95.35%
82 / 86
86.67%
13 / 15
 CRAP
0.00%
0 / 1
LoggingMiddleware
95.35%
82 / 86
86.67%
13 / 15
 31
0.00%
0 / 1
 __construct
100.00%
1 / 1
100.00%
1 / 1
 1
 setRedactedHeaders
100.00%
2 / 2
100.00%
1 / 1
 1
 getRedactedHeaders
100.00%
1 / 1
100.00%
1 / 1
 1
 addRedactedHeader
100.00%
2 / 2
100.00%
1 / 1
 1
 setIncludeBody
100.00%
2 / 2
100.00%
1 / 1
 1
 getIncludeBody
100.00%
1 / 1
100.00%
1 / 1
 1
 setMaxBodyLength
100.00%
2 / 2
100.00%
1 / 1
 1
 getMaxBodyLength
100.00%
1 / 1
100.00%
1 / 1
 1
 process
100.00%
16 / 16
100.00%
1 / 1
 2
 logRetriesTo
100.00%
12 / 12
100.00%
1 / 1
 2
 levelForStatus
100.00%
5 / 5
100.00%
1 / 1
 3
 buildContext
100.00%
15 / 15
100.00%
1 / 1
 4
 bodyForLog
92.31%
12 / 13
0.00%
0 / 1
 5.01
 redact
100.00%
5 / 5
100.00%
1 / 1
 3
 truncate
62.50%
5 / 8
0.00%
0 / 1
 4.84
1<?php
2declare(strict_types=1);
3/**
4 * Pop PHP Framework (https://www.popphp.org/)
5 *
6 * @link       https://github.com/popphp/popphp-framework
7 * @author     Nick Sagona, III <nick@popphp.org>
8 * @copyright  Copyright (c) 2009-2026 Nick Sagona, III
9 * @license    https://www.popphp.org/license     New BSD License
10 */
11
12/**
13 * @namespace
14 */
15namespace Pop\Http\Client\Middleware;
16
17use Pop\Http\Body;
18use Psr\Http\Message\RequestInterface;
19use Psr\Http\Message\ResponseInterface;
20use Psr\Http\Message\StreamInterface;
21use Psr\Log\LoggerInterface;
22use Psr\Log\LogLevel;
23
24/**
25 * PSR-3 logging middleware - logs one line per handler invocation (per
26 * dispatch attempt), with a level derived from the outcome (info for
27 * success, warning for 4xx, error for 5xx or a thrown exception), known-
28 * sensitive headers redacted by default, and request/response bodies
29 * excluded unless explicitly opted in. Exceptions are logged then
30 * re-thrown completely unmodified. No special coupling with
31 * RetryMiddleware - see logRetriesTo() for an optional adapter onto its
32 * existing onRetry hook.
33 *
34 * @category   Pop
35 * @package    Pop\Http
36 * @author     Nick Sagona, III <nick@popphp.org>
37 * @copyright  Copyright (c) 2009-2026 Nick Sagona, III
38 * @license    https://www.popphp.org/license     New BSD License
39 * @version    6.0.0
40 */
41class LoggingMiddleware implements MiddlewareInterface
42{
43
44    /**
45     * The PSR-3 logger to write to
46     * @var LoggerInterface
47     */
48    protected LoggerInterface $logger;
49
50    /**
51     * Header names redacted from the logged context (case-insensitive match)
52     * @var array
53     */
54    protected array $redactedHeaders = ['Authorization', 'Cookie', 'Set-Cookie', 'X-Api-Key', 'Proxy-Authorization'];
55
56    /**
57     * Whether to include (truncated) request/response body content in the log context
58     * @var bool
59     */
60    protected bool $includeBody = false;
61
62    /**
63     * Maximum body length included in the log context when includeBody is true
64     * @var int
65     */
66    protected int $maxBodyLength = 1000;
67
68    /**
69     * Constructor
70     *
71     * @param LoggerInterface $logger
72     */
73    public function __construct(LoggerInterface $logger)
74    {
75        $this->logger = $logger;
76    }
77
78    /**
79     * Set the redacted header list, replacing the defaults
80     *
81     * @param  array $headers
82     * @return LoggingMiddleware
83     */
84    public function setRedactedHeaders(array $headers): LoggingMiddleware
85    {
86        $this->redactedHeaders = $headers;
87        return $this;
88    }
89
90    /**
91     * Get the redacted header list
92     *
93     * @return array
94     */
95    public function getRedactedHeaders(): array
96    {
97        return $this->redactedHeaders;
98    }
99
100    /**
101     * Add a header name to the redacted list
102     *
103     * @param  string $header
104     * @return LoggingMiddleware
105     */
106    public function addRedactedHeader(string $header): LoggingMiddleware
107    {
108        $this->redactedHeaders[] = $header;
109        return $this;
110    }
111
112    /**
113     * Set whether to include (truncated) request/response body content in the log context
114     *
115     * @param  bool $include
116     * @return LoggingMiddleware
117     */
118    public function setIncludeBody(bool $include): LoggingMiddleware
119    {
120        $this->includeBody = $include;
121        return $this;
122    }
123
124    /**
125     * Get whether body content is included in the log context
126     *
127     * @return bool
128     */
129    public function getIncludeBody(): bool
130    {
131        return $this->includeBody;
132    }
133
134    /**
135     * Set the maximum body length included in the log context when includeBody is true
136     *
137     * @param  int $length
138     * @return LoggingMiddleware
139     */
140    public function setMaxBodyLength(int $length): LoggingMiddleware
141    {
142        $this->maxBodyLength = $length;
143        return $this;
144    }
145
146    /**
147     * Get the maximum body length included in the log context
148     *
149     * @return int
150     */
151    public function getMaxBodyLength(): int
152    {
153        return $this->maxBodyLength;
154    }
155
156    /**
157     * Process the request, logging one line for this invocation once the outcome is known
158     *
159     * @param  RequestInterface        $request
160     * @param  RequestHandlerInterface $handler
161     * @return ResponseInterface
162     */
163    public function process(RequestInterface $request, RequestHandlerInterface $handler): ResponseInterface
164    {
165        $start = microtime(true);
166
167        try {
168            $response = $handler->handle($request);
169        } catch (\Throwable $exception) {
170            $duration = microtime(true) - $start;
171            $this->logger->error(
172                'HTTP {method} {uri} -> exception: {exception_class}: {exception_message} ({duration}s)',
173                $this->buildContext($request, null, $exception, $duration)
174            );
175            throw $exception;
176        }
177
178        $duration = microtime(true) - $start;
179        $this->logger->log(
180            $this->levelForStatus($response->getStatusCode()),
181            'HTTP {method} {uri} -> {status} ({duration}s)',
182            $this->buildContext($request, $response, null, $duration)
183        );
184
185        return $response;
186    }
187
188    /**
189     * Adapt a PSR-3 logger into a callable matching RetryMiddleware::setOnRetry()'s
190     * signature, producing a structured "retrying" warning log per attempt with the
191     * failure reason (exception class+message, or response status) and computed delay
192     *
193     * @param  LoggerInterface $logger
194     * @return callable
195     */
196    public static function logRetriesTo(LoggerInterface $logger): callable
197    {
198        return function (int $attempt, RequestInterface $request, ?ResponseInterface $response, ?\Throwable $exception, float $delaySeconds) use ($logger): void {
199            $reason = ($exception !== null)
200                ? $exception::class . ': ' . $exception->getMessage()
201                : (string)$response?->getStatusCode();
202
203            $logger->warning('Retrying {method} {uri} - attempt {attempt}, delay {delay}s, reason: {reason}', [
204                'method'  => $request->getMethod(),
205                'uri'     => (string)$request->getUri(),
206                'attempt' => $attempt,
207                'delay'   => $delaySeconds,
208                'reason'  => $reason,
209            ]);
210        };
211    }
212
213    /**
214     * Determine the PSR-3 log level for a response status code
215     *
216     * @param  int $code
217     * @return string
218     */
219    protected function levelForStatus(int $code): string
220    {
221        if ($code >= 500) {
222            return LogLevel::ERROR;
223        }
224        if ($code >= 400) {
225            return LogLevel::WARNING;
226        }
227
228        return LogLevel::INFO;
229    }
230
231    /**
232     * Build the structured log context for a request/response/exception outcome
233     *
234     * @param  RequestInterface   $request
235     * @param  ?ResponseInterface $response
236     * @param  ?\Throwable        $exception
237     * @param  float              $duration
238     * @return array
239     */
240    protected function buildContext(RequestInterface $request, ?ResponseInterface $response, ?\Throwable $exception, float $duration): array
241    {
242        $context = [
243            'method'   => $request->getMethod(),
244            'uri'      => (string)$request->getUri(),
245            'duration' => round($duration, 4),
246            'headers'  => $this->redact($request->getHeaders()),
247        ];
248
249        if ($exception !== null) {
250            $context['exception_class']   = $exception::class;
251            $context['exception_message'] = $exception->getMessage();
252        } else {
253            $context['status'] = $response->getStatusCode();
254        }
255
256        if ($this->includeBody) {
257            $context['request_body'] = $this->bodyForLog($request->getBody());
258            if ($response !== null) {
259                $context['response_body'] = $this->bodyForLog($response->getBody());
260            }
261        }
262
263        return $context;
264    }
265
266    /**
267     * Build the (truncated) logged representation of a request/response body without
268     * materializing the whole underlying stream into memory - critical for large,
269     * file-backed bodies (e.g. multi-megabyte uploads), where only ~maxBodyLength bytes
270     * ever need to exist as a PHP string.
271     *
272     * For a Pop\Http\Body, reads at most maxBodyLength + 1 raw bytes directly off the
273     * underlying stream resource (bypassing render()'s encoding/chunk-split transforms,
274     * which are irrelevant - and potentially misleading - for a debug log), saving and
275     * restoring the stream's read position exactly as Body::getContent() does, so other
276     * consumers of the same Body object are unaffected. Non-seekable streams are skipped
277     * gracefully with a placeholder rather than letting a rewind()/fseek() PHP warning leak
278     * out of a logging call. Any other StreamInterface implementation falls back to the
279     * previous whole-body-then-truncate behavior, since there is no generic PSR-7 API for a
280     * position-preserving bounded read.
281     *
282     * @param  StreamInterface $body
283     * @return string
284     */
285    protected function bodyForLog(StreamInterface $body): string
286    {
287        if (!($body instanceof Body)) {
288            return $this->truncate((string)$body);
289        }
290
291        $stream = $body->getStream();
292        if ($stream === null) {
293            return '';
294        }
295
296        if (!$body->isSeekable()) {
297            return '[non-seekable stream, body omitted]';
298        }
299
300        $length   = max(0, $this->maxBodyLength);
301        $position = ftell($stream);
302        rewind($stream);
303        $content = fread($stream, $length + 1);
304        fseek($stream, $position);
305
306        return $this->truncate(($content === false) ? '' : $content);
307    }
308
309    /**
310     * Redact configured header names from a PSR-7 getHeaders()-shaped array
311     *
312     * @param  array $headers
313     * @return array
314     */
315    protected function redact(array $headers): array
316    {
317        $redactedNames = array_map('strtolower', $this->redactedHeaders);
318
319        foreach ($headers as $name => $values) {
320            if (in_array(strtolower($name), $redactedNames, true)) {
321                $headers[$name] = ['[REDACTED]'];
322            }
323        }
324
325        return $headers;
326    }
327
328    /**
329     * Truncate body content to the configured maximum length
330     *
331     * A negative maxBodyLength is clamped to 0 - mb_substr()/substr() treat a negative
332     * length as "omit N characters from the end," not "take N characters," so without
333     * clamping, a negative value would silently produce unbounded (merely trailing-trimmed)
334     * output that still looks truncated because of the appended '...'.
335     *
336     * Uses mb_strlen()/mb_substr() when available for multi-byte-safe truncation, falling
337     * back to byte-based strlen()/substr() otherwise - ext-mbstring is only suggested, not
338     * required, by this package, so an unconditional mb_* call would fatal on a build
339     * without it. The byte-based fallback can split a multi-byte character mid-sequence;
340     * that's an accepted, honest degradation rather than a fatal error.
341     *
342     * @param  string $content
343     * @return string
344     */
345    protected function truncate(string $content): string
346    {
347        $length = max(0, $this->maxBodyLength);
348
349        if (function_exists('mb_strlen')) {
350            return (mb_strlen($content) > $length)
351                ? mb_substr($content, 0, $length) . '...'
352                : $content;
353        }
354
355        return (strlen($content) > $length)
356            ? substr($content, 0, $length) . '...'
357            : $content;
358    }
359
360}