Logging With Log4j2

Why Logs

When a nightly test fails at 2 AM, the log is the first thing you read. System.out.println has no levels, no timestamps and no thread names. Log4j2 gives all three and can write to the console and a file at the same time.

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

log4j2.xml

Example

src/test/resources/log4j2.xml

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
  <Appenders>
    <Console name="Console" target="SYSTEM_OUT">
      <PatternLayout pattern="%d{HH:mm:ss.SSS} %-5level [%t] %c{1} - %msg%n"/>
    </Console>
    <File name="File" fileName="target/logs/test-run.log">
      <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss} %-5level [%t] %c{1} - %msg%n"/>
    </File>
  </Appenders>
  <Loggers>
    <Root level="info">
      <AppenderRef ref="Console"/>
      <AppenderRef ref="File"/>
    </Root>
  </Loggers>
</Configuration>

Logging From Pages and Tests

public class CartPage extends BasePage {
    private static final Logger log = LogManager.getLogger(CartPage.class);

    public CheckoutPage proceedToCheckout() {
        log.info("Cart has {} item(s), clicking checkout", text(By.id("cart-count")));
        click(By.id("checkout"));
        return new CheckoutPage(driver);
    }
}

Example

Console output with two parallel threads:

mvn test -Dgroups=smoke

Example output

10:31:02.114 INFO  [TestNG-methods-1] LoginPage - Logging in as [email protected]
10:31:02.120 INFO  [TestNG-methods-2] SearchPage - Searching for 'headphones'
10:31:04.871 INFO  [TestNG-methods-2] CartPage - Cart has 1 item(s), clicking checkout
10:31:05.302 ERROR [TestNG-methods-1] TestListener - FAILED validLogin: expected [Welcome, Asha] but found []

Tip: Never log passwords, OTPs or card numbers, even in QA. Mask them: log.info("password: ******").