Submit a request

How to Debug Outbound HTTP Requests in Repository 3

Avatar
Peter Lynch
Created: - Updated:

The Nexus Repository 3 requires outbound HTTP access to many external hosts and URLs. Sometimes these outbound requests fail for unknown reasons. Examining the outbound request URLs, the response status codes and HTTP headers of the requests and responses can help debug problems.

An administrator can enable log statements that print the outbound HTTP request and response details into the nexus.log.

Open the Logging Configuration To Make Changes

Debugging outbound requests can be done by adjusting logger levels. Logger-level changes take effect immediately and do not require a restart of the server.

To access the Logging level configuration:

  1. Sign-in to Nexus Repository 3 UI as an Administrator user account such as admin .
  2. Click the Administration cog icon in the top toolbar.
  3. Using the left navigation menu, navigate to Support -> Logging

Summary Outbound Logging for Repository Requests

The intent of summary logging is to log a minimum of statements to understand what remote URLs are being accessed in response to any inbound repository request. This logging records:

  • full outbound URL being requested, including HTTP method and protocol used
  • if a response is returned, the HTTP status line and time elapsed between when the request started to the first response of HTTP headers from the remote. The time elapsed does not include the total time to receive the entire response body
  • if a response is not received, you will not see a corresponding response line - however, you may see other log messages describing a problem

Use Cases

This logging is particularly useful to understand what proxy repository members' outbound requests were used to resolve an inbound request to a group repository.

The logging may help isolate unexpected 3xx redirects to servers that need to be whitelisted by an HTTP proxy server or firewall.

By tracking the thread id and the URLs being used, one can relate the log requests together for the same inbound request.

Example

2019-03-11 13:39:43,485-0300 DEBUG [qtp1014084813-360] admin org.sonatype.nexus.httpclient.outbound - https://repo1.maven.org/maven2/org/springframework/boot/spring-boot/1.5.17.RELEASE/spring-boot-1.5.17.RELEASE-javadoc.jar > GET /maven2/org/springframework/boot/spring-boot/1.5.17.RELEASE/spring-boot-1.5.17.RELEASE-javadoc.jar HTTP/1.1
2019-03-11 13:39:43,831-0300 DEBUG [qtp1014084813-360] admin org.sonatype.nexus.httpclient.outbound - https://repo1.maven.org/maven2/org/springframework/boot/spring-boot/1.5.17.RELEASE/spring-boot-1.5.17.RELEASE-javadoc.jar < HTTP/1.1 200 OK @ 351.0 ms
2019-03-11 13:39:44,702-0300 DEBUG [qtp1014084813-360] admin org.sonatype.nexus.httpclient.outbound - http://localhost:8070/rest/integration/repositories/9AA91332-F6541AD7-5C6AC8E7-E0AD5F2D-04F4056A/maven-central-3/evaluate/quarantine > POST /rest/integration/repositories/9AA91332-F6541AD7-5C6AC8E7-E0AD5F2D-04F4056A/maven-central-3/evaluate/quarantine HTTP/1.1
2019-03-11 13:39:44,709-0300 WARN  [qtp1014084813-360] admin com.sonatype.nexus.clm.internal.FirewallContributedHandler - Could not get latest quarantine status for asset maven-central-3:org/springframework/boot/spring-boot/1.5.17.RELEASE/spring-boot-1.5.17.RELEASE-javadoc.jar: Connect to localhost:8070 [localhost/127.0.0.1] failed: Connection refused (Connection refused)
2019-03-11 13:39:44,724-0300 INFO  [qtp1014084813-360] admin com.sonatype.nexus.clm.internal.FirewallContributedHandler - Blocked serving of quarantined asset maven-central-3:org/springframework/boot/spring-boot/1.5.17.RELEASE/spring-boot-1.5.17.RELEASE-javadoc.jar because quarantineStatus=PENDING

Enabling Outbound Repository Request Summary Logging

  1. Open the Logging Configuration to make changes.
  2. In the top right filter field type 'outbound'
  3. Select the logger named org.sonatype.nexus.httpclient.outboundand change the level value to DEBUG.
  4. Click Update. Changes take effect without requiring a server restart.

Disabling Outbound Repository Request Summary Logging

  1. Open the Logging Configuration to make changes.
  2. In the top right filter field type 'outbound'
  3. Select the logger named org.sonatype.nexus.httpclient.outboundand change the level value back to the default INFO level.
  4. Click Update. Changes take effect without requiring a server restart.

Detailed Outbound HTTP Header Logging

All outbound HTTP requests Nexus Repository 3 makes use Apache httpclient libraries.

For every outbound request, including those which have nothing to do with inbound repository content requests, you can enable logging statements that print the full outbound HTTP request and response headers.

CAUTION: This logging is very verbose. Enabling this logging should only be done on a short term to diagnose a specific problem and then immediately be reset back to default levels.

Enabling Outbound HTTP Header Detailed Logging

