Skip to content

Commit

Permalink
Browse files Browse the repository at this point in the history
feature #31641 [HttpClient] make $response->getInfo('debug') return e…
…xtended logs about the HTTP transaction (nicolas-grekas)

This PR was submitted for the master branch but it was merged into the 4.3 branch instead (closes #31641).

Discussion
----------

[HttpClient] make $response->getInfo('debug') return extended logs about the HTTP transaction

| Q             | A
| ------------- | ---
| Branch?       | master
| Bug fix?      | no
| New feature?  | yes
| BC breaks?    | no
| Deprecations? | no
| Tests pass?   | yes
| Fixed tickets | -
| License       | MIT
| Doc PR        | -

This maps the `CURLOPT_VERBOSE` mode of curl to the `debug` info and emulates it when using `NativeHttpClient`.

For example:
```
* Found bundle for host http2-push.io: 0x56193881ae40 [can multiplex]\n
* Re-using existing connection! (#0) with host http2-push.io\n
* Connected to http2-push.io (216.239.38.21) port 443 (#0)\n
* Using Stream ID: 3 (easy handle 0x5619388fcd50)\n
> GET /css/style.css HTTP/2\r\n
Host: http2-push.io\r\n
User-Agent: Symfony HttpClient/Curl\r\n
Accept-Encoding: deflate, gzip\r\n
\r\n
< HTTP/2 200 \r\n
< date: Mon, 27 May 2019 18:23:23 GMT\r\n
< expires: Mon, 27 May 2019 18:33:23 GMT\r\n
< etag: "0CqJow"\r\n
< x-cloud-trace-context: 543375291bd3b71b67fe389260ad1fbd;o=1\r\n
< content-type: text/css\r\n
< content-encoding: gzip\r\n
< server: Google Frontend\r\n
< content-length: 1805\r\n
< cache-control: public, max-age=600\r\n
< age: 0\r\n
< \r\n
* Connection #0 to host http2-push.io left intact\n
```

Commits
-------

1214609 [HttpClient] make $response->getInfo('debug') return extended logs about the HTTP transaction
  • Loading branch information
fabpot committed May 28, 2019
2 parents cfeb5be + 1214609 commit 94f38d0
Show file tree
Hide file tree
Showing 4 changed files with 57 additions and 6 deletions.
12 changes: 11 additions & 1 deletion src/Symfony/Component/HttpClient/NativeHttpClient.php
Expand Up @@ -108,6 +108,7 @@ public function request(string $method, string $url, array $options = []): Respo
'size_body' => \strlen($options['body']),
'primary_ip' => '',
'primary_port' => 'http:' === $url['scheme'] ? 80 : 443,
'debug' => \extension_loaded('curl') ? '' : "* Enable the curl extension for better performance\n",
];

if ($onProgress = $options['on_progress']) {
Expand Down Expand Up @@ -139,6 +140,8 @@ public function request(string $method, string $url, array $options = []): Respo
$info['size_download'] = $dlNow;
} elseif (STREAM_NOTIFY_CONNECT === $code) {
$info['connect_time'] += $now - $info['fopen_time'];
$info['debug'] .= $info['request_header'];
unset($info['request_header']);
} else {
return;
}
Expand All @@ -160,13 +163,16 @@ public function request(string $method, string $url, array $options = []): Respo
$options['request_headers'][] = 'host: '.$host.$port;
}

if (!isset($options['headers']['user-agent'])) {
$options['request_headers'][] = 'user-agent: Symfony HttpClient/Native';
}

