diogo/symfony
Archived
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

feature #30537 [HttpClient] logger integration (antonch1989, nicolas-grekas)

Browse Source 
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
-------

26d15c8bbe [HttpClient] log requests, responses and pushes when they happen
fc6ba7efad [HttpClient] logger integration
This commit is contained in:
Fabien Potencier 2019-04-05 14:49:12 +02:00
commit 09e8d74627
10 changed files with 144 additions and 38 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
src/Symfony/Bundle/FrameworkBundle/Resources/config/http_client.xml
View File

@ -6,9 +6,13 @@
<services>
<service id="http_client" class="Symfony\Contracts\HttpClient\HttpClientInterface">
<tag name="monolog.logger" channel="http_client" />
<factory class="Symfony\Component\HttpClient\HttpClient" method="create" />
<argument type="collection" /> <!-- default options -->
<argument /> <!-- max host connections -->
<call method="setLogger">
<argument type="service" id="logger" on-invalid="ignore" />
</call>
</service>
<service id="Symfony\Contracts\HttpClient\HttpClientInterface" alias="http_client" />

55
src/Symfony/Component/HttpClient/CurlHttpClient.php
View File

@ -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,9 +31,10 @@ use Symfony\Contracts\HttpClient\ResponseStreamInterface;
*
* @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;
@ -38,10 +42,11 @@ final class CurlHttpClient implements HttpClientInterface
/**
* @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 @@ final class CurlHttpClient implements HttpClientInterface
];
// 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 @@ final class CurlHttpClient implements HttpClientInterface
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 @@ final class CurlHttpClient implements HttpClientInterface
];
if ('GET' === $method && !$options['body'] && $expectedHeaders === $pushedHeaders) {
$this->logger && $this->logger->info(sprintf('Connecting request to pushed response: %s %s', $method, $url));
// 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));
}
$this->logger && $this->logger->info(sprintf('Request: %s %s', $method, $url));
$curlopts = [
CURLOPT_URL => $url,
CURLOPT_USERAGENT => 'Symfony HttpClient/Curl',
@ -255,7 +268,7 @@ final class CurlHttpClient implements HttpClientInterface
}
}
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,9 +295,10 @@ final class CurlHttpClient implements HttpClientInterface
}
}
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)) {
@ -292,20 +306,33 @@ final class CurlHttpClient implements HttpClientInterface
}
}
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));
return CURL_PUSH_DENY;
}
$url = $headers[':scheme'].'://'.$headers[':authority'];
// 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 ($maxPendingPushes <= \count($multi->pushedResponses)) {
$logger && $logger->info(sprintf('Rejecting pushed response from "%s" for "%s": the queue is full', $origin, $url));
return CURL_PUSH_DENY;
}
$multi->pushedResponses[$url.$headers[':path']] = [
// 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($origin, $url.'/')) {
$logger && $logger->info(sprintf('Rejecting pushed response from "%s": server is not authoritative for "%s"', $origin, $url));
return CURL_PUSH_DENY;
}
$url .= $headers[':path'];
$logger && $logger->info(sprintf('Queueing pushed response: %s', $url));
$multi->pushedResponses[$url] = [
new CurlResponse($multi, $pushed),
[
$headers['authorization'] ?? null,

5
src/Symfony/Component/HttpClient/HttpClient.php
View File

@ -25,13 +25,14 @@ final class HttpClient
/**
* @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 static function create(array $defaultOptions = [], int $maxHostConnections = 6): HttpClientInterface
public static function create(array $defaultOptions = [], int $maxHostConnections = 6, int $maxPendingPushes = 50): HttpClientInterface
{
if (\extension_loaded('curl')) {
return new CurlHttpClient($defaultOptions, $maxHostConnections);
return new CurlHttpClient($defaultOptions, $maxHostConnections, $maxPendingPushes);
}
return new NativeHttpClient($defaultOptions, $maxHostConnections);

10
src/Symfony/Component/HttpClient/NativeHttpClient.php
View File

@ -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 @@ use Symfony\Contracts\HttpClient\ResponseStreamInterface;
*
* @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 @@ final class NativeHttpClient implements HttpClientInterface
$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));
return new NativeResponse($this->multi, $context, $url, $options, $gzipEnabled, $info, $resolveRedirect, $onProgress, $this->logger);
}
/**

30
src/Symfony/Component/HttpClient/Response/CurlResponse.php
View File

@ -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 @@ final class CurlResponse implements ResponseInterface
}
$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 @@ final class CurlResponse implements ResponseInterface
$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 @@ final class CurlResponse implements ResponseInterface
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 @@ final class CurlResponse implements ResponseInterface
$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 @@ final class CurlResponse implements ResponseInterface
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 @@ final class CurlResponse implements ResponseInterface
$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));
}
}
$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 @@ final class CurlResponse implements ResponseInterface
/**
* 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 @@ final class CurlResponse implements ResponseInterface
}
curl_setopt($ch, CURLOPT_PRIVATE, 'content');
} elseif (null !== $info['redirect_url'] && $logger) {
$logger->info(sprintf('Redirecting: %s %s', $info['http_code'], $info['redirect_url']));
}
return \strlen($data);

14
src/Symfony/Component/HttpClient/Response/NativeResponse.php
View File

@ -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 @@ final class NativeResponse implements ResponseInterface
$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));
}
} catch (\Throwable $e) {
$this->close();
$this->multi->handlesActivity[$this->id][] = null;

4
src/Symfony/Component/HttpClient/Response/ResponseTrait.php
View File

@ -30,6 +30,7 @@ use Symfony\Component\HttpClient\Exception\TransportException;
*/
trait ResponseTrait
{
private $logger;
private $headers = [];
/**
@ -299,6 +300,9 @@ trait ResponseTrait
} 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']));
}
yield $response => $chunk;

49
src/Symfony/Component/HttpClient/Tests/CurlHttpClientTest.php
View File

@ -11,6 +11,7 @@
namespace Symfony\Component\HttpClient\Tests;
use Psr\Log\AbstractLogger;
use Symfony\Component\HttpClient\CurlHttpClient;
use Symfony\Contracts\HttpClient\HttpClientInterface;
use Symfony\Contracts\HttpClient\Test\HttpClientTestCase;
@ -24,4 +25,52 @@ class CurlHttpClientTest extends HttpClientTestCase
{
return new CurlHttpClient();
}
/**
* @requires PHP 7.2.17
* @requires extension curl 7.61
*/
public function testHttp2Push()
{
if (\PHP_VERSION_ID >= 70300 && \PHP_VERSION_ID < 70304) {
$this->markTestSkipped('PHP 7.3.0 to 7.3.3 don\'t support HTTP/2 PUSH');
}
if (!\defined('CURLMOPT_PUSHFUNCTION') || !(CURL_VERSION_HTTP2 & curl_version()['features'])) {
$this->markTestSkipped('curl is not compiled with support for HTTP/2 PUSH');
}
$logger = new class() extends AbstractLogger {
public $logs = [];
public function log($level, $message, array $context = [])
{
$this->logs[] = $message;
}
};
$client = new CurlHttpClient();
$client->setLogger($logger);
$index = $client->request('GET', 'https://http2-push.io');
$index->getContent();
$css = $client->request('GET', 'https://http2-push.io/css/style.css');
$js = $client->request('GET', 'https://http2-push.io/js/http2-push.js');
$css->getHeaders();
$js->getHeaders();
$expected = [
'Request: GET https://http2-push.io/',
'Queueing pushed response: https://http2-push.io/css/style.css',
'Queueing pushed response: https://http2-push.io/js/http2-push.js',
'Response: 200 https://http2-push.io/',
'Connecting request to pushed response: GET https://http2-push.io/css/style.css',
'Connecting request to pushed response: GET https://http2-push.io/js/http2-push.js',
'Response: 200 https://http2-push.io/css/style.css',
'Response: 200 https://http2-push.io/js/http2-push.js',
];
$this->assertSame($expected, $logger->logs);
}
}

