Move TLS logging from _ScrapyClientTLSOptions to handlers. (#7387)

* Move TLS logging from _ScrapyClientTLSOptions to handlers.

* Update the docs.

* Fix typing.

* Update new docs.

* Add the comment back.

docs/topics/settings.rst

@@ -1095,12 +1095,6 @@ when making a request and abort the request if the verification fails.
     certificate problems are logged when this setting is set to ``False``)
     depends on its implementation.
 
-.. warning::
-    Enabling this setting disables handling of
-    :setting:`DOWNLOADER_CLIENT_TLS_VERBOSE_LOGGING` in
-    :class:`~scrapy.core.downloader.handlers.http11.HTTP11DownloadHandler` and
-    :class:`~scrapy.core.downloader.handlers.http2.H2DownloadHandler`.
-
 .. setting:: DUPEFILTER_CLASS
 
 DUPEFILTER_CLASS

scrapy/core/downloader/contextfactory.py

@@ -57,7 +57,7 @@ class ScrapyClientContextFactory(BrowserLikePolicyForHTTPS):
     ):
         super().__init__(*args, **kwargs)  # type: ignore[no-untyped-call]
         self._ssl_method: int = method
-        self.tls_verbose_logging: bool = tls_verbose_logging
+        self.tls_verbose_logging: bool = tls_verbose_logging  # unused
         self.tls_ciphers: AcceptableCiphers
         if tls_ciphers:
             self.tls_ciphers = AcceptableCiphers.fromOpenSSLCipherString(tls_ciphers)
@@ -134,15 +134,8 @@ class ScrapyClientContextFactory(BrowserLikePolicyForHTTPS):
 
     def creatorForNetloc(self, hostname: bytes, port: int) -> ClientTLSOptions:
         if not self._verify_certificates:
-            return _ScrapyClientTLSOptions(
+            return _ScrapyClientTLSOptions(hostname.decode("ascii"), self._ctx)  # type: ignore[no-untyped-call]
-                hostname.decode("ascii"),
+        # Note that this doesn't use self._ctx
-                self._ctx,
-                verbose_logging=self.tls_verbose_logging,
-            )
-        # this matches the behavior of BrowserLikeContextFactory in that it
-        # only uses self._ssl_method and doesn't support TLS logging or other
-        # features of ScrapyClientContextFactory, however it additionally
-        # supports self.tls_ciphers
         return optionsForClientTLS(
             hostname=hostname.decode("ascii"),
             extraCertificateOptions={

scrapy/core/downloader/handlers/_httpx.py

@@ -92,9 +92,6 @@ class HttpxDownloadHandler(BaseHttpDownloadHandler):
         logger.warning(
             "HttpxDownloadHandler is experimental and is not recommented for production use."
         )
-        self._tls_verbose_logging: bool = self.crawler.settings.getbool(
-            "DOWNLOADER_CLIENT_TLS_VERBOSE_LOGGING"
-        )
         bind_address = crawler.settings.get("DOWNLOAD_BIND_ADDRESS")
         bind_address = normalize_bind_address(bind_address)
 

scrapy/core/downloader/handlers/http11.py

@@ -53,6 +53,7 @@ from scrapy.utils.defer import maybe_deferred_to_future
 from scrapy.utils.deprecate import warn_on_deprecated_spider_attribute
 from scrapy.utils.httpobj import urlparse_cached
 from scrapy.utils.python import to_bytes, to_unicode
+from scrapy.utils.ssl import _log_ssl_conn_debug_info
 from scrapy.utils.url import add_http_if_no_scheme
 
 if TYPE_CHECKING:
@@ -121,6 +122,7 @@ class HTTP11DownloadHandler(BaseHttpDownloadHandler):
             ),
             fail_on_dataloss=self._fail_on_dataloss,
             crawler=self._crawler,
+            tls_verbose_logging=self._tls_verbose_logging,
         )
         try:
             with wrap_twisted_exceptions():
@@ -391,6 +393,7 @@ class ScrapyAgent:
         warnsize: int = 0,
         fail_on_dataloss: bool = True,
         crawler: Crawler,
+        tls_verbose_logging: bool = False,
     ):
         self._contextFactory: IPolicyForHTTPS = contextFactory
         self._connectTimeout: float = connectTimeout
@@ -401,6 +404,7 @@ class ScrapyAgent:
         self._fail_on_dataloss: bool = fail_on_dataloss
         self._txresponse: TxResponse | None = None
         self._crawler: Crawler = crawler
+        self._tls_verbose_logging: bool = tls_verbose_logging
 
     def _get_agent(self, request: Request, timeout: float) -> Agent:
         from twisted.internet import reactor
@@ -557,6 +561,7 @@ class ScrapyAgent:
                 warnsize=warnsize,
                 fail_on_dataloss=fail_on_dataloss,
                 crawler=self._crawler,
+                tls_verbose_logging=self._tls_verbose_logging,
             )
         )
 
@@ -612,6 +617,8 @@ class _ResponseReader(Protocol):
         warnsize: int,
         fail_on_dataloss: bool,
         crawler: Crawler,
