From 34416ba13914df72da050d632c00e607a9ea4181 Mon Sep 17 00:00:00 2001 From: ernolf Date: Sun, 19 Jul 2026 02:06:26 +0200 Subject: [PATCH] fix: clamp the log level and count rewound stream reads once - audit_http_client_loglevel values outside 0-2 no longer behave silently like "log everything"; they are clamped to the nearest valid level and the README documents it - CountingStream::__toString no longer double counts a seekable body that was partially read before; non-seekable streams keep additive counting - README: use a realistic 20-character server request ID in the plain-format example Signed-off-by: ernolf --- README.md | 4 ++-- lib/Http/Client/Middleware/CountingStream.php | 10 +++++++++- .../Client/Middleware/HttpClientLoggerMiddleware.php | 4 +++- .../Http/Client/Middleware/CountingStreamTest.php | 12 ++++++++++++ .../Middleware/HttpClientLoggerMiddlewareTest.php | 9 +++++++++ 5 files changed, 35 insertions(+), 4 deletions(-) diff --git a/README.md b/README.md index 3503ab1..deed63d 100644 --- a/README.md +++ b/README.md @@ -46,7 +46,7 @@ Controls which responses are logged. Default: `0`. | `1` | HTTP 400+ only | | `2` | HTTP 500+ only | -Network errors (connection failures, DNS failures, etc.) are always logged regardless of this setting. +Network errors (connection failures, DNS failures, etc.) are always logged regardless of this setting. Values outside the 0–2 range are clamped to the nearest valid level. ```php 'audit_http_client_loglevel' => 1, @@ -67,7 +67,7 @@ Every entry starts with the request ID: the ID of the server request that trigge Plain-text example: ``` -67527c3ff4b8-a3f9bc12 2026-05-05T14:23:01+00:00 GET https://example.com/feed HTTP/2 200 compressed=4821 decompressed=18944 ratio=0.25 encoding=br Hdrs=Host,Accept-Encoding,User-Agent "Nextcloud/32 ..." +gkAokgFCiaAKp30GwoTn-a3f9bc12 2026-05-05T14:23:01+00:00 GET https://example.com/feed HTTP/2 200 compressed=4821 decompressed=18944 ratio=0.25 encoding=br Hdrs=Host,Accept-Encoding,User-Agent "Nextcloud/32 ..." ``` ```php diff --git a/lib/Http/Client/Middleware/CountingStream.php b/lib/Http/Client/Middleware/CountingStream.php index dd1c100..1133f9c 100644 --- a/lib/Http/Client/Middleware/CountingStream.php +++ b/lib/Http/Client/Middleware/CountingStream.php @@ -65,8 +65,16 @@ public function getContents(): string { public function __toString(): string { try { + $seekable = $this->inner->isSeekable(); $contents = (string)$this->inner; - $this->bytesRead += strlen($contents); + if ($seekable) { + // A seekable stream rewinds for __toString, so the full body + // was delivered exactly once no matter how much was already + // read before — adding would double count. + $this->bytesRead = max($this->bytesRead, strlen($contents)); + } else { + $this->bytesRead += strlen($contents); + } return $contents; } catch (\Throwable) { return ''; diff --git a/lib/Http/Client/Middleware/HttpClientLoggerMiddleware.php b/lib/Http/Client/Middleware/HttpClientLoggerMiddleware.php index 114b186..b1cdc0d 100644 --- a/lib/Http/Client/Middleware/HttpClientLoggerMiddleware.php +++ b/lib/Http/Client/Middleware/HttpClientLoggerMiddleware.php @@ -80,7 +80,9 @@ public function __construct( ) { $this->logger = $logger; $this->logBaseDir = rtrim($logBaseDir, '/'); - $this->logLevel = $logLevel; + // Values outside the documented 0-2 range fall back to the nearest + // valid level instead of silently behaving like "log everything". + $this->logLevel = min(max($logLevel, 0), 2); $this->logFormat = $logFormat; $this->excludeDomains = $excludeDomains; $this->serverReqId = $serverReqId; diff --git a/tests/unit/Http/Client/Middleware/CountingStreamTest.php b/tests/unit/Http/Client/Middleware/CountingStreamTest.php index 1a5adcb..9e0e2c3 100644 --- a/tests/unit/Http/Client/Middleware/CountingStreamTest.php +++ b/tests/unit/Http/Client/Middleware/CountingStreamTest.php @@ -98,6 +98,18 @@ public function testDestructLogsIncompleteStream(): void { $this->assertStringContainsString('[stream-incomplete]', $plain); } + public function testToStringAfterPartialReadCountsBodyOnce(): void { + $reqId = uniqid('req', true); + $stream = $this->stream('hello world', $reqId); + + $this->assertSame('hello', $stream->read(5)); + $this->assertSame('hello world', (string)$stream); + $stream->close(); + + $entries = $this->readJsonLines(); + $this->assertSame(11, $entries[0]['compressionStats']['decompressed_bytes']); + } + public function testCloseTwiceWritesOnlyOneEntry(): void { $reqId = uniqid('req', true); $stream = $this->stream('abc', $reqId); diff --git a/tests/unit/Http/Client/Middleware/HttpClientLoggerMiddlewareTest.php b/tests/unit/Http/Client/Middleware/HttpClientLoggerMiddlewareTest.php index ce9019b..030b7fa 100644 --- a/tests/unit/Http/Client/Middleware/HttpClientLoggerMiddlewareTest.php +++ b/tests/unit/Http/Client/Middleware/HttpClientLoggerMiddlewareTest.php @@ -63,6 +63,15 @@ public function testShouldLogLevelOneLogsClientAndServerErrors(): void { $this->assertTrue($this->invokePrivate($mw, 'shouldLog', [500])); } + public function testShouldLogClampsOutOfRangeLevels(): void { + $tooHigh = $this->middleware(3); + $this->assertFalse($this->invokePrivate($tooHigh, 'shouldLog', [404])); + $this->assertTrue($this->invokePrivate($tooHigh, 'shouldLog', [500])); + + $tooLow = $this->middleware(-1); + $this->assertTrue($this->invokePrivate($tooLow, 'shouldLog', [200])); + } + public function testShouldLogLevelTwoLogsServerErrorsOnly(): void { $mw = $this->middleware(2); $this->assertFalse($this->invokePrivate($mw, 'shouldLog', [200]));