8000 feature #30537 [HttpClient] logger integration (antonch1989, nicolas-… · symfony/symfony@09e8d74 · GitHub
[go: up one dir, main page]
Skip to content

Commit 09e8d74

Browse files
fabpotfabpot
committed
feature #30537 [HttpClient] logger integration (antonch1989, nicolas-grekas)
This PR was merged into the 4.3-dev branch. Discussion ---------- [HttpClient] logger integration | Q | A | ------------- | --- | Branch? | master | Bug fix? | no | New feature? | yes | BC breaks? | no <!-- see https://symfony.com/bc --> | Deprecations? | no | Tests pass? | yes <!-- please add some, will be required by reviewers --> | Fixed tickets | #30502 <!-- #-prefixed issue number(s), if any --> | License | MIT | Doc PR | Commits ------- 26d15c8 [HttpClient] log requests, responses and pushes when they happen fc6ba7e [HttpClient] logger integration
2 parents da4db91 + 26d15c8 commit 09e8d74

File tree

10 files changed

+141
-35
lines changed

10 files changed

+141
-35
lines changed

‎src/Symfony/Bundle/FrameworkBundle/Resources/config/http_client.xml

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6,9 +6,13 @@
66

77
<services>
88
<service id="http_client" class="Symfony\Contracts\HttpClient\HttpClientInterface">
9+
<tag name="monolog.logger" channel="http_client" />
910
<factory class="Symfony\Component\HttpClient\HttpClient" method="create" />
1011
<argument type="collection" /> <!-- default options -->
1112
<argument /> <!-- max host connections -->
13+
<call method="setLogger">
14+
<argument type="service" id="logger" on-invalid="ignore" />
15+
</call>
1216
</service>
1317
<service id="Symfony\Contracts\HttpClient\HttpClientInterface" alias="http_client" />
1418

‎src/Symfony/Component/HttpClient/CurlHttpClient.php

Lines changed: 38 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,9 @@
1111

1212
namespace Symfony\Component\HttpClient;
1313

