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

Author: Kyra Farrow

NativeHttpClient.php

@@ -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']) {
@@ -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;
             }
@@ -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()
@@ -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)) {
@@ -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;

Response/CurlResponse.php

@@ -28,6 +28,7 @@ final class CurlResponse implements ResponseInterface
 
     private static $performing = false;
     private $multi;
+    private $debugBuffer;
 
     /**
      * @internal
@@ -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;
@@ -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;
@@ -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;
             }
         }

Response/NativeResponse.php

@@ -34,6 +34,7 @@ final class NativeResponse implements ResponseInterface
     private $buffer;
     private $inflate;
     private $multi;
+    private $debugBuffer;
 
     /**
      * @internal
@@ -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']);
             }
         }
 
@@ -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) {
@@ -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'])) {

Response/ResponseTrait.php

@@ -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.');
         }