$context = [
'http' => [
'protocol_version' => $options['http_version'] ?: '1.1',
'method' => $method,
'content' => $options['body'],
'ignore_errors' => true,
'user_agent' => 'Symfony HttpClient/Native',
'curl_verify_ssl_peer' => $options['verify_peer'],
'curl_verify_ssl_host' => $options['verify_host'],
'auto_decode' => false, // Disable dechunk filter, it's incompatible with stream_select()
Expand Down Expand Up @@ -296,6 +302,7 @@ private static function dnsResolve(array $url, NativeClientState $multi, array &
$host = parse_url($url['authority'], PHP_URL_HOST);

if (null === $ip = $multi->dnsCache[$host] ?? null) {
$info['debug'] .= "* Hostname was NOT found in DNS cache\n";
$now = microtime(true);

if (!$ip = gethostbynamel($host)) {
Expand All @@ -304,6 +311,9 @@ private static function dnsResolve(array $url, NativeClientState $multi, array &

$info['namelookup_time'] += microtime(true) - $now;
$multi->dnsCache[$host] = $ip = $ip[0];
$info['debug'] .= "* Added {$host}:0:{$ip} to DNS cache\n";
} else {
$info['debug'] .= "* Hostname was found in DNS cache\n";
}

$info['primary_ip'] = $ip;
Expand Down
15 changes: 15 additions & 0 deletions src/Symfony/Component/HttpClient/Response/CurlResponse.php
Expand Up @@ -28,6 +28,7 @@ final class CurlResponse implements ResponseInterface

private static $performing = false;
private $multi;
private $debugBuffer;

/**
* @internal
Expand All @@ -38,6 +39,9 @@ public function __construct(CurlClientState $multi, $ch, array $options = null,

if (\is_resource($ch)) {
$this->handle = $ch;
$this->debugBuffer = fopen('php://temp', 'w+');
curl_setopt($ch, CURLOPT_VERBOSE, true);
curl_setopt($ch, CURLOPT_STDERR, $this->debugBuffer);
} else {
$this->info['url'] = $ch;
$ch = $this->handle;
Expand Down Expand Up @@ -143,6 +147,13 @@ public function getInfo(string $type = null)
{
if (!$info = $this->finalInfo) {
self::perform($this->multi);

if ('debug' === $type) {
rewind($this->debugBuffer);

return stream_get_contents($this->debugBuffer);
}

$info = array_merge($this->info, curl_getinfo($this->handle));
$info['url'] = $this->info['url'] ?? $info['url'];
$info['redirect_url'] = $this->info['redirect_url'] ?? null;
Expand All @@ -154,6 +165,10 @@ public function getInfo(string $type = null)
}

if (!\in_array(curl_getinfo($this->handle, CURLINFO_PRIVATE), ['headers', 'content'], true)) {
rewind($this->debugBuffer);
$info['debug'] = stream_get_contents($this->debugBuffer);
fclose($this->debugBuffer);
$this->debugBuffer = null;
$this->finalInfo = $info;
}
}
Expand Down
26 changes: 23 additions & 3 deletions src/Symfony/Component/HttpClient/Response/NativeResponse.php
Expand Up @@ -34,6 +34,7 @@ final class NativeResponse implements ResponseInterface
private $buffer;
private $inflate;
private $multi;
private $debugBuffer;

/**
* @internal
Expand Down Expand Up @@ -76,12 +77,19 @@ public function getInfo(string $type = null)
{
if (!$info = $this->finalInfo) {
self::perform($this->multi);

if ('debug' === $type) {
return $this->info['debug'];
}

$info = $this->info;
$info['url'] = implode('', $info['url']);
unset($info['fopen_time'], $info['size_body']);
unset($info['fopen_time'], $info['size_body'], $info['request_header']);

if (null === $this->buffer) {
$this->finalInfo = $info;
} else {
unset($info['debug']);
}
}

Expand Down Expand Up @@ -112,10 +120,23 @@ private function open(): void
$url = $this->url;

while (true) {
$context = stream_context_get_options($this->context);

if ($proxy = $context['http']['proxy'] ?? null) {
$this->info['debug'] .= "* Establish HTTP proxy tunnel to {$proxy}\n";
$this->info['request_header'] = $url;
} else {
$this->info['debug'] .= "* Trying {$this->info['primary_ip']}...\n";
$this->info['request_header'] = $this->info['url']['path'].$this->info['url']['query'];
}

$this->info['request_header'] = sprintf("> %s %s HTTP/%s \r\n", $context['http']['method'], $this->info['request_header'], $context['http']['protocol_version']);
$this->info['request_header'] .= implode("\r\n", $context['http']['header'])."\r\n\r\n";

// 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);
self::addResponseHeaders($http_response_header, $this->info, $this->headers, $this->info['debug']);
$url = ($this->resolveRedirect)($this->multi, $this->headers['location'][0] ?? null, $this->context);

if (null === $url) {
Expand All @@ -136,7 +157,6 @@ private function open(): void
}

stream_set_blocking($h, false);
$context = stream_context_get_options($this->context);
$this->context = $this->resolveRedirect = null;

if (isset($context['ssl']['peer_certificate_chain'])) {
Expand Down
10 changes: 8 additions & 2 deletions src/Symfony/Component/HttpClient/Response/ResponseTrait.php
Expand Up @@ -189,19 +189,25 @@ abstract protected static function perform(ClientState $multi, array &$responses
*/
abstract protected static function select(ClientState $multi, float $timeout): int;

private static function addResponseHeaders(array $responseHeaders, array &$info, array &$headers): void
private static function addResponseHeaders(array $responseHeaders, array &$info, array &$headers, string &$debug = ''): void
{
foreach ($responseHeaders as $h) {
if (11 <= \strlen($h) && '/' === $h[4] && preg_match('#^HTTP/\d+(?:\.\d+)? ([12345]\d\d) .*#', $h, $m)) {
$headers = [];
if ($headers) {
$debug .= "< \r\n";
$headers = [];
}
$info['http_code'] = (int) $m[1];
} elseif (2 === \count($m = explode(':', $h, 2))) {
$headers[strtolower($m[0])][] = ltrim($m[1]);
}

$debug .= "< {$h}\r\n";
$info['response_headers'][] = $h;
}

$debug .= "< \r\n";

if (!$info['http_code']) {
throw new TransportException('Invalid or missing HTTP status line.');
}
Expand Down

0 comments on commit 94f38d0

Please sign in to comment.