How to redirect AWS sdk logging output

Question

I keep getting those on STDOUT even though I'm using logback and configured it. I'm not able to get AWS stuff out of the console.

Jun 19, 2014 3:46:40 PM com.amazonaws.http.AmazonHttpClient executeHelper
INFO: Unable to execute HTTP request: The target server failed to respond
org.apache.http.NoHttpResponseException: The target server failed to respond
        at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:95)
        at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:62)
        at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
        at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
        at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)  
        at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)   
        at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
        at com.amazonaws.http.protocol.SdkHttpRequestExecutor.doReceiveResponse(SdkHttpRequestExecutor.java:66)
        at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
        at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:713)
        at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:518)
        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
        at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
        at com.amazonaws.http.AmazonHttpClient.executeHelper(AmazonHttpClient.java:402)
        at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:245)
        at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:3573)
        at com.amazonaws.services.s3.AmazonS3Client.getObjectMetadata(AmazonS3Client.java:990)
        at com.amazonaws.services.s3.AmazonS3Client.getObjectMetadata(AmazonS3Client.java:970)
        at com.here.prime.cdtfilter.S3MapStore$$anonfun$1.apply(S3MapStore.scala:49)
        at com.here.prime.cdtfilter.S3MapStore$$anonfun$1.apply(S3MapStore.scala:48)
        at com.here.prime.utils.Utils$.retry(Utils.scala:26)

This is my logback configuration:

<configuration debug="false" scan="true" scanPeriod="30 seconds">
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>cdtxfilter.log</file>
        <append>true</append>
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <logger name="com.amazonaws.request" level="WARN">
    </logger>

    <root level="DEBUG">
        <!--<appender-ref ref="STDOUT" />-->
        <appender-ref ref="FILE" />
    </root>
</configuration>

---

Solution:

Force logging through logback, instead of commons-logging:

In build.sbt added:

resolvers ++= Seq(
  "version99 Empty loggers" at "http://version99.qos.ch",
)

libraryDependencies ++= Seq(
  "org.slf4j" % "jcl-over-slf4j" % "1.7.7",
  "commons-logging" % "commons-logging" % "99-empty",
  "ch.qos.logback" % "logback-classic" % "1.0.13",
)

In logback.xml, fine tune the log level for the noisy classes inside AWS SDK:

<configuration...
[..]
    <logger name="com.amazonaws" level="ERROR"/>
    <logger name="org.apache.http" level="INFO" />
</configuration>

Answer 1

First that I'd like to tell is that, because of historical reasons, logging in java is a mess and you should be ready to put some effort into making it right.

Now, to your problem.

First of all it really seems like logs you are getting in your STDOUT bypass logback (at least they do not follow any of the patterns defined in your logback configuration).

There may be 2 reasons of that:

1. You've misconfigured logback in some way which is less likely (verify this by checking whether any log entries end up in the files you've configured logback write them to).

2. Logs form AWS sdk getting handled by commons logging (most likely, since this is the logging system that is used by AWS sdk) or something that mimics commons logging to redirect logs to, for example, SLF4J (less likely, since this requires some explicit configuration of the classpath).

Now to deal with this I would suggest you to start with this article to get an overview of the java's logging zoo.

Next, to solve your problem I would suggest you to configure popular logging systems (commons logging, log4j, etc) to direct their logs to SLF4j and use logback as SLF4j implementation.

Read this, and this (if you use maven, otherwise find a way to exclude jcl and log4j relevant to your build system) to understand what should and what should not be placed into your classpath.

One of my projects use AWS sdk and has logging set up as proposed above.

In my pom.xml I set up dependencies like this:

...

<repositories>
    <repository>
        <id>version99</id>
        <url>http://version99.qos.ch/</url>
    </repository>
</repositories>

<dependencyManagement>
    <dependencies>
        <dependency>
            <groupId>commons-logging</groupId>
            <artifactId>commons-logging</artifactId>
            <version>99-empty</version>
        </dependency>
        <dependency>
            <groupId>log4j</groupId>
            <artifactId>log4j</artifactId>
            <version>99-empty</version>
        </dependency>
    </dependencies>
</dependencyManagement>

<dependencies>
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>slf4j-api</artifactId>
        <version>1.7.7</version>
    </dependency>
    <dependency>
        <groupId>ch.qos.logback</groupId>
        <artifactId>logback-classic</artifactId>
        <version>1.1.2</version>
    </dependency>
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>log4j-over-slf4j</artifactId>
        <version>1.7.7</version>
    </dependency>
    <dependency>
        <groupId>org.slf4j</groupId>
        <artifactId>jcl-over-slf4j</artifactId>
        <version>1.7.7</version>
    </dependency>

    ...

</dependencies>

...

... and also in my classpath I have logback.xml like this:

<appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>logs.log</file>
    <append>false</append>
    <encoder>
        <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
    </encoder>
</appender>

<root level="debug">
    <appender-ref ref="FILE" />
</root>

... and and all logs end up written to my log file.

This should give you some idea on how dependencies/logging should be configured.

Feel free to clarify unclear moments in comments.

Answer 2

You are getting messages to STDOUT most likely because you have something in your classpath at runtime, which is logging to STDOUT (f.ex. a class which is using apache commons logging like suggested in earlier post). Not alone that you are using logback, means that all logging goes through logback.

To get control over all logging in your application, you have to:

A) Check your classpath and remove all other binaries of logging libraries (commons-logging, log4j etc.) If you are using maven, run mvn dependency:tree -X, then use exlusion to remove dependencies to logging libraries.

B) Replace these libraries with bridges to direct your logging to SLF4J

C) Direct your logging from source code via SLF4J to Logback. There is a migrator to mitigate your work. Check if it can help you.

D) Configure your logback, either in logback.xml or logback.groovy.