Skip to content

fix: redact handler stats URLs and report stream consumption honestly #21

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
ernolf merged 2 commits into from
Jul 19, 2026
Merged

fix: redact handler stats URLs and report stream consumption honestly #21

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
959e2b5
fix: redact credentials from logged handler stats URLs
ernolf Jul 19, 2026
5d9e51c
fix: derive stream consumption from EOF and report detached bodies as…
ernolf Jul 19, 2026
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
45 changes: 33 additions & 12 deletions lib/Http/Client/Middleware/CountingStream.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand All @@ -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();
}
Expand Down Expand Up @@ -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;
Expand All @@ -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);
}

Expand Down Expand Up @@ -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,
Expand All @@ -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);
Expand Down
17 changes: 16 additions & 1 deletion lib/Http/Client/Middleware/HttpClientLoggerMiddleware.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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()));
};
}

Expand Down Expand Up @@ -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) {
Expand Down
34 changes: 34 additions & 0 deletions tests/unit/Http/Client/Middleware/CountingStreamTest.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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);
Expand Down
59 changes: 59 additions & 0 deletions tests/unit/Http/Client/Middleware/HttpClientLoggerMiddlewareTest.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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);
Expand Down
Loading