Uploaded image for project: 'Dev - Nexus Repo'
  1. Dev - Nexus Repo
  2. NEXUS-31174

Exceptions that occur while retrieving a remote certificate are not always logged

    Details

    • Type: Bug
    • Status: New
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 3.37.3
    • Fix Version/s: None
    • Component/s: Logging, SSL
    • Labels:
    • Notability:
      n/a

      Description

      If an error happens during SSL certificate retrieval, it is not logged at INFO log levels. This makes problem diagnosis of this action harder.

      Example, the only INFO level logged here is the action that we are about to check the remote for certificate chain:

      2022-02-09 11:20:13,604-0500 INFO  [qtp496558140-827]  admin com.sonatype.nexus.ssl.plugin.internal.CertificateRetriever - Retrieving certificate from https://registry.npmjs.org:443
      2022-02-09 11:20:13,605-0500 DEBUG [qtp496558140-827]  admin org.apache.http.client.protocol.RequestAddCookies - CookieSpec selected: ignoreCookies
      2022-02-09 11:20:13,606-0500 DEBUG [qtp496558140-827]  admin org.apache.http.client.protocol.RequestAuthCache - Auth cache not set in the context
      2022-02-09 11:20:13,606-0500 DEBUG [qtp496558140-827]  admin org.apache.http.impl.conn.BasicHttpClientConnectionManager - Get connection for route {tls}->http://proxy.us-east-1.app.example.org:8080->https://registry.npmjs.org:443
      2022-02-09 11:20:13,606-0500 DEBUG [qtp496558140-827]  admin org.apache.http.impl.conn.DefaultManagedHttpClientConnection - http-outgoing-179: set socket timeout to 0
      2022-02-09 11:20:13,606-0500 DEBUG [qtp496558140-827]  admin org.apache.http.impl.execchain.MainClientExec - Opening connection {tls}->http://proxy.us-east-1.app.example.org:8080->https://registry.npmjs.org:443
      2022-02-09 11:20:13,607-0500 DEBUG [qtp496558140-827]  admin org.apache.http.impl.conn.DefaultHttpClientConnectionOperator - Connecting to proxy.us-east-1.app.example.org/10.0.0.0:8080
      2022-02-09 11:20:13,607-0500 DEBUG [qtp496558140-827]  admin org.apache.http.impl.conn.DefaultHttpClientConnectionOperator - Connection established 10.0.0.0:59250<->10.0.0.0:8080
      2022-02-09 11:20:13,607-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 >> CONNECT registry.npmjs.org:443 HTTP/1.1
      2022-02-09 11:20:13,608-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 >> Host: registry.npmjs.org:443
      2022-02-09 11:20:13,608-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 >> User-Agent: Nexus/3.37.3-02 (PRO; Linux; 3.10.0-1160.49.1.el7.x86_64; amd64; 1.8.0_312)
      2022-02-09 11:20:13,611-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 << HTTP/1.1 403 Forbidden
      2022-02-09 11:20:13,611-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 << Server: squid/3.5.20
      2022-02-09 11:20:13,612-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 << Mime-Version: 1.0
      2022-02-09 11:20:13,612-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 << Date: Wed, 09 Feb 2022 16:20:13 GMT
      2022-02-09 11:20:13,612-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 << Content-Type: text/html;charset=utf-8
      2022-02-09 11:20:13,612-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 << Content-Length: 3607
      2022-02-09 11:20:13,613-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 << X-Squid-Error: ERR_ACCESS_DENIED 0
      2022-02-09 11:20:13,613-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 << Vary: Accept-Language
      2022-02-09 11:20:13,613-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 << Content-Language: en
      2022-02-09 11:20:13,613-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 << X-Cache: MISS from proxy.us-east-1.app.example.org
      2022-02-09 11:20:13,614-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 << X-Cache-Lookup: NONE from proxy.us-east-1.app.example.org:8080
      2022-02-09 11:20:13,614-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 << Via: 1.1 proxy.us-east-1.app.example.org (squid/3.5.20)
      2022-02-09 11:20:13,614-0500 DEBUG [qtp496558140-827]  admin org.apache.http.headers - http-outgoing-179 << Connection: keep-alive
      2022-02-09 11:20:13,614-0500 DEBUG [qtp496558140-827]  admin org.apache.http.impl.conn.DefaultManagedHttpClientConnection - http-outgoing-179: Close connection
      2022-02-09 11:20:13,615-0500 DEBUG [qtp496558140-827]  admin org.apache.http.impl.execchain.MainClientExec - CONNECT refused by proxy: HTTP/1.1 403 Forbidden
      2022-02-09 11:20:13,615-0500 DEBUG [qtp496558140-827]  admin org.apache.http.impl.execchain.MainClientExec - Connection discarded
      2022-02-09 11:20:13,615-0500 DEBUG [qtp496558140-827]  admin org.apache.http.impl.conn.BasicHttpClientConnectionManager - Releasing connection [Not bound]
      

      The user in the UI either sees the error that gets reported by the subsequent SSL socket exception problem, or sees nothing. Looking at the DEFAULT logs will not tell them what happened.

      Expected

      Do not swallow exceptions that get logged when retrieving remote SSL certificate details. Instead log the exception name and message ( and transtive throwables ) at INFO level by default. At DEBUG level, also log the full stack trace.

      In the example above, at INFO log levels it should be very clear that the HTTP Proxy server denied access to the CONNECT tunnel attempt with 403 response code.

        Attachments

          Activity

            People

            Assignee:
            Unassigned Unassigned
            Reporter:
            plynch Peter Lynch
            Last Updated By:
            Michael Oliverio Michael Oliverio
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Dates

              Created:
              Updated:

                tigCommentSecurity.panel-title