From 60529bd59c9445f83687f35af46ec929bf45f612 Mon Sep 17 00:00:00 2001 From: Yun Wang Date: Wed, 22 Jul 2026 15:53:12 +0200 Subject: [PATCH 1/4] feat: add psr-3 structured logging with secret redaction --- CHANGELOG.md | 10 ++ README.md | 34 +++++ composer.json | 1 + composer.lock | 52 +++++++- phpunit.xml | 3 - src/ClientBuilder.php | 78 +++++++++--- src/Http/GuzzleHttpClient.php | 131 ++++++++++++++++++-- src/Http/LogRedaction.php | 53 ++++++++ tests/ClientBuilderTest.php | 74 +++++++++++ tests/Http/LoggingTest.php | 122 ++++++++++++++++++ tests/Integration/ConnectionPoolLogTest.php | 105 ++++++++-------- 11 files changed, 574 insertions(+), 89 deletions(-) create mode 100644 src/Http/LogRedaction.php create mode 100644 tests/Http/LoggingTest.php diff --git a/CHANGELOG.md b/CHANGELOG.md index b5d03aa2..153af69a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,16 @@ All notable changes to this project will be documented in this file. The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/), and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html). +## [Unreleased] + +### Added + +- Structured logging via [PSR-3](https://www.php-fig.org/psr/psr-3/): `ClientBuilder::logger()` injects any `Psr\Log\LoggerInterface`; no logger is used by default. Emits `client.initialized` (INFO, once), `http.request.sent` / `http.response.received` (DEBUG, per attempt), and `http.request.failed` (ERROR, transport failures only). Query and JSON-body secrets (`api_key`, `api_secret`, `token`, `password`) are always redacted. Request/response bodies are excluded by default; opt in with `ClientBuilder::logBodies(true)`. + +### Changed + +- **Behavior change:** the connection-pool configuration is no longer written to PHP's `error_log()` at client construction. That information is now available only through an injected PSR-3 logger, as the `client.initialized` event. If you relied on the old `error_log` line, inject a logger via `->logger(...)` instead. + ## [9.0.0] - 2026-07-15 OpenAPI regeneration for optional query parameters ([FEEDS-1651](https://linear.app/stream/issue/FEEDS-1651), [#54](https://github.com/GetStream/getstream-php/pull/54)). diff --git a/README.md b/README.md index 4a585d72..5dfa0761 100644 --- a/README.md +++ b/README.md @@ -57,6 +57,40 @@ Per-call `curl` overrides replace (do not merge with) the client-level `curl` op **Escape hatch:** Passing your own client via `->httpClient($mine)` skips all 4 knobs; your client is used as-is. +## Logging + +The SDK emits structured events through a [PSR-3](https://www.php-fig.org/psr/psr-3/) `Psr\Log\LoggerInterface`. No logger is injected by default (`Psr\Log\NullLogger`, a no-op); pass your own via `->logger(...)`: + +```php +$client = (new GetStream\ClientBuilder()) + ->apiKey($apiKey) + ->apiSecret($apiSecret) + ->logger($myPsr3Logger) + ->build(); +``` + +Events emitted: + +| Event | Level | When | +|---|---|---| +| `client.initialized` | INFO | Once, at construction | +| `http.request.sent` | DEBUG | Before each HTTP attempt | +| `http.response.received` | DEBUG | After any HTTP response, including 4xx/5xx (status codes are data, not a failure) | +| `http.request.failed` | ERROR | Transport failure only (connection reset, timeout, DNS failure, TLS handshake failure) — no HTTP response was received | + +The SDK never sets the logger's minimum level; that's the caller's responsibility. + +**Bodies are not logged by default.** Enable with `->logBodies(true)`; this emits one WARN at construction and adds (key-redacted) `http.request.body` / `http.response.body` fields to the DEBUG events. Query values for `api_key`, `api_secret`, `token` and top-level JSON body keys `api_secret`, `token`, `password` are always redacted (case-insensitive for query values), whether or not body logging is on. No headers are ever logged. + +```php +$client = (new GetStream\ClientBuilder()) + ->apiKey($apiKey) + ->apiSecret($apiSecret) + ->logger($myPsr3Logger) + ->logBodies(true) + ->build(); +``` + ## Code Generation Generate API methods from OpenAPI spec: diff --git a/composer.json b/composer.json index a5be582c..992a3dd6 100644 --- a/composer.json +++ b/composer.json @@ -16,6 +16,7 @@ "ext-json": "*", "firebase/php-jwt": "^7.0", "guzzlehttp/guzzle": "^7.0", + "psr/log": "^3.0", "vlucas/phpdotenv": "^5.0" }, "require-dev": { diff --git a/composer.lock b/composer.lock index 836c4d4c..45326a5e 100644 --- a/composer.lock +++ b/composer.lock @@ -4,7 +4,7 @@ "Read more about it at https://getcomposer.org/doc/01-basic-usage.md#installing-dependencies", "This file is @generated automatically" ], - "content-hash": "191564aa94ee40f4d652a4951de2e3db", + "content-hash": "159185f0345e18ed9c19003d87c1617e", "packages": [ { "name": "firebase/php-jwt", @@ -691,6 +691,56 @@ }, "time": "2023-04-04T09:54:51+00:00" }, + { + "name": "psr/log", + "version": "3.0.2", + "source": { + "type": "git", + "url": "https://github.com/php-fig/log.git", + "reference": "f16e1d5863e37f8d8c2a01719f5b34baa2b714d3" + }, + "dist": { + "type": "zip", + "url": "https://api.github.com/repos/php-fig/log/zipball/f16e1d5863e37f8d8c2a01719f5b34baa2b714d3", + "reference": "f16e1d5863e37f8d8c2a01719f5b34baa2b714d3", + "shasum": "" + }, + "require": { + "php": ">=8.0.0" + }, + "type": "library", + "extra": { + "branch-alias": { + "dev-master": "3.x-dev" + } + }, + "autoload": { + "psr-4": { + "Psr\\Log\\": "src" + } + }, + "notification-url": "https://packagist.org/downloads/", + "license": [ + "MIT" + ], + "authors": [ + { + "name": "PHP-FIG", + "homepage": "https://www.php-fig.org/" + } + ], + "description": "Common interface for logging libraries", + "homepage": "https://github.com/php-fig/log", + "keywords": [ + "log", + "psr", + "psr-3" + ], + "support": { + "source": "https://github.com/php-fig/log/tree/3.0.2" + }, + "time": "2024-09-11T13:17:53+00:00" + }, { "name": "ralouphie/getallheaders", "version": "3.0.3", diff --git a/phpunit.xml b/phpunit.xml index 27149625..a4496a2b 100644 --- a/phpunit.xml +++ b/phpunit.xml @@ -17,8 +17,5 @@ src - - - diff --git a/src/ClientBuilder.php b/src/ClientBuilder.php index 647fbe73..e447688d 100644 --- a/src/ClientBuilder.php +++ b/src/ClientBuilder.php @@ -9,6 +9,8 @@ use GetStream\Http\GuzzleHttpClient; use GetStream\Http\HttpClientInterface; use GetStream\Http\PoolConfig; +use Psr\Log\LoggerInterface; +use Psr\Log\NullLogger; /** * Builder class for creating GetStream clients with environment variable support. @@ -22,6 +24,8 @@ class ClientBuilder private bool $loadEnv = true; private ?string $envPath = null; private PoolConfig $pool; + private ?LoggerInterface $logger = null; + private bool $logBodies = false; public function __construct() { @@ -112,6 +116,30 @@ public function requestTimeout(int $seconds): self return $this; } + /** + * Inject a PSR-3 logger for structured `client.initialized` / `http.request.*` / + * `http.response.*` events. Default when none is set: `Psr\Log\NullLogger` (no-op). + * The SDK never sets the logger's level; that is the caller's responsibility. + */ + public function logger(LoggerInterface $logger): self + { + $this->logger = $logger; + + return $this; + } + + /** + * Include (key-redacted) request/response bodies in the `http.request.sent` / + * `http.response.received` log events. Off by default. Enabling this emits one + * WARN at construction time. + */ + public function logBodies(bool $on): self + { + $this->logBodies = $on; + + return $this; + } + /** * Disable loading from environment variables. */ @@ -265,41 +293,51 @@ private function getEnvVar(string $name): ?string /** * Resolve the HttpClient. * If the user supplied one via httpClient(), return it as-is (escape hatch). - * Otherwise build a GuzzleHttpClient with the configured PoolConfig and emit the INFO log. + * Otherwise build a GuzzleHttpClient with the configured PoolConfig. Either way, + * emit one `client.initialized` INFO event through the injected PSR-3 logger. */ private function resolveHttpClient(): HttpClientInterface { + $logger = $this->logger ?? new NullLogger(); + $user = $this->httpClient; if ($user !== null) { - $this->logInfo( - 'getstream-php connection pool: user_http_client=true (5 knobs not applied)' - ); + $logger->info('client.initialized', $this->clientInitializedContext(userHttpClient: true)); + $this->warnIfLogBodies($logger); return $user; } - $client = new GuzzleHttpClient([], 3, $this->pool); + $client = new GuzzleHttpClient([], 3, $this->pool, $logger, $this->logBodies); - $this->logInfo(sprintf( - 'getstream-php connection pool: max_conns_per_host=%d idle_timeout=%ds connect_timeout=%ds request_timeout=%ds user_http_client=false', - $this->pool->maxConnsPerHost, - $this->pool->idleTimeout, - $this->pool->connectTimeout, - $this->pool->requestTimeout, - )); + $logger->info('client.initialized', $this->clientInitializedContext(userHttpClient: false)); + $this->warnIfLogBodies($logger); return $client; } - /** - * Emit one INFO log line via error_log(). - * Suppressed under PHPUnit to keep test output clean (PHPUNIT_RUNNING constant is set in phpunit.xml). - */ - private function logInfo(string $message): void + private function warnIfLogBodies(LoggerInterface $logger): void { - if (defined('PHPUNIT_RUNNING') && PHPUNIT_RUNNING) { - return; + if ($this->logBodies) { + $logger->warning( + 'Request/response bodies will be included in log events (keys api_secret/token/password are redacted).' + ); } - error_log('[INFO] ' . $message); + } + + /** @return array */ + private function clientInitializedContext(bool $userHttpClient): array + { + return [ + 'stream.sdk.name' => 'getstream-php', + 'stream.sdk.version' => Constant::VERSION, + 'stream.client.max_conns_per_host' => $this->pool->maxConnsPerHost, + 'stream.client.idle_timeout_seconds' => $this->pool->idleTimeout, + 'stream.client.connect_timeout_seconds' => $this->pool->connectTimeout, + 'stream.client.request_timeout_seconds' => $this->pool->requestTimeout, + 'stream.client.gzip_enabled' => true, + 'stream.client.user_http_client' => $userHttpClient, + 'stream.client.log_bodies' => $this->logBodies, + ]; } } diff --git a/src/Http/GuzzleHttpClient.php b/src/Http/GuzzleHttpClient.php index 4cfefd76..b303f1f8 100644 --- a/src/Http/GuzzleHttpClient.php +++ b/src/Http/GuzzleHttpClient.php @@ -17,6 +17,8 @@ use GuzzleHttp\Handler\CurlMultiHandler; use GuzzleHttp\HandlerStack; use Psr\Http\Message\ResponseInterface; +use Psr\Log\LoggerInterface; +use Psr\Log\NullLogger; /** * Guzzle HTTP client implementation. @@ -31,16 +33,30 @@ class GuzzleHttpClient implements HttpClientInterface /** @var PoolConfig Effective pool configuration (kept for diagnostics). */ private PoolConfig $pool; + private LoggerInterface $logger; + + /** Whether request/response bodies are included (key-redacted) in log events. */ + private bool $logBodies; + /** * Create a new GuzzleHttpClient. * - * @param array $config Guzzle client configuration (wins over $pool defaults) - * @param int $maxRetries Maximum retries for 429 rate-limit responses (default 3). - * @param PoolConfig|null $pool Connection pool configuration. When null, spec defaults apply. + * @param array $config Guzzle client configuration (wins over $pool defaults) + * @param int $maxRetries Maximum retries for 429 rate-limit responses (default 3). + * @param PoolConfig|null $pool Connection pool configuration. When null, spec defaults apply. + * @param LoggerInterface|null $logger PSR-3 logger for structured request/response events. Defaults to NullLogger. + * @param bool $logBodies When true, include (key-redacted) request/response bodies in log events. */ - public function __construct(array $config = [], int $maxRetries = 3, ?PoolConfig $pool = null) - { + public function __construct( + array $config = [], + int $maxRetries = 3, + ?PoolConfig $pool = null, + ?LoggerInterface $logger = null, + bool $logBodies = false, + ) { $pool = $pool ?? new PoolConfig(); + $this->logger = $logger ?? new NullLogger(); + $this->logBodies = $logBodies; // Persistent multi handle: routes every request (sync and async) through one // libcurl multi handle that holds a connection pool for the lifetime of this @@ -94,6 +110,77 @@ public function getPoolConfig(): PoolConfig return $this->pool; } + private static function elapsedMs(int $startNs): int + { + return (int) ((hrtime(true) - $startNs) / 1e6); + } + + /** Emit the `http.request.sent` DEBUG event for one HTTP attempt. */ + private function emitRequestSent(string $method, string $path, string $query, array $requestOptions): void + { + $context = [ + 'http.request.method' => $method, + 'url.path' => $path, + 'url.query' => LogRedaction::redactQuery($query), + ]; + + if ($this->logBodies && isset($requestOptions['json'])) { + $encoded = json_encode($requestOptions['json']); + if ($encoded !== false) { + $context['http.request.body'] = LogRedaction::redactJsonBody($encoded); + } + } + + $this->logger->debug('http.request.sent', $context); + } + + /** + * Emit the `http.response.received` DEBUG event for one HTTP attempt + * (any status code, including 4xx/5xx: those are data, not a transport + * failure). Reads the response body exactly once and returns it so the + * caller can reuse it instead of consuming the stream a second time. + */ + private function emitResponseReceived(ResponseInterface $response, int $durationMs): string + { + $size = $response->getBody()->getSize(); + $rawBody = (string) $response->getBody(); + + $context = [ + 'http.response.status_code' => $response->getStatusCode(), + 'http.response.body.size' => $size ?? strlen($rawBody), + 'duration_ms' => $durationMs, + ]; + + if ($this->logBodies) { + $contentType = $response->getHeaderLine('Content-Type'); + $context['http.response.body'] = str_contains($contentType, 'application/json') + ? LogRedaction::redactJsonBody($rawBody) + : $rawBody; + } + + $this->logger->debug('http.response.received', $context); + + return $rawBody; + } + + /** Emit the `http.request.failed` ERROR event: transport failure, no HTTP response received. */ + private function emitRequestFailed( + string $method, + string $path, + string $query, + StreamTransportException $transportException, + int $durationMs, + ): void { + $this->logger->error('http.request.failed', [ + 'http.request.method' => $method, + 'url.path' => $path, + 'url.query' => LogRedaction::redactQuery($query), + 'error.type' => $transportException->getErrorType(), + 'error.message' => $transportException->getMessage(), + 'duration_ms' => $durationMs, + ]); + } + /** * Make an HTTP request. * @@ -137,29 +224,48 @@ public function request( } } + $parsedPath = parse_url($url, PHP_URL_PATH); + $path = is_string($parsedPath) ? $parsedPath : $url; + $parsedQuery = parse_url($url, PHP_URL_QUERY); + $query = is_string($parsedQuery) ? $parsedQuery : ''; + // Retry loop for rate-limited (429) responses. for ($attempt = 0;; $attempt++) { + $this->emitRequestSent($method, $path, $query, $requestOptions); + $start = hrtime(true); + try { $response = $this->client->request($method, $url, $requestOptions); } catch (ClientException | ServerException $e) { // Reachable only if a caller flipped `http_errors` back to true. - return $this->createStreamResponse($e->getResponse(), $e); + $durationMs = self::elapsedMs($start); + $rawBody = $this->emitResponseReceived($e->getResponse(), $durationMs); + + return $this->createStreamResponse($e->getResponse(), $e, $rawBody); } catch (ConnectException $e) { - throw new StreamTransportException( + $transportException = new StreamTransportException( $e->getMessage(), self::mapConnectErrorType($e), $e, ); + $this->emitRequestFailed($method, $path, $query, $transportException, self::elapsedMs($start)); + + throw $transportException; } catch (GuzzleException $e) { - throw new StreamTransportException( + $transportException = new StreamTransportException( $e->getMessage(), StreamTransportException::ERROR_TYPE_UNKNOWN, $e, ); + $this->emitRequestFailed($method, $path, $query, $transportException, self::elapsedMs($start)); + + throw $transportException; } + $rawBody = $this->emitResponseReceived($response, self::elapsedMs($start)); + if ($response->getStatusCode() !== 429 || $attempt >= $this->maxRetries) { - return $this->createStreamResponse($response); + return $this->createStreamResponse($response, null, $rawBody); } // Parse Retry-After header or use exponential backoff. Jitter @@ -179,13 +285,16 @@ public function request( * @param \Throwable|null $previous Cause-chain link when the caller already * caught a Guzzle exception that exposed * the response. + * @param string|null $rawBody Body already read by the caller (e.g. for logging). + * The response body stream can only be consumed once; + * pass it through instead of re-reading it here. * * @return StreamResponse */ - private function createStreamResponse(ResponseInterface $response, ?\Throwable $previous = null): StreamResponse + private function createStreamResponse(ResponseInterface $response, ?\Throwable $previous = null, ?string $rawBody = null): StreamResponse { $statusCode = $response->getStatusCode(); - $rawBody = $response->getBody()->getContents(); + $rawBody ??= $response->getBody()->getContents(); // Convert headers to lowercase keys $headers = []; diff --git a/src/Http/LogRedaction.php b/src/Http/LogRedaction.php new file mode 100644 index 00000000..4bef8f61 --- /dev/null +++ b/src/Http/LogRedaction.php @@ -0,0 +1,53 @@ +'; + private const QUERY_PARAMS = ['api_key', 'api_secret', 'token']; + private const BODY_KEYS = ['api_secret', 'token', 'password']; + + public static function redactQuery(string $query): string + { + if ($query === '') { + return ''; + } + parse_str($query, $params); + foreach ($params as $name => $_value) { + if (in_array(strtolower((string) $name), self::QUERY_PARAMS, true)) { + $params[$name] = self::REDACTED; + } + } + + return urldecode(http_build_query($params)); + } + + public static function redactJsonBody(?string $body): ?string + { + if ($body === null || $body === '') { + return $body; + } + $data = json_decode($body, true); + if (!is_array($data)) { + return $body; + } + $changed = false; + foreach (self::BODY_KEYS as $key) { + if (array_key_exists($key, $data)) { + $data[$key] = self::REDACTED; + $changed = true; + } + } + + if (!$changed) { + return $body; + } + $encoded = json_encode($data); + + return $encoded !== false ? $encoded : $body; + } +} diff --git a/tests/ClientBuilderTest.php b/tests/ClientBuilderTest.php index 80d1f242..f76a97a4 100644 --- a/tests/ClientBuilderTest.php +++ b/tests/ClientBuilderTest.php @@ -8,6 +8,7 @@ use GetStream\Client; use GetStream\ClientBuilder; use GetStream\Http\HttpClientInterface; +use GetStream\Tests\Http\RecordingLogger; use GetStream\VideoClient; use PHPUnit\Framework\MockObject\MockObject; use PHPUnit\Framework\TestCase; @@ -291,4 +292,77 @@ public function userSuppliedHttpClientBypassesBuild(): void // And it is NOT a GuzzleHttpClient (no pool config is applied to it). self::assertNotInstanceOf(\GetStream\Http\GuzzleHttpClient::class, $client->getHttpClient()); } + + /** @test */ + public function loggerReceivesExactlyOneClientInitializedInfoEvent(): void + { + $logger = new RecordingLogger(); + + (new ClientBuilder()) + ->apiKey('k') + ->apiSecret('s') + ->maxConnsPerHost(7) + ->idleTimeout(33) + ->connectTimeout(2) + ->requestTimeout(11) + ->logger($logger) + ->skipEnvLoad() + ->build(); + + $events = $logger->named('client.initialized'); + self::assertCount(1, $events); + self::assertSame('info', $events[0]['level']); + + $context = $events[0]['context']; + self::assertSame('getstream-php', $context['stream.sdk.name']); + self::assertSame(\GetStream\Constant::VERSION, $context['stream.sdk.version']); + self::assertSame(7, $context['stream.client.max_conns_per_host']); + self::assertSame(33, $context['stream.client.idle_timeout_seconds']); + self::assertSame(2, $context['stream.client.connect_timeout_seconds']); + self::assertSame(11, $context['stream.client.request_timeout_seconds']); + self::assertTrue($context['stream.client.gzip_enabled']); + self::assertFalse($context['stream.client.user_http_client']); + self::assertFalse($context['stream.client.log_bodies']); + } + + /** @test */ + public function logBodiesTrueAddsExactlyOneWarnAndFlagsSchema(): void + { + $logger = new RecordingLogger(); + + (new ClientBuilder()) + ->apiKey('k') + ->apiSecret('s') + ->logger($logger) + ->logBodies(true) + ->skipEnvLoad() + ->build(); + + $warnings = array_values(array_filter($logger->records, fn ($r) => $r['level'] === 'warning')); + self::assertCount(1, $warnings); + + $initialized = $logger->named('client.initialized'); + self::assertCount(1, $initialized); + self::assertTrue($initialized[0]['context']['stream.client.log_bodies']); + } + + /** @test */ + public function buildingWithoutLoggerProducesNoErrorLogOutput(): void + { + $tmp = tempnam(sys_get_temp_dir(), 'gs-no-log-'); + $previous = ini_set('error_log', $tmp); + + try { + (new ClientBuilder()) + ->apiKey('k') + ->apiSecret('s') + ->skipEnvLoad() + ->build(); + } finally { + ini_set('error_log', $previous === false ? '' : $previous); + } + + self::assertSame('', file_get_contents($tmp), 'no logger injected: construction must produce zero error_log output'); + @unlink($tmp); + } } diff --git a/tests/Http/LoggingTest.php b/tests/Http/LoggingTest.php new file mode 100644 index 00000000..0c2cf53f --- /dev/null +++ b/tests/Http/LoggingTest.php @@ -0,0 +1,122 @@ + */ + public array $records = []; + + public function log($level, \Stringable|string $message, array $context = []): void + { + $this->records[] = ['level' => (string) $level, 'message' => (string) $message, 'context' => $context]; + } + + /** @return list */ + public function named(string $event): array + { + return array_values(array_filter($this->records, fn ($r) => $r['message'] === $event)); + } +} + +final class LoggingTest extends TestCase +{ + private function client(array $responses, RecordingLogger $logger, bool $logBodies = false): GuzzleHttpClient + { + $stack = HandlerStack::create(new MockHandler($responses)); + + return new GuzzleHttpClient(['handler' => $stack], 3, null, $logger, $logBodies); + } + + public function testSentAndReceivedOnSuccess(): void + { + $logger = new RecordingLogger(); + $client = $this->client([new Response(200, ['Content-Type' => 'application/json'], '{"ok":true}')], $logger); + $client->request('GET', 'http://localhost/api/v2/app?api_key=key'); + $this->assertCount(1, $logger->named('http.request.sent')); + $received = $logger->named('http.response.received'); + $this->assertCount(1, $received); + $this->assertSame(200, $received[0]['context']['http.response.status_code']); + $this->assertArrayHasKey('duration_ms', $received[0]['context']); + } + + public function testErrorStatusIsReceivedNotFailed(): void + { + $logger = new RecordingLogger(); + $client = $this->client([new Response(500, ['Content-Type' => 'application/json'], '{"code":1,"message":"boom"}')], $logger); + try { + $client->request('GET', 'http://localhost/api/v2/app'); + $this->fail('expected exception'); + } catch (\GetStream\Exceptions\StreamApiException) { + } + $this->assertCount(1, $logger->named('http.response.received')); + $this->assertCount(0, $logger->named('http.request.failed')); + } + + public function testTransportFailureEmitsFailed(): void + { + $logger = new RecordingLogger(); + $client = $this->client([new ConnectException('reset', new Request('GET', 'http://localhost/x'))], $logger); + try { + $client->request('GET', 'http://localhost/x'); + $this->fail('expected exception'); + } catch (\GetStream\Exceptions\StreamTransportException) { + } + $failed = $logger->named('http.request.failed'); + $this->assertCount(1, $failed); + $this->assertSame('error', $failed[0]['level']); + $this->assertArrayHasKey('error.type', $failed[0]['context']); + } + + public function testQueryRedaction(): void + { + $logger = new RecordingLogger(); + $client = $this->client([new Response(200, [], '{}')], $logger); + $client->request('GET', 'http://localhost/api/v2/app?api_key=sekret&x=1'); + $sent = $logger->named('http.request.sent')[0]; + $this->assertStringNotContainsString('sekret', $sent['context']['url.query']); + $this->assertStringContainsString('', $sent['context']['url.query']); + } + + public function testLogBodiesOffByDefaultOnWithRedaction(): void + { + $logger = new RecordingLogger(); + $client = $this->client([new Response(200, ['Content-Type' => 'application/json'], '{"token":"tok","keep":"v"}')], $logger); + $client->request('GET', 'http://localhost/x'); + $this->assertArrayNotHasKey('http.response.body', $logger->named('http.response.received')[0]['context']); + + $logger2 = new RecordingLogger(); + $client2 = $this->client([new Response(200, ['Content-Type' => 'application/json'], '{"token":"tok","keep":"v"}')], $logger2, true); + $client2->request('GET', 'http://localhost/x'); + $body = $logger2->named('http.response.received')[0]['context']['http.response.body']; + // Quoted, not bare: the key name "token" itself contains the substring + // "tok", and redaction preserves key names (only values are redacted). + // Bare assertStringNotContainsString('tok', ...) can never pass while + // the "token" key is present; mirrors the quoted-value check below in + // testRedactionHelpers. + $this->assertStringNotContainsString('"tok"', $body); + $this->assertStringContainsString('keep', $body); + } + + public function testRedactionHelpers(): void + { + $this->assertSame('api_key=&x=1', LogRedaction::redactQuery('api_key=sekret&x=1')); + $out = LogRedaction::redactJsonBody('{"api_secret":"s","password":"p","keep":"v"}'); + $this->assertStringNotContainsString('"s"', $out); + $this->assertStringNotContainsString('"p"', $out); + $this->assertStringContainsString('"keep":"v"', $out); + $this->assertSame('not json', LogRedaction::redactJsonBody('not json')); + } +} diff --git a/tests/Integration/ConnectionPoolLogTest.php b/tests/Integration/ConnectionPoolLogTest.php index f954377f..88f81462 100644 --- a/tests/Integration/ConnectionPoolLogTest.php +++ b/tests/Integration/ConnectionPoolLogTest.php @@ -4,76 +4,73 @@ namespace GetStream\Tests\Integration; +use GetStream\ClientBuilder; use PHPUnit\Framework\TestCase; +use Psr\Log\AbstractLogger; /** * @group integration */ class ConnectionPoolLogTest extends TestCase { - public function testInfoLogContainsAllKnobs(): void + public function testClientInitializedLogContainsAllKnobs(): void { - $tmp = tempnam(sys_get_temp_dir(), 'gs-cp-log-'); - $autoload = realpath(__DIR__ . '/../../vendor/autoload.php'); - $script = <<apiKey('k')->apiSecret('s') - ->maxConnsPerHost(7)->idleTimeout(33)->connectTimeout(2)->requestTimeout(11) - ->skipEnvLoad() - ->build(); -PHP; - $scriptPath = tempnam(sys_get_temp_dir(), 'gs-cp-script-') . '.php'; - file_put_contents($scriptPath, $script); + $logger = new class extends AbstractLogger { + /** @var list */ + public array $records = []; - $cmd = sprintf('php %s %s 2>&1', escapeshellarg($scriptPath), escapeshellarg($tmp)); - exec($cmd, $out, $code); - self::assertSame(0, $code, implode("\n", $out)); + public function log($level, \Stringable|string $message, array $context = []): void + { + $this->records[] = ['level' => (string) $level, 'message' => (string) $message, 'context' => $context]; + } + }; - $log = file_get_contents($tmp); - self::assertStringContainsString('max_conns_per_host=7', $log); - self::assertStringContainsString('idle_timeout=33s', $log); - self::assertStringContainsString('connect_timeout=2s', $log); - self::assertStringContainsString('request_timeout=11s', $log); - self::assertStringContainsString('user_http_client=false', $log); + (new ClientBuilder()) + ->apiKey('k')->apiSecret('s') + ->maxConnsPerHost(7)->idleTimeout(33)->connectTimeout(2)->requestTimeout(11) + ->logger($logger) + ->skipEnvLoad() + ->build(); - @unlink($tmp); - @unlink($scriptPath); + self::assertCount(1, $logger->records); + $event = $logger->records[0]; + self::assertSame('info', $event['level']); + self::assertSame('client.initialized', $event['message']); + self::assertSame(7, $event['context']['stream.client.max_conns_per_host']); + self::assertSame(33, $event['context']['stream.client.idle_timeout_seconds']); + self::assertSame(2, $event['context']['stream.client.connect_timeout_seconds']); + self::assertSame(11, $event['context']['stream.client.request_timeout_seconds']); + self::assertFalse($event['context']['stream.client.user_http_client']); } - public function testInfoLogIndicatesEscapeHatchUsed(): void + public function testClientInitializedLogIndicatesEscapeHatchUsed(): void { - $tmp = tempnam(sys_get_temp_dir(), 'gs-cp-log-'); - $autoload = realpath(__DIR__ . '/../../vendor/autoload.php'); - $script = <<apiKey('k')->apiSecret('s') - ->httpClient(\$mock) - ->skipEnvLoad() - ->build(); -PHP; - $scriptPath = tempnam(sys_get_temp_dir(), 'gs-cp-script-') . '.php'; - file_put_contents($scriptPath, $script); + $logger = new class extends AbstractLogger { + /** @var list */ + public array $records = []; + + public function log($level, \Stringable|string $message, array $context = []): void + { + $this->records[] = ['level' => (string) $level, 'message' => (string) $message, 'context' => $context]; + } + }; - $cmd = sprintf('php %s %s 2>&1', escapeshellarg($scriptPath), escapeshellarg($tmp)); - exec($cmd, $out, $code); - self::assertSame(0, $code, implode("\n", $out)); + $mock = new class implements \GetStream\Http\HttpClientInterface { + public function request(string $method, string $url, array $headers = [], mixed $body = null, array $options = []): \GetStream\StreamResponse + { + return new \GetStream\StreamResponse(200, [], null, ''); + } + }; - $log = file_get_contents($tmp); - self::assertStringContainsString('user_http_client=true', $log); - self::assertStringContainsString('5 knobs not applied', $log); + (new ClientBuilder()) + ->apiKey('k')->apiSecret('s') + ->httpClient($mock) + ->logger($logger) + ->skipEnvLoad() + ->build(); - @unlink($tmp); - @unlink($scriptPath); + self::assertCount(1, $logger->records); + self::assertSame('client.initialized', $logger->records[0]['message']); + self::assertTrue($logger->records[0]['context']['stream.client.user_http_client']); } } From 6cd5326ba68cbeb1ef7352ad2370b3c591d2554e Mon Sep 17 00:00:00 2001 From: Yun Wang Date: Wed, 22 Jul 2026 16:03:36 +0200 Subject: [PATCH 2/4] fix: redact secrets from transport exception messages before logging Guzzle's ConnectException/GuzzleException messages embed the full request URL, including api_key/api_secret/token query params. That message was logged verbatim into error.message on http.request.failed, leaking live secrets on every DNS/connect/TLS/timeout failure even though the sibling url.query field was already redacted. Add LogRedaction::redactMessage() to scrub key=value occurrences of the known secret keys anywhere in a free-form string, and apply it at the http.request.failed emission site. --- src/Http/GuzzleHttpClient.php | 2 +- src/Http/LogRedaction.php | 16 ++++++++++++++++ tests/Http/LoggingTest.php | 34 ++++++++++++++++++++++++++++++++++ 3 files changed, 51 insertions(+), 1 deletion(-) diff --git a/src/Http/GuzzleHttpClient.php b/src/Http/GuzzleHttpClient.php index b303f1f8..793db7f6 100644 --- a/src/Http/GuzzleHttpClient.php +++ b/src/Http/GuzzleHttpClient.php @@ -176,7 +176,7 @@ private function emitRequestFailed( 'url.path' => $path, 'url.query' => LogRedaction::redactQuery($query), 'error.type' => $transportException->getErrorType(), - 'error.message' => $transportException->getMessage(), + 'error.message' => LogRedaction::redactMessage($transportException->getMessage()), 'duration_ms' => $durationMs, ]); } diff --git a/src/Http/LogRedaction.php b/src/Http/LogRedaction.php index 4bef8f61..c9da76be 100644 --- a/src/Http/LogRedaction.php +++ b/src/Http/LogRedaction.php @@ -50,4 +50,20 @@ public static function redactJsonBody(?string $body): ?string return $encoded !== false ? $encoded : $body; } + + /** + * Redact secret query-parameter values wherever `key=value` appears in a + * free-form string (e.g. a transport exception message that echoes back + * the failed request URL). Value runs up to the next `&`, whitespace, or + * end of string; everything else in the message is left untouched. + */ + public static function redactMessage(string $message): string + { + $keys = implode('|', array_map( + static fn (string $key): string => preg_quote($key, '/'), + self::QUERY_PARAMS, + )); + + return (string) preg_replace('/(' . $keys . ')=[^&\s]*/i', '${1}=' . self::REDACTED, $message); + } } diff --git a/tests/Http/LoggingTest.php b/tests/Http/LoggingTest.php index 0c2cf53f..64d42689 100644 --- a/tests/Http/LoggingTest.php +++ b/tests/Http/LoggingTest.php @@ -80,6 +80,30 @@ public function testTransportFailureEmitsFailed(): void $this->assertArrayHasKey('error.type', $failed[0]['context']); } + public function testTransportFailureRedactsSecretFromMessage(): void + { + // Guzzle builds its ConnectException message by appending the full + // request URL (incl. query string); its own redaction only strips + // HTTP Basic userinfo, not query params. This is the mainline shape + // of that message for a DNS/connect/TLS/timeout failure. + $leakyMessage = 'cURL error 7: Failed to connect to 127.0.0.1 port 1 after 0 ms: ' + . 'Couldn\'t connect to server for http://localhost/api/v2/app?api_key=SUPERSECRETKEY&user_id=123'; + $logger = new RecordingLogger(); + $client = $this->client( + [new ConnectException($leakyMessage, new Request('GET', 'http://localhost/api/v2/app?api_key=SUPERSECRETKEY&user_id=123'))], + $logger, + ); + try { + $client->request('GET', 'http://localhost/api/v2/app?api_key=SUPERSECRETKEY&user_id=123'); + $this->fail('expected exception'); + } catch (\GetStream\Exceptions\StreamTransportException) { + } + $failed = $logger->named('http.request.failed'); + $message = $failed[0]['context']['error.message']; + $this->assertStringContainsString('api_key=', $message); + $this->assertStringNotContainsString('SUPERSECRETKEY', $message); + } + public function testQueryRedaction(): void { $logger = new RecordingLogger(); @@ -118,5 +142,15 @@ public function testRedactionHelpers(): void $this->assertStringNotContainsString('"p"', $out); $this->assertStringContainsString('"keep":"v"', $out); $this->assertSame('not json', LogRedaction::redactJsonBody('not json')); + + $this->assertSame( + 'api_key=&user_id=123', + LogRedaction::redactMessage('api_key=SUPERSECRETKEY&user_id=123'), + ); + $this->assertSame( + 'api_secret= token=', + LogRedaction::redactMessage('api_secret=shh token=tok'), + ); + $this->assertStringContainsString('user_id=123', LogRedaction::redactMessage('user_id=123')); } } From e2a527256fcceef89c9436e77896a020e10f6719 Mon Sep 17 00:00:00 2001 From: Yun Wang Date: Wed, 22 Jul 2026 16:54:19 +0200 Subject: [PATCH 3/4] style: align log_bodies warning to canonical cross-SDK wording --- src/ClientBuilder.php | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/ClientBuilder.php b/src/ClientBuilder.php index e447688d..4c145aec 100644 --- a/src/ClientBuilder.php +++ b/src/ClientBuilder.php @@ -320,7 +320,7 @@ private function warnIfLogBodies(LoggerInterface $logger): void { if ($this->logBodies) { $logger->warning( - 'Request/response bodies will be included in log events (keys api_secret/token/password are redacted).' + 'HTTP request/response bodies will be logged. Auth headers and known-secret fields are still redacted, but other sensitive data (messages, PII) may appear in logs. Disable for production.' ); } } From 9f9f421ff0818be2b22ee773f44cb093eaa73150 Mon Sep 17 00:00:00 2001 From: Yun Wang Date: Wed, 22 Jul 2026 18:00:30 +0200 Subject: [PATCH 4/4] fix(tests): extract RecordingLogger to its own file so it autoloads under paratest workers --- tests/Http/LoggingTest.php | 19 ++----------------- tests/Http/RecordingLogger.php | 31 +++++++++++++++++++++++++++++++ 2 files changed, 33 insertions(+), 17 deletions(-) create mode 100644 tests/Http/RecordingLogger.php diff --git a/tests/Http/LoggingTest.php b/tests/Http/LoggingTest.php index 64d42689..97dfe80a 100644 --- a/tests/Http/LoggingTest.php +++ b/tests/Http/LoggingTest.php @@ -12,24 +12,9 @@ use GuzzleHttp\Psr7\Request; use GuzzleHttp\Psr7\Response; use PHPUnit\Framework\TestCase; -use Psr\Log\AbstractLogger; -final class RecordingLogger extends AbstractLogger -{ - /** @var list */ - public array $records = []; - - public function log($level, \Stringable|string $message, array $context = []): void - { - $this->records[] = ['level' => (string) $level, 'message' => (string) $message, 'context' => $context]; - } - - /** @return list */ - public function named(string $event): array - { - return array_values(array_filter($this->records, fn ($r) => $r['message'] === $event)); - } -} +// RecordingLogger moved to its own autoloadable file (tests/Http/RecordingLogger.php) +// so it resolves under paratest's per-process runner; see that file. final class LoggingTest extends TestCase { diff --git a/tests/Http/RecordingLogger.php b/tests/Http/RecordingLogger.php new file mode 100644 index 00000000..7fec5e32 --- /dev/null +++ b/tests/Http/RecordingLogger.php @@ -0,0 +1,31 @@ + */ + public array $records = []; + + public function log($level, \Stringable|string $message, array $context = []): void + { + $this->records[] = ['level' => (string) $level, 'message' => (string) $message, 'context' => $context]; + } + + /** @return list */ + public function named(string $event): array + { + return array_values(array_filter($this->records, fn ($r) => $r['message'] === $event)); + } +}