consoleCaptor.getStandardOutput() doesn't work

[Eric-Jalal]

Describe the bug
Hello, My issue is that with the same way as it is explained in the README I tried to use consoleCaptor.getStandardOutput() since I'm using @QuarkusTest but it gets nothing from the output, Even though the console is showing multiple json logs in the output.

@QuarkusTest
public class TestLog {

  ObjectMapper mapper = new ObjectMapper();

  @Test
  public void testLogIsInJsonFormat() {
    try (ConsoleCaptor consoleCaptor = new ConsoleCaptor()) {

      QueryClass query = new QueryClass();
      query.querySomeItem(null, null);
      List<String> standardOutPut = consoleCaptor.getStandardOutput(); // this list returns empty

      assertTrue(isValid(standardOutPut.get(1)));
    }
  }
}

{"timestamp":"2022-08-10T09:32:41.109+03:00","sequence":76,"loggerClassName":"org.jboss.logging.Logger","loggerName":"io.quarkus.amazon.lambda.runtime.AbstractLambdaPollLoop","level":"INFO","message":"Listening on: http://localhost:8081/_lambda_/2018-06-01/runtime/invocation/next","threadName":"Lambda Thread (TEST)","threadId":127,"mdc":{},"ndc":"","hostName":"my-laptop-name","processName":"JUnitStarter","processId":48118}

java.lang.IndexOutOfBoundsException: Index 1 out of bounds for length 0 // This means nothing was captured from the logs

    <dependency>
      <groupId>io.github.hakky54</groupId>
      <artifactId>logcaptor</artifactId>
      <version>2.7.10</version>
      <scope>test</scope>
    </dependency>
    <dependency>
      <groupId>io.github.hakky54</groupId>
      <artifactId>consolecaptor</artifactId>
      <version>1.0.2</version>
      <scope>test</scope>
    </dependency>

I suspect that maybe because I'm using @JbossLog annotation, but then how this can be used with that JBossLog ?

Environmental Data:

• Java Version 17
• Maven Version 3.8.5
• OS (MacOS)

[Hakky54]

Hi Eric,

I would advice not using ConsoleCaptor alongside with LogCaptor as it can conflict each other. I am not sure if that is the cause of the issue. But can you try to remove LogCaptor from your project and also from your pom?

[Eric-Jalal]

Hi Eric,

I would advice not using ConsoleCaptor alongside with LogCaptor as it can conflict each other. I am not sure if that is the cause of the issue. But can you try to remove LogCaptor from your project and also from your pom?

I just removed it and still the same issue exist. This is basically a copy paste of the example and the only difference is that my logger is JBoss, could that be the cause?
But I also changed the logger to SLF4J and still the issue exist.

[Hakky54]

It seems like the main issue is because of the @QuarkusTest annotation. I discovered that QuarkusTest is using a ConsoleHandler from the Jboss Logger library. The ConsoleHandler uses the System.out to log everything to the console. ConsoleCapture should manipulate the System.out, but fails to because the ConsoleHandler is initialized before ConsoleCaptor because of the QuarkusTest annotation. The good news is that I found a solution, however it will take some time to finilize it. I think by one week it should be ready, maybe earlier. So my advice is to drop LogCaptor as it is having issues because of multiple classloaders caused by Quarkus, which is unfortunally not fixable. And just wait for the new release of ConsoleCaptor.

[Hakky54]

Hi again Eric,

It seems I have made a mistake during the testing late in the night. The @QuarkusTest annotation was disabled. Although I had a fix ready it still didn't work because of the different classloader issue caused by @QuarkusTest annotation.

With ConsoleCaptor you can capture the logs while removing the @QuarkusTest annotation, but then you need to add ConsoleCaptor as a javaagent which is complex to set it up. I would rather provide you an easy solution.

I have now a working solution with LogCaptor. I used the following code snippets:

In my pom I needed to exclude the slf4j implementation provided by Jboss. In that way LogCaptor can use his own slf4j implementation

<plugin>
    <artifactId>maven-surefire-plugin</artifactId>
    <version>${version.maven-surefire-plugin}</version>
    <configuration>
        <classpathDependencyExcludes>
            <classpathDependencyExclude>org.jboss.slf4j:slf4j-jboss-logmanager</classpathDependencyExclude>
        </classpathDependencyExcludes>
    </configuration>
