From 959e2b534fffb834cf052619ac0b67c202c2e113 Mon Sep 17 00:00:00 2001 From: ernolf Date: Sun, 19 Jul 2026 10:41:42 +0200 Subject: [PATCH 1/2] fix: redact credentials from logged handler stats URLs Signed-off-by: ernolf --- .../Middleware/HttpClientLoggerMiddleware.php | 17 +++++- .../HttpClientLoggerMiddlewareTest.php | 59 +++++++++++++++++++ 2 files changed, 75 insertions(+), 1 deletion(-) diff --git a/lib/Http/Client/Middleware/HttpClientLoggerMiddleware.php b/lib/Http/Client/Middleware/HttpClientLoggerMiddleware.php index c46e785..074c6ab 100644 --- a/lib/Http/Client/Middleware/HttpClientLoggerMiddleware.php +++ b/lib/Http/Client/Middleware/HttpClientLoggerMiddleware.php @@ -148,7 +148,7 @@ public function __invoke(callable $handler): callable { // Attach on_stats callback to capture cURL transfer stats if (!isset($options[RequestOptions::ON_STATS])) { $options[RequestOptions::ON_STATS] = function (TransferStats $stats) use ($reqId): void { - TransferStatsStore::set($reqId, $stats->getHandlerStats()); + TransferStatsStore::set($reqId, $this->redactHandlerStats($stats->getHandlerStats())); }; } @@ -445,6 +445,21 @@ private function redactUri(string $uri): string { return $base . '?' . implode('&', $pairs) . $fragment; } + /** + * curl's transfer stats repeat the request URI: "url" holds the effective + * URI after redirects, "redirect_url" a pending redirect target. Logged + * verbatim they would bypass redactUri(), so both are redacted before the + * stats reach the store. + */ + private function redactHandlerStats(array $handlerStats): array { + foreach (['url', 'redirect_url'] as $key) { + if (isset($handlerStats[$key]) && is_string($handlerStats[$key]) && $handlerStats[$key] !== '') { + $handlerStats[$key] = $this->redactUri($handlerStats[$key]); + } + } + return $handlerStats; + } + private function normalizeHeaders(array $hdrs): array { $out = []; foreach ($hdrs as $k => $v) { diff --git a/tests/unit/Http/Client/Middleware/HttpClientLoggerMiddlewareTest.php b/tests/unit/Http/Client/Middleware/HttpClientLoggerMiddlewareTest.php index 2667b6f..ac87113 100644 --- a/tests/unit/Http/Client/Middleware/HttpClientLoggerMiddlewareTest.php +++ b/tests/unit/Http/Client/Middleware/HttpClientLoggerMiddlewareTest.php @@ -336,6 +336,65 @@ public function testRedactUriWithoutQueryIsUnchanged(): void { ); } + public function testRedactHandlerStatsRedactsUrlAndRedirectUrl(): void { + $mw = $this->middleware(); + $this->assertSame( + [ + 'url' => 'https://calendar.google.com/calendar/ical/user%40googlemail.com/private-***REMOVED SENSITIVE VALUE***/basic.ics', + 'redirect_url' => 'https://x.test/cb?token=***REMOVED SENSITIVE VALUE***', + 'http_code' => 200, + ], + $this->invokePrivate($mw, 'redactHandlerStats', [[ + 'url' => 'https://calendar.google.com/calendar/ical/user%40googlemail.com/private-0123456789abcdef0123456789abcdef/basic.ics', + 'redirect_url' => 'https://x.test/cb?token=geheim', + 'http_code' => 200, + ]]), + ); + } + + public function testRedactHandlerStatsLeavesEmptyRedirectUrl(): void { + $mw = $this->middleware(); + $this->assertSame( + ['url' => 'https://x.test/plain', 'redirect_url' => ''], + $this->invokePrivate($mw, 'redactHandlerStats', [ + ['url' => 'https://x.test/plain', 'redirect_url' => ''], + ]), + ); + } + + public function testLoggedHandlerStatsUrlIsRedacted(): void { + $dir = sys_get_temp_dir() . '/aahc-hs-' . bin2hex(random_bytes(4)); + $mw = new HttpClientLoggerMiddleware(new NullLogger(), $dir); + + $handler = $mw(function (Request $request, array $options) { + $response = new Response(204); + $options[RequestOptions::ON_STATS]( + new TransferStats($request, $response, 0.1, null, [ + 'url' => (string)$request->getUri(), + 'http_code' => 204, + ]), + ); + return new FulfilledPromise($response); + }); + + try { + $handler(new Request('GET', 'https://example.com/hook?token=geheim'), [])->wait(); + + $lines = file($dir . '/example.com.json', FILE_IGNORE_NEW_LINES | FILE_SKIP_EMPTY_LINES); + $this->assertNotFalse($lines); + $entry = json_decode($lines[0], true, 512, JSON_THROW_ON_ERROR); + $this->assertSame( + 'https://example.com/hook?token=***REMOVED SENSITIVE VALUE***', + $entry['handlerStats']['url'], + ); + } finally { + foreach (glob($dir . '/*') ?: [] as $file) { + @unlink($file); + } + @rmdir($dir); + } + } + public function testLoggedUriIsRedacted(): void { $dir = sys_get_temp_dir() . '/aahc-uri-' . bin2hex(random_bytes(4)); $mw = new HttpClientLoggerMiddleware(new NullLogger(), $dir); From 5d9e51ca87e0d6676fb9784389c8ab4bc7fcb73c Mon Sep 17 00:00:00 2001 From: ernolf Date: Sun, 19 Jul 2026 10:42:06 +0200 Subject: [PATCH 2/2] fix: derive stream consumption from EOF and report detached bodies as unknown Signed-off-by: ernolf --- lib/Http/Client/Middleware/CountingStream.php | 45 ++++++++++++++----- .../Client/Middleware/CountingStreamTest.php | 34 ++++++++++++++ 2 files changed, 67 insertions(+), 12 deletions(-) diff --git a/lib/Http/Client/Middleware/CountingStream.php b/lib/Http/Client/Middleware/CountingStream.php index 716e204..4169056 100644 --- a/lib/Http/Client/Middleware/CountingStream.php +++ b/lib/Http/Client/Middleware/CountingStream.php @@ -14,12 +14,14 @@ /** * Wraps a response body stream to count decompressed bytes and write the log - * entry once the body has been fully consumed (close) or garbage collected - * (__destruct fallback for streams that are never explicitly closed). + * entry once the stream is closed, detached or garbage collected. Consumption + * is derived from the read position; a detached body is consumed outside this + * wrapper, so its byte count and consumption state are reported as unknown. */ final class CountingStream implements StreamInterface { private int $bytesRead = 0; private bool $logged = false; + private bool $detached = false; public function __construct( private StreamInterface $inner, @@ -33,20 +35,21 @@ public function __construct( public function __destruct() { if (!$this->logged) { - $this->writeLog(false); + $this->writeLog(); } } public function close(): void { if (!$this->logged) { - $this->writeLog(true); + $this->writeLog(); } $this->inner->close(); } public function detach(): mixed { + $this->detached = true; if (!$this->logged) { - $this->writeLog(false); + $this->writeLog(); } return $this->inner->detach(); } @@ -121,9 +124,22 @@ public function getMetadata(?string $key = null): mixed { return $this->inner->getMetadata($key); } - private function writeLog(bool $complete): void { + private function writeLog(): void { $this->logged = true; try { + // Callers almost never close() the stream themselves, so + // consumption is derived from the read position instead of the + // close/destruct distinction. A detached body is handed to the + // caller as a raw resource and read outside this wrapper. + $consumed = false; + if (!$this->detached) { + try { + $consumed = $this->inner->eof(); + } catch (\Throwable) { + // Stream already closed or invalid; treat as not consumed. + } + } + $handlerStats = TransferStatsStore::get($this->reqId); $compressed = null; @@ -142,8 +158,8 @@ private function writeLog(bool $complete): void { } } - $decompressed = $this->bytesRead; - if ($compressed !== null && $decompressed > 0) { + $decompressed = $this->detached ? null : $this->bytesRead; + if ($compressed !== null && $decompressed !== null && $decompressed > 0) { $ratio = round($compressed / $decompressed, 2); } @@ -180,10 +196,15 @@ private function writeLog(bool $complete): void { 'decompressed_bytes' => $decompressed, 'ratio' => $ratio, ], - 'stream_consumed' => $complete, + 'stream_consumed' => $this->detached ? null : $consumed, ]; - $incomplete = $complete ? '' : ' [stream-incomplete]'; + $suffix = ''; + if ($this->detached) { + $suffix = ' [stream-detached]'; + } elseif (!$consumed) { + $suffix = ' [stream-incomplete]'; + } $plain = sprintf( "%s %s %s %s %s %s compressed=%s decompressed=%s ratio=%s encoding=%s Hdrs=%s \"%s\"%s\n", $this->reqId, @@ -193,12 +214,12 @@ private function writeLog(bool $complete): void { $this->meta['http'] ?? '-', $this->meta['status'] ?? '-', $compressed ?? '-', - $decompressed, + $decompressed ?? '-', $ratio ?? '-', $encoding, $headerNames, $userAgent, - $incomplete + $suffix ); [$jsonFile, $plainFile] = LogPathHelper::getPathsFromMeta($this->meta, $this->logBaseDir, $this->reqId); diff --git a/tests/unit/Http/Client/Middleware/CountingStreamTest.php b/tests/unit/Http/Client/Middleware/CountingStreamTest.php index 9e0e2c3..344ffd0 100644 --- a/tests/unit/Http/Client/Middleware/CountingStreamTest.php +++ b/tests/unit/Http/Client/Middleware/CountingStreamTest.php @@ -98,6 +98,40 @@ public function testDestructLogsIncompleteStream(): void { $this->assertStringContainsString('[stream-incomplete]', $plain); } + public function testDestructAfterFullReadReportsStreamConsumed(): void { + $reqId = uniqid('req', true); + $stream = $this->stream('hello world', $reqId); + + $this->assertSame('hello world', $stream->getContents()); + unset($stream); + + $entries = $this->readJsonLines(); + $this->assertCount(1, $entries); + $this->assertTrue($entries[0]['stream_consumed']); + + $plain = file_get_contents($this->baseDir . '/example.com.log'); + $this->assertNotFalse($plain); + $this->assertStringNotContainsString('[stream-incomplete]', $plain); + } + + public function testDetachReportsConsumptionAsUnknown(): void { + $reqId = uniqid('req', true); + $stream = $this->stream('hello world', $reqId); + + $resource = $stream->detach(); + $this->assertIsResource($resource); + + $entries = $this->readJsonLines(); + $this->assertCount(1, $entries); + $this->assertNull($entries[0]['compressionStats']['decompressed_bytes']); + $this->assertNull($entries[0]['compressionStats']['ratio']); + $this->assertNull($entries[0]['stream_consumed']); + + $plain = file_get_contents($this->baseDir . '/example.com.log'); + $this->assertNotFalse($plain); + $this->assertStringContainsString('[stream-detached]', $plain); + } + public function testToStringAfterPartialReadCountsBodyOnce(): void { $reqId = uniqid('req', true); $stream = $this->stream('hello world', $reqId);