+        *,
+        tls_verbose_logging: bool = False,
     ):
         self._finished: Deferred[_ResultT] = finished
         self._txresponse: TxResponse = txresponse
@@ -625,6 +632,7 @@ class _ResponseReader(Protocol):
         self._certificate: ssl.Certificate | None = None
         self._ip_address: ipaddress.IPv4Address | ipaddress.IPv6Address | None = None
         self._crawler: Crawler = crawler
+        self._tls_verbose_logging: bool = tls_verbose_logging
 
     def _finish_response(
         self, flags: list[str] | None = None, stop_download: StopDownload | None = None
@@ -653,6 +661,12 @@ class _ResponseReader(Protocol):
                 self.transport._producer.getPeer().host
             )
 
+        if self._tls_verbose_logging:
+            connection = self.transport._producer.getHandle()
+            hostname = urlparse_cached(self._request).hostname
+            assert hostname is not None
+            _log_ssl_conn_debug_info(hostname, connection)
+
     def dataReceived(self, bodyBytes: bytes) -> None:
         # This maybe called several times after cancel was called with buffered data.
         if self._finished.called:

scrapy/core/downloader/tls.py

@@ -2,7 +2,6 @@ import logging
 from typing import Any
 
 from OpenSSL import SSL
-from OpenSSL.SSL import Connection
 from service_identity import VerificationError
 from service_identity.exceptions import CertificateError
 from service_identity.pyopenssl import verify_hostname, verify_ip_address
@@ -10,7 +9,6 @@ from twisted.internet._sslverify import ClientTLSOptions
 from twisted.internet.ssl import AcceptableCiphers
 
 from scrapy.utils.deprecate import create_deprecated_class
-from scrapy.utils.ssl import get_temp_key_info, x509name_to_string
 
 logger = logging.getLogger(__name__)
 
@@ -29,53 +27,24 @@ openssl_methods: dict[str, int] = {
 }
 
 
-def _log_tls(hostname: str, connection: Connection) -> None:
-    logger.debug(
-        "SSL connection to %s using protocol %s, cipher %s",
-        hostname,
-        connection.get_protocol_version_name(),
-        connection.get_cipher_name(),
-    )
-    server_cert = connection.get_peer_certificate()
-    if server_cert:
-        logger.debug(
-            'SSL connection certificate: issuer "%s", subject "%s"',
-            x509name_to_string(server_cert.get_issuer()),
-            x509name_to_string(server_cert.get_subject()),
-        )
-    key_info = get_temp_key_info(connection._ssl)
-    if key_info:
-        logger.debug("SSL temp key: %s", key_info)
-
-
 class _ScrapyClientTLSOptions(ClientTLSOptions):
     """
     SSL Client connection creator ignoring certificate verification errors
-    (for genuinely invalid certificates or bugs in verification code) and
+    (for genuinely invalid certificates or bugs in verification code).
-    optionally logging TLS details of the connection.
 
     Same as Twisted's private _sslverify.ClientTLSOptions,
     except that VerificationError, CertificateError and ValueError
     exceptions are caught, so that the connection is not closed, only
-    logging warnings. Also, HTTPS connection parameters logging is added.
+    logging warnings.
 
     Instances of this class are returned from
     :class:`.ScrapyClientContextFactory`.
     """
 
-    def __init__(self, hostname: str, ctx: SSL.Context, verbose_logging: bool = False):
-        super().__init__(hostname, ctx)  # type: ignore[no-untyped-call]
-        self.verbose_logging: bool = verbose_logging
-
     def _identityVerifyingInfoCallback(
         self, connection: SSL.Connection, where: int, ret: Any
     ) -> None:
-        if where & SSL.SSL_CB_HANDSHAKE_START and self._hostnameIsDnsName:
+        if where & SSL.SSL_CB_HANDSHAKE_DONE:
-            connection.set_tlsext_host_name(self._hostnameBytes)
-        elif where & SSL.SSL_CB_HANDSHAKE_DONE:
-            if self.verbose_logging:
-                _log_tls(self._hostnameASCII, connection)
-
             try:
                 if self._hostnameIsDnsName:
                     verify_hostname(connection, self._hostnameASCII)
@@ -94,6 +63,8 @@ class _ScrapyClientTLSOptions(ClientTLSOptions):
                     self._hostnameASCII,
                     e,
                 )
+        else:
+            super()._identityVerifyingInfoCallback(connection, where, ret)  # type: ignore[no-untyped-call]
 
 
 ScrapyClientTLSOptions = create_deprecated_class(

scrapy/core/http2/agent.py

@@ -43,6 +43,10 @@ class H2ConnectionPool:
             ConnectionKeyT, deque[Deferred[H2ClientProtocol]]
         ] = {}
 
+        self._tls_verbose_logging: bool = settings.getbool(
+            "DOWNLOADER_CLIENT_TLS_VERBOSE_LOGGING"
+        )
+
     def get_connection(
         self, key: ConnectionKeyT, uri: URI, endpoint: HostnameEndpoint
     ) -> Deferred[H2ClientProtocol]:
