Skip to main content

Configuring Maven HTTP Wagon Detailed Logging

Peter
Updated

This note describes how to enable detailed HTTP logging for all versions of Apache Maven.

Problems with Maven and HTTP/HTTPS?

You may have experienced problems downloading or uploading artifacts using Apache Maven.

You've already tried the defacto Maven debug output ( -X ) and don't see anything obvious or it provides you seemingly little practical information as to what may be going wrong from the client point of view.

Common problems people run into are:

  • bugs in certain Maven Wagon versions
  • bugs in certain Maven Extensions
  • classpath extensions silently overriding your perceived Maven classpath
  • misbehaving remote servers
  • HTTP proxy server issues including NTLM and socks proxies
  • broken non proxy host settings
  • system proxy interfering with Maven/Java proxy
  • cached responses and CDN issues
  • Virus scanners and Network instrusion software gone amuck
  • agressive firewalls and locked Windows policies out of your control
  • Maven Settings Mirror and Server ID misconfiguration issues
  • Unexpected Authentication ( 401, 403 ) issues
  • HTTPS certificates, protocol and cipher issues

Or maybe you wish to have had timestamped logging messages so you can see what is taking so long!

Well before you go and fire up Wireshark, configure Maven with Charles Proxy or troll your repository manager DEBUG logs, consider enabling some finer grained HTTP logging with a few simple steps.

How?

Simple!

  1. Create ( Maven 2.2.1/3.0.x ) or replace completely ( Maven 3.1.x+ ) the contents of a file at $M2_HOME/conf/logging/simplelogger.properties using the following content:

    # https://support.sonatype.com/entries/23656571-Configuring-Maven-HTTP-Wagon-Detailed-Logging
# ==========================================================================================================
# === 1) copy this file to $M2_HOME/conf/logging/simplelogger.properties
# === 2) MAVEN_OPTS should include reference to this file. Example: 
# ===    *nix: export MAVEN_OPTS="$MAVEN_OPTS -Djava.util.logging.config.file=$M2_HOME/conf/logging/simplelogger.properties"
# ===    *win: set MAVEN_OPTS "%MAVEN_OPTS% -Djava.util.logging.config.file=%M2_HOME%/conf/logging/simplelogger.properties"
# ==========================================================================================================

# === Maven 2.2.1 and Maven 3.0.x section
.level = INFO

handlers=java.util.logging.ConsoleHandler
java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter
java.util.logging.ConsoleHandler.level = ALL

# lightweight wagon - evil
sun.net.www.level = FINEST

# Maven 2.2.1 + wagon-http 2.1 + commons-httpclient 3.1 loaded via as extension dependency
# may require slf4j-jdk14 as build extension if slf4j is also loaded via transitive extension
httpclient.wire.header.level=FINEST
org.apache.commons.httpclient.level=FINE

# Maven 2.2.1 / 3.0.x + wagon-http 2.1 + httpclient 4x
org.apache.http.level = FINEST
org.apache.http.wire.level = SEVERE
org.apache.http.impl.conn.level = FINEST
org.apache.http.impl.client.level = FINEST
org.apache.http.client.level = FINEST

# wagon-http 2.2+ + httpclient 4x is shaded
org.apache.maven.wagon.providers.http.httpclient.level = FINEST
org.apache.maven.wagon.providers.http.httpclient.wire.level = SEVERE

# === Maven 3.1.x+ section

# http://maven.apache.org/maven-logging.html Default Overrides
org.slf4j.simpleLogger.defaultLogLevel=trace
org.slf4j.simpleLogger.showDateTime=true
org.slf4j.simpleLogger.showThreadName=true
org.slf4j.simpleLogger.showLogName=true
org.slf4j.simpleLogger.logFile=System.out
org.slf4j.simpleLogger.levelInBrackets=true
org.slf4j.simpleLogger.log.Sisu=info
org.slf4j.simpleLogger.warnLevelString=WARNING

# HTTP logging overrides
org.slf4j.simpleLogger.log.org.apache.http=DEBUG
org.slf4j.simpleLogger.log.org.apache.http.wire=ERROR
org.slf4j.simplelogger.log.org.apache.maven.wagon.providers.http=DEBUG
org.slf4j.simplelogger.log.org.apache.maven.wagon.providers.http.httpclient.wire=ERROR

  2. Specify an additional Java system property to your MAVEN_OPTS environment variable.

    *nix:

    export MAVEN_OPTS="$MAVEN_OPTS -Djava.util.logging.config.file=$M2_HOME/conf/logging/simplelogger.properties"

    Windows:

    set MAVEN_OPTS "%MAVEN_OPTS% -Djava.util.logging.config.file=%M2_HOME%/conf/logging/simplelogger.properties"

  3. Optional: For HTTPS related problems, use -Djavax.net.debug=ssl in MAVEN_OPTS to get low level protocol activity.

  4. Optional: In cases where slf4j may be pulled in by a Maven build extension ( ie. wagon-webdav-jackrabbit ), then you may get no logging of HTTP traffic. A tell tale sign would be seeing this message in your build logs printed to stderr:

    SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.

    To fix this, you need to add a slf4j implementation to the build classpath to fix this. The easiest way to fix this is add the following build extension in your pom.xml before any other extension:

    <extension>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-jdk14</artifactId>
    <version>1.7.5</version>
</extension>

    This should cause slf4j to log to java.util.logging via the configured logging properties file.

What do I get?