</plugin>

Example greetings resource with JBossLog annotation from LomBok

import lombok.extern.jbosslog.JBossLog;

import javax.ws.rs.GET;
import javax.ws.rs.Path;
import javax.ws.rs.Produces;
import javax.ws.rs.core.MediaType;

@JBossLog
@Path("/hello")
public class GreetingResource {

    @GET
    @Produces(MediaType.TEXT_PLAIN)
    public String hello() {
        log.info("Saying hello from the logger!");
        return "Hello from RESTEasy Reactive";
    }

}

And the test class:

import nl.altindag.log.LogCaptor;
import org.assertj.core.api.Assertions;
import org.junit.jupiter.api.Test;

public class GreetingsResourceWithoutQuarkusTestShould {

    @Test
    void sayHello() {
        LogCaptor logCaptor = LogCaptor.forClass(GreetingResource.class);

        new GreetingResource().hello();

        Assertions.assertThat(logCaptor.getLogs()).contains("Saying hello from the logger!");
    }

}

The above example works. If you need any help with it I can also create an example project so you can try it out yourself.

I also tried with the Quarkus test annotation, but than I am having a run time exception, see below:

import io.quarkus.test.junit.QuarkusTest;
import nl.altindag.log.LogCaptor;
import org.junit.jupiter.api.Test;

import static io.restassured.RestAssured.given;
import static org.assertj.core.api.Assertions.assertThatThrownBy;
import static org.hamcrest.Matchers.is;

@QuarkusTest
public class GreetingsResourceWithQuarkusTestShould {

    @Test
    void sayHello() {
        assertThatThrownBy(LogCaptor::forRoot)
                .isInstanceOf(IllegalArgumentException.class)
                .hasMessageContaining("Multiple classloaders are being used. " +
                        "The Logging API is created by the following classloader: [jdk.internal.loader.ClassLoaders$AppClassLoader], " +
                        "while it should have been created by the following classloader: [io.quarkus.bootstrap.classloading.QuarkusClassLoader].");

        given()
            .when().get("/hello")
            .then()
                .statusCode(200)
                .body(is("Hello from RESTEasy Reactive"));
    }

}

So the downside is you can not use Quarkus test and RestAssured if you want to test your business logic and also want to test your logs together in the same test file. I would advice to keep them separate and use the first working example for just asserting the logs. Hope this will help you. Please let me know if this will work for you

[Hakky54]

Hi @Jerilok

I gave a last attempt and I manage to get it working. It was troublesome, but it works for LogCaptor and ConsoleCaptor! I would still advice to go with ConsoleCaptor as it also works with the @QuarkusTest annotation. So forget all of my previous replies 😄

See here for a working demo:

• Unit testing logs with ConsoleCaptor while using Quarkus with Jboss logging and Lombok
• Unit testing logs with LogCaptor while using Quarkus with Jboss logging and Lombok

The steps below is for setting up console captor!

So what you need to do is:

1. Add logback-classic as test dependency
2. Add logback-test.xml as test resource
3. Configure surefire plugin to exclude their slf4j logging implementation

So your pom.xml should be something like this:

<dependencies>
    <dependency>
        <groupId>org.projectlombok</groupId>
        <artifactId>lombok</artifactId>
        <version>${version.lombok}</version>
    </dependency>
    <dependency>
        <groupId>org.jboss.logging</groupId>
        <artifactId>jboss-logging</artifactId>
        <version>${version.jboss-logging}</version>
    </dependency>

    <dependency>
        <groupId>io.quarkus</groupId>
        <artifactId>quarkus-resteasy-reactive</artifactId>
    </dependency>
    <dependency>
        <groupId>io.quarkus</groupId>
        <artifactId>quarkus-junit5</artifactId>
        <scope>test</scope>
    </dependency>
    <dependency>
        <groupId>io.rest-assured</groupId>
        <artifactId>rest-assured</artifactId>
        <scope>test</scope>
    </dependency>
    <dependency>
        <groupId>ch.qos.logback</groupId>
        <artifactId>logback-classic</artifactId>
        <version>${version.logback-classic}</version>
        <scope>test</scope>
    </dependency>
    <dependency>
        <groupId>io.github.hakky54</groupId>
        <artifactId>consolecaptor</artifactId>
        <version>${version.consolecaptor}</version>
        <scope>test</scope>
    </dependency>
    <dependency>
        <groupId>org.junit.jupiter</groupId>
        <artifactId>junit-jupiter-api</artifactId>
        <version>${version.junit}</version>
        <scope>test</scope>
    </dependency>
    <dependency>
        <groupId>org.junit.jupiter</groupId>
        <artifactId>junit-jupiter-engine</artifactId>
        <version>${version.junit}</version>
        <scope>test</scope>
    </dependency>
    <dependency>
        <groupId>org.assertj</groupId>
        <artifactId>assertj-core</artifactId>
        <version>${version.assertj-core}</version>
        <scope>test</scope>
    </dependency>