Caution: This logging is verbose and may print outbound authentication headers in the nexus.log. Enabling this logging should be constrained to the time period required to investigate a problem.

Logger-level changes take effect immediately and do not require a restart of the server.

  1. Open the Logging configuration to make changes.
  2. Click Create logger button
  3. On the Create Logger screen set these values:
    1. Logger name: org.apache.http
    2. Logger level: DEBUG
    Save these changes. If asked to Confirm Update? then click Yes.
  4. Reproduce a scenario that causes Nexus to trigger an outbound request. Examine the nexus.log for activity from the org.apache.http logger.

Disabling Outbound HTTP Header Detailed Logging

When you are done reproducing a problem and examining the HTTP outbound requests in the nexus.log, it is important to reset the log levels to sensible defaults.

Option 1: Reset all Loggers to default levels

  1. Open the Logging configuration to make changes.
  2. Click Reset to default levels button to reset all Loggers to their shipped default values

Option 2: Change a specific Logger level to a previous value

  1. Open the Logging configuration to make changes.
  2. Use the Filter field at top right to find the Logger needing adjustment.

    For example, to find the org.apache.http logger, type that name into the filter field.
  3. Select the found logger in the table and change the Level value to its new value. For example, change the org.apache.http logger back to INFO.
  4. Click Update to save the logger level changes.

Example Outbound HTTP Header Detailed Logging Statements

Here are example log statements similar to what you might see when loading the Welcome page in the Nexus Repository 3 UI:

