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

This commit is contained in:
Nicolas Grekas 2019-05-27 20:15:39 +02:00 committed by Fabien Potencier
parent cfeb5bee07
commit 1214609b37
4 changed files with 57 additions and 6 deletions

View File

@ -108,6 +108,7 @@ final class NativeHttpClient implements HttpClientInterface, LoggerAwareInterfac
'size_body' => \strlen($options['body']), 'size_body' => \strlen($options['body']),
'primary_ip' => '', 'primary_ip' => '',
'primary_port' => 'http:' === $url['scheme'] ? 80 : 443, 'primary_port' => 'http:' === $url['scheme'] ? 80 : 443,
'debug' => \extension_loaded('curl') ? '' : "* Enable the curl extension for better performance\n",
]; ];
if ($onProgress = $options['on_progress']) { if ($onProgress = $options['on_progress']) {
@ -139,6 +140,8 @@ final class NativeHttpClient implements HttpClientInterface, LoggerAwareInterfac
$info['size_download'] = $dlNow; $info['size_download'] = $dlNow;
} elseif (STREAM_NOTIFY_CONNECT === $code) { } elseif (STREAM_NOTIFY_CONNECT === $code) {
$info['connect_time'] += $now - $info['fopen_time']; $info['connect_time'] += $now - $info['fopen_time'];
$info['debug'] .= $info['request_header'];
unset($info['request_header']);
} else { } else {
return; return;
} }
@ -160,13 +163,16 @@ final class NativeHttpClient implements HttpClientInterface, LoggerAwareInterfac
$options['request_headers'][] = 'host: '.$host.$port; $options['request_headers'][] = 'host: '.$host.$port;
} }
if (!isset($options['headers']['user-agent'])) {
$options['request_headers'][] = 'user-agent: Symfony HttpClient/Native';
}
$context = [ $context = [
'http' => [ 'http' => [
'protocol_version' => $options['http_version'] ?: '1.1', 'protocol_version' => $options['http_version'] ?: '1.1',
'method' => $method, 'method' => $method,
'content' => $options['body'], 'content' => $options['body'],
'ignore_errors' => true, 'ignore_errors' => true,
'user_agent' => 'Symfony HttpClient/Native',
'curl_verify_ssl_peer' => $options['verify_peer'], 'curl_verify_ssl_peer' => $options['verify_peer'],
'curl_verify_ssl_host' => $options['verify_host'], 'curl_verify_ssl_host' => $options['verify_host'],
'auto_decode' => false, // Disable dechunk filter, it's incompatible with stream_select() 'auto_decode' => false, // Disable dechunk filter, it's incompatible with stream_select()
@ -296,6 +302,7 @@ final class NativeHttpClient implements HttpClientInterface, LoggerAwareInterfac
$host = parse_url($url['authority'], PHP_URL_HOST); $host = parse_url($url['authority'], PHP_URL_HOST);
if (null === $ip = $multi->dnsCache[$host] ?? null) { if (null === $ip = $multi->dnsCache[$host] ?? null) {
$info['debug'] .= "* Hostname was NOT found in DNS cache\n";
$now = microtime(true); $now = microtime(true);
if (!$ip = gethostbynamel($host)) { if (!$ip = gethostbynamel($host)) {
@ -304,6 +311,9 @@ final class NativeHttpClient implements HttpClientInterface, LoggerAwareInterfac
$info['namelookup_time'] += microtime(true) - $now; $info['namelookup_time'] += microtime(true) - $now;
$multi->dnsCache[$host] = $ip = $ip[0]; $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; $info['primary_ip'] = $ip;

View File

@ -28,6 +28,7 @@ final class CurlResponse implements ResponseInterface
private static $performing = false; private static $performing = false;
private $multi; private $multi;
private $debugBuffer;
/** /**
* @internal * @internal
@ -38,6 +39,9 @@ final class CurlResponse implements ResponseInterface
if (\is_resource($ch)) { if (\is_resource($ch)) {
$this->handle = $ch; $this->handle = $ch;
$this->debugBuffer = fopen('php://temp', 'w+');
curl_setopt($ch, CURLOPT_VERBOSE, true);
curl_setopt($ch, CURLOPT_STDERR, $this->debugBuffer);
} else { } else {
$this->info['url'] = $ch; $this->info['url'] = $ch;
$ch = $this->handle; $ch = $this->handle;
@ -143,6 +147,13 @@ final class CurlResponse implements ResponseInterface
{ {
if (!$info = $this->finalInfo) { if (!$info = $this->finalInfo) {
self::perform($this->multi); 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 = array_merge($this->info, curl_getinfo($this->handle));
$info['url'] = $this->info['url'] ?? $info['url']; $info['url'] = $this->info['url'] ?? $info['url'];
$info['redirect_url'] = $this->info['redirect_url'] ?? null; $info['redirect_url'] = $this->info['redirect_url'] ?? null;
@ -154,6 +165,10 @@ final class CurlResponse implements ResponseInterface
} }
if (!\in_array(curl_getinfo($this->handle, CURLINFO_PRIVATE), ['headers', 'content'], true)) { 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; $this->finalInfo = $info;
} }
} }

View File

@ -34,6 +34,7 @@ final class NativeResponse implements ResponseInterface
private $buffer; private $buffer;
private $inflate; private $inflate;
private $multi; private $multi;
private $debugBuffer;
/** /**
* @internal * @internal
@ -76,12 +77,19 @@ final class NativeResponse implements ResponseInterface
{ {
if (!$info = $this->finalInfo) { if (!$info = $this->finalInfo) {
self::perform($this->multi); self::perform($this->multi);
if ('debug' === $type) {
return $this->info['debug'];
}
$info = $this->info; $info = $this->info;
$info['url'] = implode('', $info['url']); $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) { if (null === $this->buffer) {
$this->finalInfo = $info; $this->finalInfo = $info;
} else {
unset($info['debug']);
} }
} }
@ -112,10 +120,23 @@ final class NativeResponse implements ResponseInterface
$url = $this->url; $url = $this->url;
while (true) { 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 // Send request and follow redirects when needed
$this->info['fopen_time'] = microtime(true); $this->info['fopen_time'] = microtime(true);
$this->handle = $h = fopen($url, 'r', false, $this->context); $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); $url = ($this->resolveRedirect)($this->multi, $this->headers['location'][0] ?? null, $this->context);
if (null === $url) { if (null === $url) {
@ -136,7 +157,6 @@ final class NativeResponse implements ResponseInterface
} }
stream_set_blocking($h, false); stream_set_blocking($h, false);
$context = stream_context_get_options($this->context);
$this->context = $this->resolveRedirect = null; $this->context = $this->resolveRedirect = null;
if (isset($context['ssl']['peer_certificate_chain'])) { if (isset($context['ssl']['peer_certificate_chain'])) {

View File

@ -189,19 +189,25 @@ trait ResponseTrait
*/ */
abstract protected static function select(ClientState $multi, float $timeout): int; 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) { foreach ($responseHeaders as $h) {
if (11 <= \strlen($h) && '/' === $h[4] && preg_match('#^HTTP/\d+(?:\.\d+)? ([12345]\d\d) .*#', $h, $m)) { 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]; $info['http_code'] = (int) $m[1];
} elseif (2 === \count($m = explode(':', $h, 2))) { } elseif (2 === \count($m = explode(':', $h, 2))) {
$headers[strtolower($m[0])][] = ltrim($m[1]); $headers[strtolower($m[0])][] = ltrim($m[1]);
} }
$debug .= "< {$h}\r\n";
$info['response_headers'][] = $h; $info['response_headers'][] = $h;
} }
$debug .= "< \r\n";
if (!$info['http_code']) { if (!$info['http_code']) {
throw new TransportException('Invalid or missing HTTP status line.'); throw new TransportException('Invalid or missing HTTP status line.');
} }