</dependencies>

<dependencyManagement>
    <dependencies>
        <dependency>
            <groupId>${quarkus.platform.group-id}</groupId>
            <artifactId>${quarkus.platform.artifact-id}</artifactId>
            <version>${quarkus.platform.version}</version>
            <type>pom</type>
            <scope>import</scope>
        </dependency>
    </dependencies>
</dependencyManagement>

<build>
    <plugins>
        <plugin>
            <artifactId>maven-surefire-plugin</artifactId>
            <version>${version.maven-surefire-plugin}</version>
            <configuration>
                <classpathDependencyExcludes>
                    <classpathDependencyExclude>org.jboss.slf4j:slf4j-jboss-logmanager</classpathDependencyExclude>
                </classpathDependencyExcludes>
            </configuration>
        </plugin>
        <plugin>
            <groupId>${quarkus.platform.group-id}</groupId>
            <artifactId>quarkus-maven-plugin</artifactId>
            <version>${quarkus.platform.version}</version>
            <executions>
                <execution>
                    <goals>
                        <goal>build</goal>
                    </goals>
                </execution>
            </executions>
        </plugin>
    </plugins>
</build>

Your logback-test.xml file should have the following content:

<configuration>

    <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>

    <root level="TRACE">
        <appender-ref ref="STDOUT" />
    </root>

</configuration>

This is an example greeting resource:

import lombok.extern.jbosslog.JBossLog;

import javax.ws.rs.GET;
import javax.ws.rs.Path;
import javax.ws.rs.Produces;
import javax.ws.rs.core.MediaType;

@JBossLog
@Path("/hello")
public class GreetingResource {

    @GET
    @Produces(MediaType.TEXT_PLAIN)
    public String hello() {
        log.info("Saying hello from the logger!");
        return "Hello from RESTEasy Reactive";
    }

}

And the working test class:

import io.quarkus.test.junit.QuarkusTest;
import nl.altindag.console.ConsoleCaptor;
import org.junit.jupiter.api.Test;

import java.util.List;

import static io.restassured.RestAssured.given;
import static org.assertj.core.api.Assertions.assertThat;
import static org.hamcrest.Matchers.is;
import static org.junit.jupiter.api.Assertions.assertTrue;

@QuarkusTest
public class GreetingsResourceShould {

    @Test
    void successfullyCapturesLogs() {
        try(ConsoleCaptor consoleCaptor = new ConsoleCaptor()) {

            new GreetingResource().hello();

            List<String> standardOutput = consoleCaptor.getStandardOutput();
            assertThat(standardOutput).isNotEmpty();
            assertTrue(standardOutput.stream().anyMatch(message -> message.contains("Saying hello from the logger!")));
        }
    }

    @Test
    void successfullyCapturesLogsAlternativeWhileUsingRestAssured() {
        try(ConsoleCaptor consoleCaptor = new ConsoleCaptor()) {

            given()
                    .when().get("/hello")
                    .then()
                    .statusCode(200)
                    .body(is("Hello from RESTEasy Reactive"));

            List<String> standardOutput = consoleCaptor.getStandardOutput();
            assertThat(standardOutput).isNotEmpty();
            assertTrue(standardOutput.stream().anyMatch(message -> message.contains("Saying hello from the logger!")));
        }
    }

}

Can you give it a try and share your results here?

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.