Skip to content

[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

Merged
merged 2 commits into from
Apr 5, 2019
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -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" />

Expand Down
49 changes: 38 additions & 11 deletions src/Symfony/Component/HttpClient/CurlHttpClient.php
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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);
Expand All @@ -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;
}

Expand All @@ -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;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

  1. Why do you use a reference here ?
  2. There is no need to create a logger variable here since we can use $this in a close since PHP 5.5 IIRC)


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);
});
}

Expand Down Expand Up @@ -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));
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

  1. I would use quote around %s (to detect empty method or empty URL for exemple)
  2. I would move this to debug log level


// 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));
Copy link
Member

Choose a reason for hiding this comment

The 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));
Copy link
Member

Choose a reason for hiding this comment

The 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',
Expand Down Expand Up @@ -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));
}

/**
Expand All @@ -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));
Copy link
Member

Choose a reason for hiding this comment

The 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));
Copy link
Member

Choose a reason for hiding this comment

The 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));
Copy link
Member

Choose a reason for hiding this comment

The 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));
Copy link
Member

Choose a reason for hiding this comment

The 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,
Expand Down
5 changes: 3 additions & 2 deletions src/Symfony/Component/HttpClient/HttpClient.php
Original file line number Diff line number Diff line change
Expand Up @@ -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);
Expand Down
10 changes: 8 additions & 2 deletions src/Symfony/Component/HttpClient/NativeHttpClient.php
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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;
Expand Down Expand Up @@ -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));
Copy link
Member

Choose a reason for hiding this comment

The 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);
}

/**
Expand Down
30 changes: 22 additions & 8 deletions src/Symfony/Component/HttpClient/Response/CurlResponse.php
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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;

Expand All @@ -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;
Expand All @@ -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) {
Expand Down Expand Up @@ -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);
Expand All @@ -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);
Expand Down Expand Up @@ -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)) {
Expand All @@ -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));
Copy link
Member

Choose a reason for hiding this comment

The 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];
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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']));
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Quote

}

return \strlen($data);
Expand Down
14 changes: 11 additions & 3 deletions src/Symfony/Component/HttpClient/Response/NativeResponse.php
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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;
Expand Down Expand Up @@ -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));
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Quote

}
} catch (\Throwable $e) {
$this->close();
$this->multi->handlesActivity[$this->id][] = null;
Expand Down
4 changes: 4 additions & 0 deletions src/Symfony/Component/HttpClient/Response/ResponseTrait.php
Original file line number Diff line number Diff line change
Expand Up @@ -30,6 +30,7 @@
*/
trait ResponseTrait
{
private $logger;
private $headers = [];

/**
Expand Down Expand Up @@ -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']));
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Quote

}

yield $response => $chunk;
Expand Down
Loading