When Maven is uploading or downloading artifacts, you get detailed HTTP logging on stderr similar to this:

Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.client.protocol.ResponseProcessCookies processCookies
FINE: Cookie accepted: "[version: 0][name: rememberMe][value: deleteMe][domain: repository.sonatype.org][path: /][expiry: Tue Apr 09 14:13:33 PDT 2013]". 
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.client.DefaultRequestDirector execute
FINE: Connection can be kept alive for 5000 MILLISECONDS
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.client.HttpAuthenticator isAuthenticationRequested
FINE: Authentication required
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.client.HttpAuthenticator authenticate
FINE: repository.sonatype.org:443 requested authentication
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.client.AuthenticationStrategyImpl select
FINE: Authentication schemes in the order of preference: [negotiate, Kerberos, NTLM, Digest, Basic]
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.client.AuthenticationStrategyImpl select
FINE: Challenge for negotiate authentication scheme not available
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.client.AuthenticationStrategyImpl select
FINE: Challenge for Kerberos authentication scheme not available
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.client.AuthenticationStrategyImpl select
FINE: Challenge for NTLM authentication scheme not available
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.client.AuthenticationStrategyImpl select
FINE: Challenge for Digest authentication scheme not available
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.client.HttpAuthenticator authenticate
FINE: Selected authentication options: [BASIC]
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.client.protocol.RequestAddCookies process
FINE: CookieSpec selected: compatibility
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.client.protocol.RequestAuthCache process
FINE: Auth cache not set in the context
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.client.protocol.RequestTargetAuthentication process
FINE: Target auth state: CHALLENGED
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.client.protocol.RequestAuthenticationBase process
FINE: Generating response to an authentication challenge using basic scheme
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.client.protocol.RequestProxyAuthentication process
FINE: Proxy auth state: UNCHALLENGED
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.client.DefaultRequestDirector tryExecute
FINE: Attempt 2 to execute request
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection sendRequestHeader
FINE: Sending request: GET /content/groups/sonatype-grid/junit/junit/3.8.1/junit-3.8.1.pom HTTP/1.1
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection sendRequestHeader
FINE: >> GET /content/groups/sonatype-grid/junit/junit/3.8.1/junit-3.8.1.pom HTTP/1.1
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection sendRequestHeader
FINE: >> Cache-control: no-cache
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection sendRequestHeader
FINE: >> Cache-store: no-store
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection sendRequestHeader
FINE: >> Pragma: no-cache
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection sendRequestHeader
FINE: >> Expires: 0
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection sendRequestHeader
FINE: >> Accept-Encoding: gzip
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection sendRequestHeader
FINE: >> User-Agent: Apache-Maven/3.0.5 (Java 1.7.0_17; Linux 2.6.32-358.2.1.el6.x86_64)
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection sendRequestHeader
FINE: >> Host: repository.sonatype.org
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection sendRequestHeader
FINE: >> Connection: Keep-Alive
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection sendRequestHeader
FINE: >> Authorization: Basic REDACTED
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection receiveResponseHeader
FINE: Receiving response: HTTP/1.1 200 OK
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection receiveResponseHeader
FINE: << HTTP/1.1 200 OK
^CApr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection receiveResponseHeader
FINE: << Server: nginx/0.8.54
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection receiveResponseHeader
FINE: << Date: Tue, 09 Apr 2013 21:13:33 GMT
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection receiveResponseHeader
FINE: << Content-Type: application/xml
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection receiveResponseHeader
FINE: << Transfer-Encoding: chunked
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection receiveResponseHeader
FINE: << Connection: keep-alive
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection receiveResponseHeader
FINE: << Keep-Alive: timeout=5
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection receiveResponseHeader
FINE: << Set-Cookie: rememberMe=deleteMe; Path=/; Max-Age=0; Expires=Mon, 08-Apr-2013 21:13:33 GMT
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection receiveResponseHeader
FINE: << Content-Encoding: gzip
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection receiveResponseHeader
FINE: << Last-Modified: Mon, 14 May 2007 21:34:18 GMT
Apr 09, 2013 2:13:33 PM org.apache.maven.wagon.providers.http.httpclient.impl.conn.DefaultClientConnection receiveResponseHeader
FINE: << ETag: "{SHA1{16d74791c801c89b0071b1680ea0bc85c93417bb}}"

Where's the magic?

The Apache HTTP Client based Wagon provider uses Apache Commons Logging under the hood. The provider jar file is located in your Maven installation directory at one the following locations:

Maven 2.2.1+wagon-http:2.1 : standard repo GAV path for http-client:4.1.2 jar
Maven 3.0.4 : $M2_HOME/lib/wagon-http-2.2-shaded.jar
Maven 3.0.5/3.1.1 : $M2_HOME/lib/wagon-http-2.4-shaded.jar
Maven 3.2.x : $M2_HOME/lib/wagon-http-2.6-shaded.jar

For Maven 3, as indicated by the file name, the Commons Logging classes are shaded ( repackaged ) inside these jar files in the package org.apache.maven.wagon.providers.http.commons.logging. Commons Logging falls back to using a java.util.logging (JUL) based logging implementation when running on a JDK 1.4+ environment if Log4J is not on the Maven classpath.

For Maven 2.2.1 wagon-http:2.1, the classes are not shaded, so standard httpclient logging categories can be used.

By passing the java.util.logging.config.file system property to Maven, we explicitly configure Apache HTTP Client logger levels as discussed in the httpclient logging documentation page - with one important difference for Maven 3.x - using the shaded logger names instead.

Related articles