1
src/Symfony/Component/HttpClient/composer.json
View File

@ -20,6 +20,7 @@
},
"require": {
"php": "^7.1.3",
"psr/log": "^1.0",
"symfony/contracts": "^1.1",
"symfony/polyfill-php73": "^1.11"
},

10
src/Symfony/Component/HttpKernel/HttpClientKernel.php
View File

@ -11,8 +11,6 @@
namespace Symfony\Component\HttpKernel;
use Psr\Log\LoggerInterface;
use Psr\Log\NullLogger;
use Symfony\Component\HttpClient\HttpClient;
use Symfony\Component\HttpFoundation\Request;
use Symfony\Component\HttpFoundation\Response;
@ -31,22 +29,18 @@ use Symfony\Contracts\HttpClient\HttpClientInterface;
final class HttpClientKernel implements HttpKernelInterface
{
private $client;
private $logger;
public function __construct(HttpClientInterface $client = null, LoggerInterface $logger = null)
public function __construct(HttpClientInterface $client = null)
{
if (!class_exists(HttpClient::class)) {
throw new \LogicException(sprintf('You cannot use "%s" as the HttpClient component is not installed. Try running "composer require symfony/http-client".', __CLASS__));
}
$this->client = $client ?? HttpClient::create();
$this->logger = $logger ?? new NullLogger();
}
public function handle(Request $request, $type = HttpKernelInterface::MASTER_REQUEST, $catch = true)
{
$this->logger->debug(sprintf('Request: %s %s', $request->getMethod(), $request->getUri()));
$headers = $this->getHeaders($request);
$body = '';
if (null !== $part = $this->getBody($request)) {
@ -59,8 +53,6 @@ final class HttpClientKernel implements HttpKernelInterface
'max_redirects' => 0,
] + $request->attributes->get('http_client_options', []));
$this->logger->debug(sprintf('Response: %s %s', $response->getStatusCode(), $request->getUri()));
$response = new Response($response->getContent(!$catch), $response->getStatusCode(), $response->getHeaders(!$catch));
$response->headers = new class($response->headers->all()) extends ResponseHeaderBag {