javalog4j2rest-assuredapache-httpcomponents

How to configure Apache HttpClient logger?


I am using RestAssured 5.3.0 and I want to log the low level http requests/responses. The RequestLoggingFilter docs say:

... If you need to log what's actually sent on the wire refer to the HTTP Client logging docs or use an external tool such as Wireshark .

So, I went straight to the link they point to: https://hc.apache.org/httpcomponents-client-5.2.x/logging.html

The link is about HttpClient v5, but RestAssured 5.3.0 uses v4.5. This is shown from mvn dependency:tree:

[INFO] +- io.rest-assured:rest-assured:jar:5.3.0:compile
[INFO] |  +- org.apache.groovy:groovy:jar:4.0.6:compile
[INFO] |  +- org.apache.groovy:groovy-xml:jar:4.0.6:compile
[INFO] |  +- org.apache.httpcomponents:httpclient:jar:4.5.13:compile

So, I should be actually looking at this link: https://hc.apache.org/httpcomponents-client-4.5.x/logging.html

From what I understood in the guide, I just have to add a logger in my log4j2.xml and the http client should start producing logs. Here is the example I am looking at from the guide. The section is called Enable full wire + context logging:

<Configuration>
  <Appenders>
    <Console name="Console">
      <PatternLayout pattern="%d %-5level [%logger] %msg%n%xThrowable" />
    </Console>
  </Appenders>
  <Loggers>
    <Logger name="org.apache.http" level="DEBUG">
      <AppenderRef ref="Console"/>
    </Logger>
    <Root level="INFO">
      <AppenderRef ref="Console" />
    </Root>
  </Loggers>
</Configuration>

Here is my log4j2.xml. Please note the comment there:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN" strict="true">
    <Appenders>
        <Appender type="Console" name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{3} - %msg%n"/>
        </Appender>
    </Appenders>
    <Loggers>
        <Root level="debug">
            <AppenderRef ref="Console"/>
        </Root>

       <Logger name="org.apache.http" level="all">
            <AppenderRef ref="Console"/>
       </Logger>

        <!-- desperate attempt to enable the logging on even higher hierarchy level-->
        <Logger name="org.apache" level="all">
            <AppenderRef ref="Console"/>
        </Logger>

    </Loggers>
</Configuration>

Here is the part of my pom.xml related to the logging dependencies:

...
        <!-- https://mvnrepository.com/artifact/org.slf4j/slf4j-api -->
        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-api</artifactId>
            <version>2.0.9</version>
        </dependency>

        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-core</artifactId>
            <version>2.21.1</version>
        </dependency>

        <!-- https://mvnrepository.com/artifact/org.apache.logging.log4j/log4j-slf4j2-impl -->
        <dependency>
            <groupId>org.apache.logging.log4j</groupId>
            <artifactId>log4j-slf4j2-impl</artifactId>
            <version>2.21.1</version>
            <scope>test</scope>
        </dependency>
...

I ran my tests, but no logging from the org.apache.* loggers is printed to the console.

What am I doing wrong?

EDIT: Add MVP example

RestAssured pom dependency:

<!-- https://mvnrepository.com/artifact/io.rest-assured/rest-assured -->
        <dependency>
            <groupId>io.rest-assured</groupId>
            <artifactId>rest-assured</artifactId>
            <version>5.3.0</version>
        </dependency>

Code:

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.testng.annotations.Test;

public class TestClass {
    Logger logger = LogManager.getLogger(this);

    @Test
    public void test() {
        logger.info("Before request");

        RestAssured.given()
                .get("https://google.com");

        logger.info("After request");
    }
}

Output:

22:33:51.329 [main] INFO  TestClass - Before request
22:33:52.769 [main] INFO  TestClass - After request

===============================================
Default Suite
Total tests run: 1, Passes: 1, Failures: 0, Skips: 0
===============================================


Process finished with exit code 0

Solution

  • The issue is that org.apache.httpcomponents:httpclient:jar:4.5.13 uses org.apache.commons.logging.* classes for logging and not slf4:

    package org.apache.http.impl.conn;
    
    import org.apache.commons.logging.Log;
    import org.apache.commons.logging.LogFactory;
    
    ...
    
    public class DefaultClientConnection extends SocketHttpClientConnection
        implements OperatedClientConnection, ManagedHttpClientConnection, HttpContext {
    
        private final Log log = LogFactory.getLog(getClass());
        private final Log headerLog = LogFactory.getLog("org.apache.http.headers");
        private final Log wireLog = LogFactory.getLog("org.apache.http.wire");
    

    To view logs, you need to add the Commons Logging Bridge dependency:

    <dependency>
        <groupId>org.apache.logging.log4j</groupId>
        <artifactId>log4j-jcl</artifactId>
        <version>2.12.1</version>
    </dependency>
    

    after adding this <Logger name="org.apache.http.wire" level="DEBUG"/> you will see the logs:

    [main] INFO  org.example.AppTest - Before request
    [main] DEBUG apache.http.wire -  >> "GET / HTTP/1.1[\r][\n]"
    [main] DEBUG apache.http.wire -  >> "Accept: */*[\r][\n]"
    [main] DEBUG apache.http.wire -  >> "Host: google.com[\r][\n]"
    [main] DEBUG apache.http.wire -  >> "Connection: Keep-Alive[\r][\n]"
    [main] DEBUG apache.http.wire -  >> "User-Agent: Apache-HttpClient/4.5.13 (Java/21)[\r][\n]"
    [main] DEBUG apache.http.wire -  >> "Accept-Encoding: gzip,deflate[\r][\n]"
    [main] DEBUG apache.http.wire -  >> "[\r][\n]"
    [main] DEBUG apache.http.wire -  << "HTTP/1.1 301 Moved Permanently[\r][\n]"
    [main] DEBUG apache.http.wire -  << "Location: https://www.google.com/[\r][\n]"