-
-
Notifications
You must be signed in to change notification settings - Fork 9.6k
[HttpClient] logger integration #30537
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.
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
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -11,6 +11,9 @@ | |
|
||
namespace Symfony\Component\HttpClient; | ||
|
||
use Psr\Log\LoggerAwareInterface; | ||
use Psr\Log\LoggerAwareTrait; | ||
use Psr\Log\LoggerInterface; | ||
use Symfony\Component\HttpClient\Exception\TransportException; | ||
use Symfony\Component\HttpClient\Response\CurlResponse; | ||
use Symfony\Component\HttpClient\Response\ResponseStream; | ||
|
@@ -28,20 +31,22 @@ | |
* | ||
* @experimental in 4.3 | ||
*/ | ||
final class CurlHttpClient implements HttpClientInterface | ||
final class CurlHttpClient implements HttpClientInterface, LoggerAwareInterface | ||
{ | ||
use HttpClientTrait; | ||
use LoggerAwareTrait; | ||
|
||
private $defaultOptions = self::OPTIONS_DEFAULTS; | ||
private $multi; | ||
|
||
/** | ||
* @param array $defaultOptions Default requests' options | ||
* @param int $maxHostConnections The maximum number of connections to a single host | ||
* @param int $maxPendingPushes The maximum number of pushed responses to accept in the queue | ||
* | ||
* @see HttpClientInterface::OPTIONS_DEFAULTS for available options | ||
*/ | ||
public function __construct(array $defaultOptions = [], int $maxHostConnections = 6) | ||
public function __construct(array $defaultOptions = [], int $maxHostConnections = 6, int $maxPendingPushes = 50) | ||
{ | ||
if ($defaultOptions) { | ||
[, $this->defaultOptions] = self::prepareRequest(null, null, $defaultOptions, self::OPTIONS_DEFAULTS); | ||
|
@@ -65,7 +70,7 @@ public function __construct(array $defaultOptions = [], int $maxHostConnections | |
]; | ||
|
||
// Skip configuring HTTP/2 push when it's unsupported or buggy, see https://bugs.php.net/bug.php?id=77535 | ||
if (\PHP_VERSION_ID < 70217 || (\PHP_VERSION_ID >= 70300 && \PHP_VERSION_ID < 70304)) { | ||
if (0 >= $maxPendingPushes || \PHP_VERSION_ID < 70217 || (\PHP_VERSION_ID >= 70300 && \PHP_VERSION_ID < 70304)) { | ||
return; | ||
} | ||
|
||
|
@@ -74,8 +79,10 @@ public function __construct(array $defaultOptions = [], int $maxHostConnections | |
return; | ||
} | ||
|
||
curl_multi_setopt($mh, CURLMOPT_PUSHFUNCTION, static function ($parent, $pushed, array $requestHeaders) use ($multi) { | ||
return self::handlePush($parent, $pushed, $requestHeaders, $multi); | ||
$logger = &$this->logger; | ||
|
||
curl_multi_setopt($mh, CURLMOPT_PUSHFUNCTION, static function ($parent, $pushed, array $requestHeaders) use ($multi, $maxPendingPushes, &$logger) { | ||
return self::handlePush($parent, $pushed, $requestHeaders, $multi, $maxPendingPushes, $logger); | ||
}); | ||
} | ||
|
||
|
@@ -103,13 +110,19 @@ public function request(string $method, string $url, array $options = []): Respo | |
]; | ||
|
||
if ('GET' === $method && !$options['body'] && $expectedHeaders === $pushedHeaders) { | ||
$this->logger && $this->logger->info(sprintf('Connecting request to pushed response: %s %s', $method, $url)); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
|
||
|
||
// Reinitialize the pushed response with request's options | ||
$pushedResponse->__construct($this->multi, $url, $options); | ||
$pushedResponse->__construct($this->multi, $url, $options, $this->logger); | ||
|
||
return $pushedResponse; | ||
} | ||
|
||
$this->logger && $this->logger->info(sprintf('Rejecting pushed response for "%s": authorization headers don\'t match the request', $url)); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I would move that to warning log level |
||
} | ||
|
||
$this->logger && $this->logger->info(sprintf('Request: %s %s', $method, $url)); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I would use quote around %s (to detect empty method or empty URL for exemple) |
||
|
||
$curlopts = [ | ||
CURLOPT_URL => $url, | ||
CURLOPT_USERAGENT => 'Symfony HttpClient/Curl', | ||
|
@@ -255,7 +268,7 @@ public function request(string $method, string $url, array $options = []): Respo | |
} | ||
} | ||
|
||
return new CurlResponse($this->multi, $ch, $options, $method, self::createRedirectResolver($options, $host)); | ||
return new CurlResponse($this->multi, $ch, $options, $this->logger, $method, self::createRedirectResolver($options, $host)); | ||
} | ||
|
||
/** | ||
|
@@ -282,30 +295,44 @@ public function __destruct() | |
} | ||
} | ||
|
||
private static function handlePush($parent, $pushed, array $requestHeaders, \stdClass $multi): int | ||
private static function handlePush($parent, $pushed, array $requestHeaders, \stdClass $multi, int $maxPendingPushes, ?LoggerInterface $logger): int | ||
{ | ||
$headers = []; | ||
$origin = curl_getinfo($parent, CURLINFO_EFFECTIVE_URL); | ||
|
||
foreach ($requestHeaders as $h) { | ||
if (false !== $i = strpos($h, ':', 1)) { | ||
$headers[substr($h, 0, $i)] = substr($h, 1 + $i); | ||
} | ||
} | ||
|
||
if ('GET' !== $headers[':method'] || isset($headers['range'])) { | ||
if (!isset($headers[':method']) || !isset($headers[':scheme']) || !isset($headers[':authority']) || !isset($headers[':path']) || 'GET' !== $headers[':method'] || isset($headers['range'])) { | ||
$logger && $logger->info(sprintf('Rejecting pushed response from "%s": pushed headers are invalid', $origin)); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I would move that to warning |
||
|
||
return CURL_PUSH_DENY; | ||
} | ||
|
||
$url = $headers[':scheme'].'://'.$headers[':authority']; | ||
|
||
if ($maxPendingPushes <= \count($multi->pushedResponses)) { | ||
$logger && $logger->info(sprintf('Rejecting pushed response from "%s" for "%s": the queue is full', $origin, $url)); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. warning here too |
||
|
||
return CURL_PUSH_DENY; | ||
} | ||
|
||
// curl before 7.65 doesn't validate the pushed ":authority" header, | ||
// but this is a MUST in the HTTP/2 RFC; let's restrict pushes to the original host, | ||
// ignoring domains mentioned as alt-name in the certificate for now (same as curl). | ||
if (0 !== strpos(curl_getinfo($parent, CURLINFO_EFFECTIVE_URL), $url.'/')) { | ||
if (0 !== strpos($origin, $url.'/')) { | ||
$logger && $logger->info(sprintf('Rejecting pushed response from "%s": server is not authoritative for "%s"', $origin, $url)); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. warning here too |
||
|
||
return CURL_PUSH_DENY; | ||
} | ||
|
||
$multi->pushedResponses[$url.$headers[':path']] = [ | ||
$url .= $headers[':path']; | ||
$logger && $logger->info(sprintf('Queueing pushed response: %s', $url)); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I would add quote |
||
|
||
$multi->pushedResponses[$url] = [ | ||
new CurlResponse($multi, $pushed), | ||
[ | ||
$headers['authorization'] ?? null, | ||
|
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -11,6 +11,8 @@ | |
|
||
namespace Symfony\Component\HttpClient; | ||
|
||
use Psr\Log\LoggerAwareInterface; | ||
use Psr\Log\LoggerAwareTrait; | ||
use Symfony\Component\HttpClient\Exception\TransportException; | ||
use Symfony\Component\HttpClient\Response\NativeResponse; | ||
use Symfony\Component\HttpClient\Response\ResponseStream; | ||
|
@@ -28,9 +30,10 @@ | |
* | ||
* @experimental in 4.3 | ||
*/ | ||
final class NativeHttpClient implements HttpClientInterface | ||
final class NativeHttpClient implements HttpClientInterface, LoggerAwareInterface | ||
{ | ||
use HttpClientTrait; | ||
use LoggerAwareTrait; | ||
|
||
private $defaultOptions = self::OPTIONS_DEFAULTS; | ||
private $multi; | ||
|
@@ -205,7 +208,10 @@ public function request(string $method, string $url, array $options = []): Respo | |
$context = stream_context_create($context, ['notification' => $notification]); | ||
self::configureHeadersAndProxy($context, $host, $options['request_headers'], $proxy, $noProxy); | ||
|
||
return new NativeResponse($this->multi, $context, implode('', $url), $options, $gzipEnabled, $info, $resolveRedirect, $onProgress); | ||
$url = implode('', $url); | ||
$this->logger && $this->logger->info(sprintf('Request: %s %s', $method, $url)); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I would add quote |
||
|
||
return new NativeResponse($this->multi, $context, $url, $options, $gzipEnabled, $info, $resolveRedirect, $onProgress, $this->logger); | ||
} | ||
|
||
/** | ||
|
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -11,6 +11,7 @@ | |
|
||
namespace Symfony\Component\HttpClient\Response; | ||
|
||
use Psr\Log\LoggerInterface; | ||
use Symfony\Component\HttpClient\Chunk\FirstChunk; | ||
use Symfony\Component\HttpClient\Exception\TransportException; | ||
use Symfony\Contracts\HttpClient\ResponseInterface; | ||
|
@@ -29,7 +30,7 @@ final class CurlResponse implements ResponseInterface | |
/** | ||
* @internal | ||
*/ | ||
public function __construct(\stdClass $multi, $ch, array $options = null, string $method = 'GET', callable $resolveRedirect = null) | ||
public function __construct(\stdClass $multi, $ch, array $options = null, LoggerInterface $logger = null, string $method = 'GET', callable $resolveRedirect = null) | ||
{ | ||
$this->multi = $multi; | ||
|
||
|
@@ -41,6 +42,7 @@ public function __construct(\stdClass $multi, $ch, array $options = null, string | |
} | ||
|
||
$this->id = $id = (int) $ch; | ||
$this->logger = $logger; | ||
$this->timeout = $options['timeout'] ?? null; | ||
$this->info['http_method'] = $method; | ||
$this->info['user_data'] = $options['user_data'] ?? null; | ||
|
@@ -64,8 +66,8 @@ public function __construct(\stdClass $multi, $ch, array $options = null, string | |
$content = ($options['buffer'] ?? true) ? $content : null; | ||
} | ||
|
||
curl_setopt($ch, CURLOPT_HEADERFUNCTION, static function ($ch, string $data) use (&$info, &$headers, $options, $multi, $id, &$location, $resolveRedirect): int { | ||
return self::parseHeaderLine($ch, $data, $info, $headers, $options, $multi, $id, $location, $resolveRedirect); | ||
curl_setopt($ch, CURLOPT_HEADERFUNCTION, static function ($ch, string $data) use (&$info, &$headers, $options, $multi, $id, &$location, $resolveRedirect, $logger): int { | ||
return self::parseHeaderLine($ch, $data, $info, $headers, $options, $multi, $id, $location, $resolveRedirect, $logger); | ||
}); | ||
|
||
if (null === $options) { | ||
|
@@ -103,7 +105,9 @@ public function __construct(\stdClass $multi, $ch, array $options = null, string | |
throw new TransportException($response->info['error']); | ||
} | ||
|
||
if (\in_array(curl_getinfo($ch = $response->handle, CURLINFO_PRIVATE), ['headers', 'destruct'], true)) { | ||
$waitFor = curl_getinfo($ch = $response->handle, CURLINFO_PRIVATE); | ||
|
||
if (\in_array($waitFor, ['headers', 'destruct'], true)) { | ||
try { | ||
if (\defined('CURLOPT_STREAM_WEIGHT')) { | ||
curl_setopt($ch, CURLOPT_STREAM_WEIGHT, 32); | ||
|
@@ -115,6 +119,8 @@ public function __construct(\stdClass $multi, $ch, array $options = null, string | |
$response->close(); | ||
throw $e; | ||
} | ||
} elseif ('content' === $waitFor && ($response->multi->handlesActivity[$response->id][0] ?? null) instanceof FirstChunk) { | ||
self::stream([$response])->current(); | ||
} | ||
|
||
curl_setopt($ch, CURLOPT_HEADERFUNCTION, null); | ||
|
@@ -156,8 +162,8 @@ public function getInfo(string $type = null) | |
public function __destruct() | ||
{ | ||
try { | ||
if (null === $this->timeout || isset($this->info['url'])) { | ||
return; // pushed response | ||
if (null === $this->timeout) { | ||
return; // Unused pushed response | ||
} | ||
|
||
if ('content' === $waitFor = curl_getinfo($this->handle, CURLINFO_PRIVATE)) { | ||
|
@@ -171,7 +177,13 @@ public function __destruct() | |
$this->close(); | ||
|
||
// Clear local caches when the only remaining handles are about pushed responses | ||
if (\count($this->multi->openHandles) === \count($this->multi->pushedResponses)) { | ||
if (!$this->multi->openHandles) { | ||
if ($this->logger) { | ||
foreach ($this->multi->pushedResponses as $url => $response) { | ||
$this->logger->info(sprintf('Unused pushed response: %s', $url)); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Warning and quote |
||
} | ||
} | ||
|
||
$this->multi->pushedResponses = []; | ||
// Schedule DNS cache eviction for the next request | ||
$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 | |
/** | ||
* Parses header lines as curl yields them to us. | ||
*/ | ||
private static function parseHeaderLine($ch, string $data, array &$info, array &$headers, ?array $options, \stdClass $multi, int $id, ?string &$location, ?callable $resolveRedirect): int | ||
private static function parseHeaderLine($ch, string $data, array &$info, array &$headers, ?array $options, \stdClass $multi, int $id, ?string &$location, ?callable $resolveRedirect, ?LoggerInterface $logger): int | ||
{ | ||
if (!\in_array($waitFor = @curl_getinfo($ch, CURLINFO_PRIVATE), ['headers', 'destruct'], true)) { | ||
return \strlen($data); // Ignore HTTP trailers | ||
|
@@ -306,6 +318,8 @@ private static function parseHeaderLine($ch, string $data, array &$info, array & | |
} | ||
|
||
curl_setopt($ch, CURLOPT_PRIVATE, 'content'); | ||
} elseif (null !== $info['redirect_url'] && $logger) { | ||
$logger->info(sprintf('Redirecting: %s %s', $info['http_code'], $info['redirect_url'])); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Quote |
||
} | ||
|
||
return \strlen($data); | ||
|
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -11,6 +11,7 @@ | |
|
||
namespace Symfony\Component\HttpClient\Response; | ||
|
||
use Psr\Log\LoggerInterface; | ||
use Symfony\Component\HttpClient\Chunk\FirstChunk; | ||
use Symfony\Component\HttpClient\Exception\TransportException; | ||
use Symfony\Contracts\HttpClient\ResponseInterface; | ||
|
@@ -35,12 +36,13 @@ final class NativeResponse implements ResponseInterface | |
/** | ||
* @internal | ||
*/ | ||
public function __construct(\stdClass $multi, $context, string $url, $options, bool $gzipEnabled, array &$info, callable $resolveRedirect, ?callable $onProgress) | ||
public function __construct(\stdClass $multi, $context, string $url, $options, bool $gzipEnabled, array &$info, callable $resolveRedirect, ?callable $onProgress, ?LoggerInterface $logger) | ||
{ | ||
$this->multi = $multi; | ||
$this->id = (int) $context; | ||
$this->context = $context; | ||
$this->url = $url; | ||
$this->logger = $logger; | ||
$this->timeout = $options['timeout']; | ||
$this->info = &$info; | ||
$this->resolveRedirect = $resolveRedirect; | ||
|
@@ -107,13 +109,19 @@ private function open(): void | |
$this->info['start_time'] = microtime(true); | ||
$url = $this->url; | ||
|
||
do { | ||
while (true) { | ||
// Send request and follow redirects when needed | ||
$this->info['fopen_time'] = microtime(true); | ||
$this->handle = $h = fopen($url, 'r', false, $this->context); | ||
self::addResponseHeaders($http_response_header, $this->info, $this->headers); | ||
$url = ($this->resolveRedirect)($this->multi, $this->headers['location'][0] ?? null, $this->context); | ||
} while (null !== $url); | ||
|
||
if (null === $url) { | ||
break; | ||
} | ||
|
||
$this->logger && $this->logger->info(sprintf('Redirecting: %s %s', $this->info['http_code'], $url ?? $this->url)); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Quote |
||
} | ||
} catch (\Throwable $e) { | ||
$this->close(); | ||
$this->multi->handlesActivity[$this->id][] = null; | ||
|
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -30,6 +30,7 @@ | |
*/ | ||
trait ResponseTrait | ||
{ | ||
private $logger; | ||
private $headers = []; | ||
|
||
/** | ||
|
@@ -299,6 +300,9 @@ public static function stream(iterable $responses, float $timeout = null): \Gene | |
} elseif ($chunk instanceof ErrorChunk) { | ||
unset($responses[$j]); | ||
$isTimeout = true; | ||
} elseif ($chunk instanceof FirstChunk && $response->logger) { | ||
$info = $response->getInfo(); | ||
$response->logger->info(sprintf('Response: %s %s', $info['http_code'], $info['url'])); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Quote |
||
} | ||
|
||
yield $response => $chunk; | ||
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.