14+
use Psr\Log\LoggerAwareInterface;
15+
use Psr\Log\LoggerAwareTrait;
16+
use Psr\Log\LoggerInterface;
1417
use Symfony\Component\HttpClient\Exception\TransportException;
1518
use Symfony\Component\HttpClient\Response\CurlResponse;
1619
use Symfony\Component\HttpClient\Response\ResponseStream;
@@ -28,20 +31,22 @@
2831
*
2932
* @experimental in 4.3
3033
*/
31-
final class CurlHttpClient implements HttpClientInterface
34+
final class CurlHttpClient implements HttpClientInterface, LoggerAwareInterface
3235
{
3336
use HttpClientTrait;
37+
use LoggerAwareTrait;
3438

3539
private $defaultOptions = self::OPTIONS_DEFAULTS;
3640
private $multi;
3741

3842
/**
3943
* @param array $defaultOptions Default requests' options
4044
* @param int $maxHostConnections The maximum number of connections to a single host
45+
* @param int $maxPendingPushes The maximum number of pushed responses to accept in the queue
4146
*
4247
* @see HttpClientInterface::OPTIONS_DEFAULTS for available options
4348
*/
44-
public function __construct(array $defaultOptions = [], int $maxHostConnections = 6)
49+
public function __construct(array $defaultOptions = [], int $maxHostConnections = 6, int $maxPendingPushes = 50)
4550
{
4651
if ($defaultOptions) {
4752
[, $this->defaultOptions] = self::prepareRequest(null, null, $defaultOptions, self::OPTIONS_DEFAULTS);
@@ -65,7 +70,7 @@ public function __construct(array $defaultOptions = [], int $maxHostConnections
6570
];
6671

6772
// Skip configuring HTTP/2 push when it's unsupported or buggy, see https://bugs.php.net/bug.php?id=77535
68-
if (\PHP_VERSION_ID < 70217 || (\PHP_VERSION_ID >= 70300 && \PHP_VERSION_ID < 70304)) {
73+
if (0 >= $maxPendingPushes || \PHP_VERSION_ID < 70217 || (\PHP_VERSION_ID >= 70300 && \PHP_VERSION_ID < 70304)) {
6974
return;
7075
}
7176

@@ -74,8 +79,10 @@ public function __construct(array $defaultOptions = [], int $maxHostConnections
7479
return;
7580
}
7681

77-
curl_multi_setopt($mh, CURLMOPT_PUSHFUNCTION, static function ($parent, $pushed, array $requestHeaders) use ($multi) {
78-
return self::handlePush($parent, $pushed, $requestHeaders, $multi);
82+
$logger = &$this->logger;
83+
84+
curl_multi_setopt($mh, CURLMOPT_PUSHFUNCTION, static function ($parent, $pushed, array $requestHeaders) use ($multi, $maxPendingPushes, &$logger) {
85+
return self::handlePush($parent, $pushed, $requestHeaders, $multi, $maxPendingPushes, $logger);
7986
});
8087
}
8188

@@ -103,13 +110,19 @@ public function request(string $method, string $url, array $options = []): Respo
103110
];
104111

105112
if ('GET' === $method && !$options['body'] && $expectedHeaders === $pushedHeaders) {
113+
$this->logger && $this->logger->info(sprintf('Connecting request to pushed response: %s %s', $method, $url));
114+
106115
// Reinitialize the pushed response with request's options
107-
$pushedResponse->__construct($this->multi, $url, $options);
116+
$pushedResponse->__construct($this->multi, $url, $options, $this->logger);
108117

109118
return $pushedResponse;
110119
}
120+
121+
$this->logger && $this->logger->info(sprintf('Rejecting pushed response for "%s": authorization headers don\'t match the request', $url));
111122
}
112123

124+
$this->logger && $this->logger->info(sprintf('Request: %s %s', $method, $url));
125+
113126
$curlopts = [
114127
CURLOPT_URL => $url,
115128
CURLOPT_USERAGENT => 'Symfony HttpClient/Curl',
@@ -255,7 +268,7 @@ public function request(string $method, string $url, array $options = []): Respo
255268
}
256269
}
257270

258-
return new CurlResponse($this->multi, $ch, $options, $method, self::createRedirectResolver($options, $host));
271+
return new CurlResponse($this->multi, $ch, $options, $this->logger, $method, self::createRedirectResolver($options, $host));
259272
}
260273

261274
/**
@@ -282,30 +295,44 @@ public function __destruct()
282295
}
283296
}
284297

285-
private static function handlePush($parent, $pushed, array $requestHeaders, \stdClass $multi): int
298+
private static function handlePush($parent, $pushed, array $requestHeaders, \stdClass $multi, int $maxPendingPushes, ?LoggerInterface $logger): int
286299
{
287300
$headers = [];
301+
$origin = curl_getinfo($parent, CURLINFO_EFFECTIVE_URL);
288302

289303
foreach ($requestHeaders as $h) {
290304
if (false !== $i = strpos($h, ':', 1)) {
291305
$headers[substr($h, 0, $i)] = substr($h, 1 + $i);
292306
}
293307
}
294308

295-
if ('GET' !== $headers[':method'] || isset($headers['range'])) {
309+
if (!isset($headers[':method']) || !isset($headers[':scheme']) || !isset($headers[':authority']) || !isset($headers[':path']) || 'GET' !== $headers[':method'] || isset($headers['range'])) {
310+
$logger && $logger->info(sprintf('Rejecting pushed response from "%s": pushed headers are invalid', $origin));
311+
296312
return CURL_PUSH_DENY;
297313
}
298314

299315
$url = $headers[':scheme'].'://'.$headers[':authority'];
300316

317+
if ($maxPendingPushes <= \count($multi->pushedResponses)) {
318+
$logger && $logger->info(sprintf('Rejecting pushed response from "%s" for "%s": the queue is full', $origin, $url));
319+
320+
return CURL_PUSH_DENY;
321+
}
322+
301323
// curl before 7.65 doesn't validate the pushed ":authority" header,
302324
// but this is a MUST in the HTTP/2 RFC; let's restrict pushes to the original host,
303325
// ignoring domains mentioned as alt-name in the certificate for now (same as curl).
304-
if (0 !== strpos(curl_getinfo($parent, CURLINFO_EFFECTIVE_URL), $url.'/')) {
326+
if (0 !== strpos($origin, $url.'/')) {
327+
$logger && $logger->info(sprintf('Rejecting pushed response from "%s": server is not authoritative for "%s"', $origin, $url));
328+
305329
return CURL_PUSH_DENY;
306330
}
307331

308-
$multi->pushedResponses[$url.$headers[':path']] = [
332+
$url .= $headers[':path'];
333+
$logger && $logger->info(sprintf('Queueing pushed response: %s', $url));
334+
335+
$multi->pushedResponses[$url] = [
309336
new CurlResponse($multi, $pushed),
310337
[
311338
$headers['authorization'] ?? null,

‎src/Symfony/Component/HttpClient/HttpClient.php

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -25,13 +25,14 @@ final class HttpClient
2525
/**
2626
* @param array $defaultOptions Default requests' options
2727
* @param int $maxHostConnections The maximum number of connections to a single host
28+
* @param int $maxPendingPushes The maximum number of pushed responses to accept in the queue
2829
*
2930
* @see HttpClientInterface::OPTIONS_DEFAULTS F438 for available options
3031
*/
31-
public static function create(array $defaultOptions = [], int $maxHostConnections = 6): HttpClientInterface
32+
public static function create(array $defaultOptions = [], int $maxHostConnections = 6, int $maxPendingPushes = 50): HttpClientInterface
3233
{
3334
if (\extension_loaded('curl')) {
34-
return new CurlHttpClient($defaultOptions, $maxHostConnections);
35+
return new CurlHttpClient($defaultOptions, $maxHostConnections, $maxPendingPushes);
3536
}
3637

3738
return new NativeHttpClient($defaultOptions, $maxHostConnections);

‎src/Symfony/Component/HttpClient/NativeHttpClient.php

Lines changed: 8 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,8 @@
1111

1212
namespace Symfony\Component\HttpClient;
1313

14+
use Psr\Log\LoggerAwareInterface;
15+
use Psr\Log\LoggerAwareTrait;
1416
use Symfony\Component\HttpClient\Exception\TransportException;
1517
use Symfony\Component\HttpClient\Response\NativeResponse;
1618
use Symfony\Component\HttpClient\Response\ResponseStream;
@@ -28,9 +30,10 @@
2830
*
2931
* @experimental in 4.3
3032
*/
31-
final class NativeHttpClient implements HttpClientInterface
33+
final class NativeHttpClient implements HttpClientInterface, LoggerAwareInterface
3234
{
3335
use HttpClientTrait;
36+
use LoggerAwareTrait;
3437

3538
private $defaultOptions = self::OPTIONS_DEFAULTS;
3639
private $multi;
@@ -205,7 +208,10 @@ public function request(string $method, string $url, array $options = []): Respo
205208
$context = stream_context_create($context, ['notification' => $notification]);
206209
self::configureHeadersAndProxy($context, $host, $options['request_headers'], $proxy, $noProxy);
207210

208-
return new NativeResponse($this->multi, $context, implode('', $url), $options, $gzipEnabled, $info, $resolveRedirect, $onProgress);
211+
$url = implode('', $url);
212+
$this->logger && $this->logger->info(sprintf('Request: %s %s', $method, $url));
213+
214+
return new NativeResponse($this->multi, $context, $url, $options, $gzipEnabled, $info, $resolveRedirect, $onProgress, $this->logger);
209215
}
210216

211217
/**

‎src/Symfony/Component/HttpClient/Response/CurlResponse.php

Lines changed: 22 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@
1111

1212
namespace Symfony\Component\HttpClient\Response;
1313

14+
use Psr\Log\LoggerInterface;
1415
use Symfony\Component\HttpClient\Chunk\FirstChunk;
1516
use Symfony\Component\HttpClient\Exception\TransportException;
1617
use Symfony\Contracts\HttpClient\ResponseInterface;
@@ -29,7 +30,7 @@ final class CurlResponse implements ResponseInterface
2930
/**
3031
* @internal
3132
*/
32-
public function __construct(\stdClass $multi, $ch, array $options = null, string $method = 'GET', callable $resolveRedirect = null)
33+
public function __construct(\stdClass $multi, $ch, array $options = null, LoggerInterface $logger = null, string $method = 'GET', callable $resolveRedirect = null)
3334
{
3435
$this->multi = $multi;
3536

@@ -41,6 +42,7 @@ public function __construct(\stdClass $multi, $ch, array $options = null, string
4142
}
4243

4344
$this->id = $id = (int) $ch;
45+
$this->logger = $logger;
4446
$this->timeout = $options['timeout'] ?? null;
4547
$this->info['http_method'] = $method;
4648
$this->info['user_data'] = $options['user_data'] ?? null;
@@ -64,8 +66,8 @@ public function __construct(\stdClass $multi, $ch, array $options = null, string
6466
$content = ($options['buffer'] ?? true) ? $content : null;
6567
}
6668

67-
curl_setopt($ch, CURLOPT_HEADERFUNCTION, static function ($ch, string $data) use (&$info, &$headers, $options, $multi, $id, &$location, $resolveRedirect): int {
68-
return self::parseHeaderLine($ch, $data, $info, $headers, $options, $multi, $id, $location, $resolveRedirect);
69+
curl_setopt($ch, CURLOPT 10000 _HEADERFUNCTION, static function ($ch, string $data) use (&$info, &$headers, $options, $multi, $id, &$location, $resolveRedirect, $logger): int {
70+
return self::parseHeaderLine($ch, $data, $info, $headers, $options, $multi, $id, $location, $resolveRedirect, $logger);
6971
});
7072

7173
if (null === $options) {
@@ -103,7 +105,9 @@ public function __construct(\stdClass $multi, $ch, array $options = null, string
103105
throw new TransportException($response->info['error']);
104106
}
105107

106-
if (\in_array(curl_getinfo($ch = $response->handle, CURLINFO_PRIVATE), ['headers', 'destruct'], true)) {
108+
$waitFor = curl_getinfo($ch = $response->handle, CURLINFO_PRIVATE);
109+
110+
if (\in_array($waitFor, ['headers', 'destruct'], true)) {
107111
try {
108112
if (\defined('CURLOPT_STREAM_WEIGHT')) {
109113
curl_setopt($ch, CURLOPT_STREAM_WEIGHT, 32);
@@ -115,6 +119,8 @@ public function __construct(\stdClass $multi, $ch, array $options = null, string
115119
$response->close();
116120
throw $e;
117121
}
122+
} elseif ('content' === $waitFor && ($response->multi->handlesActivity[$response->id][0] ?? null) instanceof FirstChunk) {
123+
self::stream([$response])->current();
118124
}
119125

120126
curl_setopt($ch, CURLOPT_HEADERFUNCTION, null);
@@ -156,8 +162,8 @@ public function getInfo(string $type = null)
156162
public function __destruct()
157163
{
158164
try {
159-
if (null === $this->timeout || isset($this->info['url'])) {
160-
return; // pushed response
165+
if (null === $this->timeout) {
166+
return; // Unused pushed response
161167
}
162168

163169
if ('content' === $waitFor = curl_getinfo($this->handle, CURLINFO_PRIVATE)) {
@@ -171,7 +177,13 @@ public function __destruct()
171177
$this->close();
172178

173179
// Clear local caches when the only remaining handles are about pushed responses
174-
if (\count($this->multi->openHandles) === \count($this->multi->pushedResponses)) {
180+
if (!$this->multi->openHandles) {
181+
if ($this->logger) {
182+
foreach ($this->multi->pushedResponses as $url => $response) {
183+
$this->logger->info(sprintf('Unused pushed response: %s', $url));
184+
}
185+
}
186+
175187
$this->multi->pushedResponses = [];
176188
// Schedule DNS cache eviction for the next request
177189
$this->multi->dnsCache[2] = $this->multi->dnsCache[2] ?: $this->multi->dnsCache[1];
@@ -249,7 +261,7 @@ protected static function select(\stdClass $multi, float $timeout): int
249261
/**
250262
* Parses header lines as curl yields them to us.
251263
*/
252-
private static function parseHeaderLine($ch, string $data, array &$info, array &$headers, ?array $options, \stdClass $multi, int $id, ?string &$location, ?callable $resolveRedirect): int
264+
private static function parseHeaderLine($ch, string $data, array &$info, array &$headers, ?array $options, \stdClass $multi, int $id, ?string &$location, ?callable $resolveRedirect, ?LoggerInterface $logger): int
253265
{
254266
if (!\in_array($waitFor = @curl_getinfo($ch, CURLINFO_PRIVATE), ['headers', 'destruct'], true)) {
255267
return \strlen($data); // Ignore HTTP trailers
@@ -306,6 +318,8 @@ private static function parseHeaderLine($ch, string $data, array &$info, array &
306318
}
307319

308320
curl_setopt($ch, CURLOPT_PRIVATE, 'content');
321+
} elseif (null !== $info['redirect_url'] && $logger) {
322+
$logger->info(sprintf('Redirecting: %s %s', $info['http_code'], $info['redirect_url']));
309323
}
310324

311325
return \strlen($data);

‎src/Symfony/Component/HttpClient/Response/NativeResponse.php

Lines changed: 11 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@
1111

1212
namespace Symfony\Component\HttpClient\Response;
1313

14+
use Psr\Log\LoggerInterface;
1415
use Symfony\Component\HttpClient\Chunk\FirstChunk;
1516
use Symfony\Component\HttpClient\Exception\TransportException;
1617
use Symfony\Contracts\HttpClient\ResponseInterface;
@@ -35,12 +36,13 @@ final class NativeResponse implements ResponseInterface
3536
/**
3637
* @internal
3738
*/
38-
public function __construct(\stdClass $multi, $context, string $url, $options, bool $gzipEnabled, array &$info, callable $resolveRedirect, ?callable $onProgress)
39+
public function __construct(\stdClass $multi, $context, string $url, $options, bool $gzipEnabled, array &$info, callable $resolveRedirect, ?callable $onProgress, ?LoggerInterface $logger)
3940
{
4041
$this->multi = $multi;
4142
$this->id = (int) $context;
4243
$this->context = $context;
4344
$this->url = $url;
45+
$this->logger = $logger;
4446
$this->timeout = $options['timeout'];
4547
$this->info = &$info;
4648
$this->resolveRedirect = $resolveRedirect;
@@ -107,13 +109,19 @@ private function open(): void
107109
$this->info['start_time'] = microtime(true);
108110
$url = $this->url;
109111

110-
do {
112+
while (true) {
111113
// Send request and follow redirects when needed
112114
$this->info['fopen_time'] = microtime(true);
113115
$this->handle = $h = fopen($url, 'r', false, $this->context);
114116
self::addResponseHeaders($http_response_header, $this->info, $this->headers);
115117
$url = ($this->resolveRedirect)($this->multi, $this->headers['location'][0] ?? null, $this->context);
116-
} while (null !== $url);
118+
119+
if (null === $url) {
120+
break;
121+
}
122+
123+
$this->logger && $this->logger->info(sprintf('Redirecting: %s %s', $this->info['http_code'], $url ?? $this->url));
124+
}
117125
} catch (\Throwable $e) {
118126
$this->close();
119127
$this->multi->handlesActivity[$this->id][] = null;

‎src/Symfony/Component/HttpClient/Response/ResponseTrait.php

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -30,6 +30,7 @@
3030
*/
3131
trait ResponseTrait
3232
{
33+
private $logger;
3334
private $headers = [];
3435

3536
/**
@@ -299,6 +300,9 @@ public static function stream(iterable $responses, float $timeout = null): \Gene
299300
} elseif ($chunk instanceof ErrorChunk) {
300301
unset($responses[$j]);
301302
$isTimeout = true;
303+
} elseif ($chunk instanceof FirstChunk && $response->logger) {
304+
$info = $response->getInfo();
305+
$response->logger->info(sprintf('Response: %s %s', $info['http_code'], $info['url']));
302306
}
303307

304308
yield $response => $chunk;

0 commit comments

Comments
 (0)
0