2017-11-28 15:33:12,518-0400 DEBUG [qtp940770288-59] admin org.apache.http.client.protocol.RequestAddCookies - CookieSpec selected: ignoreCookies
2017-11-28 15:33:12,518-0400 DEBUG [qtp940770288-59] admin org.apache.http.client.protocol.RequestAuthCache - Auth cache not set in the context
2017-11-28 15:33:12,518-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.MainClientExec - Opening connection {}->http://links.sonatype.com:80
2017-11-28 15:33:12,518-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.conn.DefaultHttpClientConnectionOperator - Connecting to links.sonatype.com/207.223.241.68:80
2017-11-28 15:33:12,573-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.conn.DefaultHttpClientConnectionOperator - Connection established 192.168.2.97:64725<->207.223.241.68:80
2017-11-28 15:33:12,573-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.conn.DefaultManagedHttpClientConnection - http-outgoing-7: set socket timeout to 20000
2017-11-28 15:33:12,573-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.MainClientExec - Executing request GET /products/nexus/outreach/pro/3.6.1-02/en/admin HTTP/1.1
2017-11-28 15:33:12,573-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.MainClientExec - Target auth state: UNCHALLENGED
2017-11-28 15:33:12,573-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.MainClientExec - Proxy auth state: UNCHALLENGED
2017-11-28 15:33:12,573-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-7 >> GET /products/nexus/outreach/pro/3.6.1-02/en/admin HTTP/1.1
2017-11-28 15:33:12,573-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-7 >> Host: links.sonatype.com
2017-11-28 15:33:12,573-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-7 >> Connection: Keep-Alive
2017-11-28 15:33:12,573-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-7 >> User-Agent: Nexus/3.6.1-02 (PRO; Mac OS X; 10.12.6; x86_64; 1.8.0_131)
2017-11-28 15:33:12,573-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-7 >> Accept-Encoding: gzip,deflate
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-7 << HTTP/1.1 302 Found
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-7 << Date: Tue, 28 Nov 2017 19:33:12 GMT
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-7 << Server: Apache
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-7 << Location: http://download.sonatype.com/nexus/outreach/pro-en-all-admin.zip
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-7 << Content-Length: 316
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-7 << Connection: close
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-7 << Content-Type: text/html; charset=iso-8859-1
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.client.DefaultRedirectStrategy - Redirect requested to location 'http://download.sonatype.com/nexus/outreach/pro-en-all-admin.zip'
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.RedirectExec - Resetting target auth state
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.RedirectExec - Redirecting to 'http://download.sonatype.com/nexus/outreach/pro-en-all-admin.zip' via {}->http://download.sonatype.com:80
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.conn.DefaultManagedHttpClientConnection - http-outgoing-7: Close connection
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.MainClientExec - Connection discarded
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.client.protocol.RequestAddCookies - CookieSpec selected: ignoreCookies
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.client.protocol.RequestAuthCache - Auth cache not set in the context
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.conn.DefaultManagedHttpClientConnection - http-outgoing-2: set socket timeout to 20000
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.MainClientExec - Executing request GET /nexus/outreach/pro-en-all-admin.zip HTTP/1.1
2017-11-28 15:33:12,625-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.MainClientExec - Target auth state: UNCHALLENGED
2017-11-28 15:33:12,626-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.MainClientExec - Proxy auth state: UNCHALLENGED
2017-11-28 15:33:12,626-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-2 >> GET /nexus/outreach/pro-en-all-admin.zip HTTP/1.1
2017-11-28 15:33:12,626-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-2 >> Host: download.sonatype.com
2017-11-28 15:33:12,626-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-2 >> Connection: Keep-Alive
2017-11-28 15:33:12,626-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-2 >> User-Agent: Nexus/3.6.1-02 (PRO; Mac OS X; 10.12.6; x86_64; 1.8.0_131)
2017-11-28 15:33:12,626-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-2 >> Accept-Encoding: gzip,deflate
2017-11-28 15:33:12,682-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-2 << HTTP/1.1 302 Found
2017-11-28 15:33:12,682-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-2 << Server: nginx
2017-11-28 15:33:12,682-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-2 << Date: Tue, 28 Nov 2017 19:33:12 GMT
2017-11-28 15:33:12,682-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-2 << Content-Type: text/html; charset=iso-8859-1
2017-11-28 15:33:12,682-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-2 << Content-Length: 337
2017-11-28 15:33:12,682-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-2 << Connection: keep-alive
2017-11-28 15:33:12,682-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-2 << Keep-Alive: timeout=5
2017-11-28 15:33:12,682-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-2 << Location: http://sonatype-download.global.ssl.fastly.net/nexus/outreach/pro-en-all-admin.zip
2017-11-28 15:33:12,682-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.MainClientExec - Connection can be kept alive for 5000 MILLISECONDS
2017-11-28 15:33:12,683-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.client.DefaultRedirectStrategy - Redirect requested to location 'http://sonatype-download.global.ssl.fastly.net/nexus/outreach/pro-en-all-admin.zip'
2017-11-28 15:33:12,683-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.RedirectExec - Resetting target auth state
2017-11-28 15:33:12,683-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.RedirectExec - Redirecting to 'http://sonatype-download.global.ssl.fastly.net/nexus/outreach/pro-en-all-admin.zip' via {}->http://sonatype-download.global.ssl.fastly.net:80
2017-11-28 15:33:12,683-0400 DEBUG [qtp940770288-59] admin org.apache.http.client.protocol.RequestAddCookies - CookieSpec selected: ignoreCookies
2017-11-28 15:33:12,683-0400 DEBUG [qtp940770288-59] admin org.apache.http.client.protocol.RequestAuthCache - Auth cache not set in the context
2017-11-28 15:33:12,683-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.conn.DefaultManagedHttpClientConnection - http-outgoing-3: set socket timeout to 20000
2017-11-28 15:33:12,683-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.MainClientExec - Executing request GET /nexus/outreach/pro-en-all-admin.zip HTTP/1.1
2017-11-28 15:33:12,683-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.MainClientExec - Target auth state: UNCHALLENGED
2017-11-28 15:33:12,683-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.MainClientExec - Proxy auth state: UNCHALLENGED
2017-11-28 15:33:12,683-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 >> GET /nexus/outreach/pro-en-all-admin.zip HTTP/1.1
2017-11-28 15:33:12,683-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 >> Host: sonatype-download.global.ssl.fastly.net
2017-11-28 15:33:12,683-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 >> Connection: Keep-Alive
2017-11-28 15:33:12,683-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 >> User-Agent: Nexus/3.6.1-02 (PRO; Mac OS X; 10.12.6; x86_64; 1.8.0_131)
2017-11-28 15:33:12,684-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 >> Accept-Encoding: gzip,deflate
2017-11-28 15:33:12,725-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 << HTTP/1.1 200 OK
2017-11-28 15:33:12,725-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 << Server: Apache
2017-11-28 15:33:12,725-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 << Last-Modified: Mon, 27 Nov 2017 18:49:15 GMT
2017-11-28 15:33:12,725-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 << ETag: "1682d2-a16d-55efb5be3a0c0"
2017-11-28 15:33:12,725-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 << Access-Control-Allow-Origin: *
2017-11-28 15:33:12,725-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 << Content-Type: application/zip
2017-11-28 15:33:12,725-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 << Content-Length: 41325
2017-11-28 15:33:12,725-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 << Accept-Ranges: bytes
2017-11-28 15:33:12,725-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 << Date: Tue, 28 Nov 2017 19:33:12 GMT
2017-11-28 15:33:12,725-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 << Via: 1.1 varnish
2017-11-28 15:33:12,726-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 << Age: 71661
2017-11-28 15:33:12,726-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 << Connection: keep-alive
2017-11-28 15:33:12,726-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 << X-Served-By: cache-jfk8130-JFK
2017-11-28 15:33:12,726-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 << X-Cache: HIT
2017-11-28 15:33:12,726-0400 DEBUG [qtp940770288-59] admin org.apache.http.headers - http-outgoing-3 << X-Cache-Hits: 5
2017-11-28 15:33:12,726-0400 DEBUG [qtp940770288-59] admin org.apache.http.impl.execchain.MainClientExec - Connection can be kept alive for 30000 MILLISECONDS
Have more questions? Submit a request

0 Comments

Article is closed for comments.