@@ -71,7 +75,12 @@ class H2ConnectionPool:
         conn_lost_deferred: Deferred[list[BaseException]] = Deferred()
         conn_lost_deferred.addCallback(self._remove_connection, key)
 
-        factory = H2ClientFactory(uri, self.settings, conn_lost_deferred)
+        factory = H2ClientFactory(
+            uri,
+            self.settings,
+            conn_lost_deferred,
+            tls_verbose_logging=self._tls_verbose_logging,
+        )
         conn_d = endpoint.connect(factory)
         conn_d.addCallback(self.put_connection, key)
 

scrapy/core/http2/protocol.py

@@ -35,6 +35,7 @@ from scrapy.core.http2.stream import Stream, StreamCloseReason
 from scrapy.exceptions import DownloadTimeoutError
 from scrapy.http import Request, Response
 from scrapy.utils.deprecate import warn_on_deprecated_spider_attribute
+from scrapy.utils.ssl import _log_ssl_conn_debug_info
 
 if TYPE_CHECKING:
     from ipaddress import IPv4Address, IPv6Address
@@ -92,6 +93,8 @@ class H2ClientProtocol(Protocol, TimeoutMixin):
         uri: URI,
         settings: Settings,
         conn_lost_deferred: Deferred[list[BaseException]],
+        *,
+        tls_verbose_logging: bool = False,
     ) -> None:
         """
         Arguments:
@@ -101,8 +104,10 @@ class H2ClientProtocol(Protocol, TimeoutMixin):
             settings -- Scrapy project settings
             conn_lost_deferred -- Deferred fires with the reason: Failure to notify
                 that connection was lost
+            tls_verbose_logging -- Whether to log TLS details
         """
         self._conn_lost_deferred: Deferred[list[BaseException]] = conn_lost_deferred
+        self._tls_verbose_logging: bool = tls_verbose_logging
 
         config = H2Configuration(client_side=True, header_encoding="utf-8")
         self.conn = H2Connection(config=config)
@@ -278,6 +283,11 @@ class H2ClientProtocol(Protocol, TimeoutMixin):
                 [InvalidNegotiatedProtocol(self.transport.negotiatedProtocol)]
             )
 
+        if self._tls_verbose_logging:
+            connection = self.transport.getHandle()
+            hostname = self.metadata["uri"].host.decode("ascii")
+            _log_ssl_conn_debug_info(hostname, connection)
+
     def _check_received_data(self, data: bytes) -> None:
         """Checks for edge cases where the connection to remote fails
         without raising an appropriate H2Error
@@ -454,13 +464,21 @@ class H2ClientFactory(Factory):
         uri: URI,
         settings: Settings,
         conn_lost_deferred: Deferred[list[BaseException]],
+        *,
+        tls_verbose_logging: bool = False,
     ) -> None:
         self.uri = uri
         self.settings = settings
         self.conn_lost_deferred = conn_lost_deferred
+        self.tls_verbose_logging = tls_verbose_logging
 
     def buildProtocol(self, addr: IAddress) -> H2ClientProtocol:
-        return H2ClientProtocol(self.uri, self.settings, self.conn_lost_deferred)
+        return H2ClientProtocol(
+            self.uri,
+            self.settings,
+            self.conn_lost_deferred,
+            tls_verbose_logging=self.tls_verbose_logging,
+        )
 
     def acceptableProtocols(self) -> list[bytes]:
         return [PROTOCOL_NAME]

scrapy/utils/_download_handlers.py

@@ -48,6 +48,9 @@ class BaseHttpDownloadHandler(BaseDownloadHandler, ABC):
         self._fail_on_dataloss: bool = crawler.settings.getbool(
             "DOWNLOAD_FAIL_ON_DATALOSS"
         )
+        self._tls_verbose_logging: bool = crawler.settings.getbool(
+            "DOWNLOADER_CLIENT_TLS_VERBOSE_LOGGING"
+        )
         self._fail_on_dataloss_warned: bool = False
 
 

scrapy/utils/ssl.py

@@ -120,3 +120,22 @@ def get_openssl_version() -> str:
     system_openssl_bytes = OpenSSL.SSL.SSLeay_version(OpenSSL.SSL.SSLEAY_VERSION)
     system_openssl = system_openssl_bytes.decode("ascii", errors="replace")
     return f"{OpenSSL.version.__version__} ({system_openssl})"
+
+
+def _log_ssl_conn_debug_info(hostname: str, connection: OpenSSL.SSL.Connection) -> None:
+    logger.debug(
+        "SSL connection to %s using protocol %s, cipher %s",
+        hostname,
+        connection.get_protocol_version_name(),
+        connection.get_cipher_name(),
+    )
+    server_cert = connection.get_peer_certificate()
+    if server_cert:
+        logger.debug(
+            'SSL connection certificate: issuer "%s", subject "%s"',
+            x509name_to_string(server_cert.get_issuer()),
+            x509name_to_string(server_cert.get_subject()),
+        )
+    key_info = get_temp_key_info(connection._ssl)
+    if key_info:
+        logger.debug("SSL temp key: %s", key_info)