I’m trying to use spring boot starter and spring boot starter web. So far I’ve got what I think is a pretty simple set up. I can see that the application is obviously finding and using the log4j2-spring.xml file so my question is why doesn’t anything from the MyRunner class log via log4j2? It does execute and the System.out.println() statements are writing to the console but the LOG.error messages are not. Please help.
pom.xml:
<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
<modelVersion>4.0.0</modelVersion>
<parent>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-parent</artifactId>
<version>2.2.1.RELEASE</version>
<relativePath />
</parent>
<groupId>com.demo</groupId>
<artifactId>demo</artifactId>
<version>0.0.1</version>
<name>iim</name>
<description>Demo</description>
<properties>
<java.version>1.8</java.version>
<maven-jar-plugin.version>3.1.1</maven-jar-plugin.version>
</properties>
<dependencies>
<dependency>
<groupId>org.apache.commons</groupId>
<artifactId>commons-lang3</artifactId>
</dependency>
<dependency>
<groupId>org.apache.commons</groupId>
<artifactId>commons-dbcp2</artifactId>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter</artifactId>
<exclusions>
<exclusion>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-logging</artifactId>
</exclusion>
</exclusions>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-devtools</artifactId>
<scope>runtime</scope>
<optional>true</optional>
</dependency>
<dependency>
<groupId>org.mybatis.spring.boot</groupId>
<artifactId>mybatis-spring-boot-starter</artifactId>
<version>2.1.1</version>
</dependency>
<dependency>
<groupId>org.springframework</groupId>
<artifactId>spring-context</artifactId>
</dependency>
<dependency>
<groupId>org.springframework</groupId>
<artifactId>spring-beans</artifactId>
</dependency>
<dependency>
<groupId>org.springframework</groupId>
<artifactId>spring-jdbc</artifactId>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-test</artifactId>
<scope>test</scope>
<exclusions>
<exclusion>
<groupId>org.junit.vintage</groupId>
<artifactId>junit-vintage-engine</artifactId>
</exclusion>
</exclusions>
</dependency>
<dependency>
<groupId>mysql</groupId>
<artifactId>mysql-connector-java</artifactId>
<scope>runtime</scope>
</dependency>
<dependency>
<groupId>org.liquibase</groupId>
<artifactId>liquibase-core</artifactId>
</dependency>
</dependencies>
<build>
<plugins>
<plugin>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-maven-plugin</artifactId>
</plugin>
</plugins>
</build>
</project>
log4j2-spring.xml:
<Properties>
<Property name="LOG_PATTERN">
%d{yyyy-MM-dd HH:mm:ss,SSS} [%t] %-5p [%F:%L] %m%n
</Property>
</Properties>
<Appenders>
<Console name="ConsoleAppender" target="SYSTEM_OUT" follow="true">
<PatternLayout pattern="${LOG_PATTERN}"/>
</Console>
</Appenders>
<Loggers>
<logger name="org.springframework" level="WARN" />
<logger name="org.apache.ibatis.logging.jdbc.BaseJdbcLogger" level="ERROR" />
<logger name="java.sql" level="ERROR" />
<logger name="org.mybatis" level="ERROR" />
<Root level="INFO">
<AppenderRef ref="ConsoleAppender" />
</Root>
</Loggers>
Application.java:
import java.util.stream.Stream;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.boot.CommandLineRunner;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.context.annotation.ComponentScan;
import org.springframework.stereotype.Component;
@SpringBootApplication
@ComponentScan("com.demo")
public class Application {
private static final Logger LOG = LoggerFactory.getLogger(Application.class);
public static void main(String[] args) {
LOG.warn("********** Starting the application");
SpringApplication.run(Application.class, args);
}
@Component
public class MyRunner implements CommandLineRunner {
@Override
public void run(String... args) throws Exception {
System.out.println(String.format("%s!!!", "HELLO WORLD"));
LOG.error(String.format("%s!!!", "HELLO WORLD"));
Stream.of("John Travolta", "Julia Childs", "Jennifer Anniston", "Helen Hunt", "Rachel Green").forEach(n -> {
System.out.println(n);
LOG.error(n);
});
}
}
}
Console Output:
2019-12-11 10:08:12,294 [restartedMain] INFO [DirectJDKLog.java:173] Initializing ProtocolHandler ["http-nio-8080"] 2019-12-11 10:08:12,296 [restartedMain] INFO [DirectJDKLog.java:173] Starting service [Tomcat] 2019-12-11 10:08:12,297 [restartedMain] INFO [DirectJDKLog.java:173] Starting Servlet engine: [Apache Tomcat/9.0.27] 2019-12-11 10:08:12,377 [restartedMain] INFO [DirectJDKLog.java:173] Initializing Spring embedded WebApplicationContext 2019-12-11 10:08:12,818 [restartedMain] INFO [HikariDataSource.java:110] HikariPool-1 - Starting... 2019-12-11 10:08:12,968 [restartedMain] INFO [HikariDataSource.java:123] HikariPool-1 - Start completed. 2019-12-11 10:08:13,407 [restartedMain] INFO [Slf4jLogger.java:42] SELECT COUNT(*) FROM db_example.DATABASECHANGELOGLOCK 2019-12-11 10:08:13,413 [restartedMain] INFO [Slf4jLogger.java:42] SELECT COUNT(*) FROM db_example.DATABASECHANGELOGLOCK 2019-12-11 10:08:13,415 [restartedMain] INFO [Slf4jLogger.java:42] SELECT `LOCKED` FROM db_example.DATABASECHANGELOGLOCK WHERE ID=1 2019-12-11 10:08:13,428 [restartedMain] INFO [Slf4jLogger.java:42] Successfully acquired change log lock 2019-12-11 10:08:13,967 [restartedMain] INFO [Slf4jLogger.java:42] Reading resource: com/demo/db/liquibase/tables/user.sql 2019-12-11 10:08:14,014 [restartedMain] INFO [Slf4jLogger.java:42] SELECT MD5SUM FROM db_example.DATABASECHANGELOG WHERE MD5SUM IS NOT NULL LIMIT 1 2019-12-11 10:08:14,015 [restartedMain] INFO [Slf4jLogger.java:42] SELECT COUNT(*) FROM db_example.DATABASECHANGELOG 2019-12-11 10:08:14,016 [restartedMain] INFO [Slf4jLogger.java:42] Reading from db_example.DATABASECHANGELOG 2019-12-11 10:08:14,016 [restartedMain] INFO [Slf4jLogger.java:42] SELECT * FROM db_example.DATABASECHANGELOG ORDER BY DATEEXECUTED ASC, ORDEREXECUTED ASC 2019-12-11 10:08:14,025 [restartedMain] INFO [Slf4jLogger.java:42] Successfully released change log lock 2019-12-11 10:08:14,087 [restartedMain] INFO [DirectJDKLog.java:173] Starting ProtocolHandler ["http-nio-8080"] HELLO WORLD!!! John Travolta Julia Childs Jennifer Anniston Helen Hunt Rachel Green
Advertisement
Answer
I tried your code with few changes to work on my IDE, and it is working perfectly fine, below is the updated code, this code may help you to dig down your issue:
package com.example.demo;
import java.util.stream.Stream;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.boot.CommandLineRunner;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.stereotype.Component;
@SpringBootApplication
public class Application {
private static final Logger LOG = LoggerFactory.getLogger(Application.class);
public static void main(String[] args) {
LOG.warn("********** Starting the application");
SpringApplication.run(Application.class, args);
}
@Component
public class MyRunner implements CommandLineRunner {
@Override
public void run(String... args) throws Exception {
System.out.println(String.format("%s!!!", "HELLO WORLD"));
LOG.error(String.format("%s!!!", "HELLO WORLD"));
Stream.of("John Travolta", "Julia Childs", "Jennifer Anniston", "Helen Hunt", "Rachel Green").forEach(n -> {
System.out.println(n);
LOG.error(n);
});
}
}
}
I have kept below log xml(log4j2-spring.xml) under – src/main/resource
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="INFO">
<Properties>
<Property name="LOG_PATTERN">
%d{yyyy-MM-dd HH:mm:ss,SSS} [%t] %-5p [%F:%L] %m%n
</Property>
</Properties>
<Appenders>
<Console name="ConsoleAppender" target="SYSTEM_OUT" follow="true">
<PatternLayout pattern="shree - ${LOG_PATTERN}"/>
</Console>
</Appenders>
<Loggers>
<logger name="org.springframework" level="WARN" />
<logger name="org.apache.ibatis.logging.jdbc.BaseJdbcLogger" level="ERROR" />
<logger name="java.sql" level="ERROR" />
<logger name="org.mybatis" level="ERROR" />
<Root level="INFO">
<AppenderRef ref="ConsoleAppender" />
</Root>
</Loggers>
</Configuration>
Removed mybatis and jdbc dependencies as spring was asking for db configuration. Those Jar might be causing the issues in your code(overriding your log configurations):
<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
<modelVersion>4.0.0</modelVersion>
<parent>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-parent</artifactId>
<version>2.2.1.RELEASE</version>
<relativePath/> <!-- lookup parent from repository -->
</parent>
<groupId>com.example</groupId>
<artifactId>demo</artifactId>
<version>0.0.1-SNAPSHOT</version>
<name>demo</name>
<description>Demo project for Spring Boot</description>
<properties>
<java.version>1.8</java.version>
<maven-jar-plugin.version>3.1.1</maven-jar-plugin.version>
</properties>
<dependencies>
<dependency>
<groupId>org.apache.commons</groupId>
<artifactId>commons-lang3</artifactId>
</dependency>
<!-- <dependency>
<groupId>org.apache.commons</groupId>
<artifactId>commons-dbcp2</artifactId>
</dependency> -->
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter</artifactId>
<exclusions>
<exclusion>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-logging</artifactId>
</exclusion>
</exclusions>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-web</artifactId>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-devtools</artifactId>
<scope>runtime</scope>
<optional>true</optional>
</dependency>
<!-- <dependency>
<groupId>org.mybatis.spring.boot</groupId>
<artifactId>mybatis-spring-boot-starter</artifactId>
<version>2.1.1</version>
</dependency> -->
<dependency>
<groupId>org.springframework</groupId>
<artifactId>spring-context</artifactId>
</dependency>
<dependency>
<groupId>org.springframework</groupId>
<artifactId>spring-beans</artifactId>
</dependency>
<!-- <dependency>
<groupId>org.springframework</groupId>
<artifactId>spring-jdbc</artifactId>
</dependency>
-->
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-test</artifactId>
<scope>test</scope>
<exclusions>
<exclusion>
<groupId>org.junit.vintage</groupId>
<artifactId>junit-vintage-engine</artifactId>
</exclusion>
</exclusions>
</dependency>
<!-- <dependency>
<groupId>mysql</groupId>
<artifactId>mysql-connector-java</artifactId>
<scope>runtime</scope>
</dependency>
<dependency>
<groupId>org.liquibase</groupId>
<artifactId>liquibase-core</artifactId>
</dependency> -->
</dependencies>
<build>
<plugins>
<plugin>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-maven-plugin</artifactId>
</plugin>
</plugins>
</build>
</project>
output:
. ____ _ __ _ _ /\ / ___'_ __ _ _(_)_ __ __ _ ( ( )___ | '_ | '_| | '_ / _` | \/ ___)| |_)| | | | | || (_| | ) ) ) ) ' |____| .__|_| |_|_| |___, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot :: (v2.2.1.RELEASE) shree - 2019-12-11 22:58:03,221 [restartedMain] INFO [StartupInfoLogger.java:55] Starting Application on LAPTOP-FS2FJ2C3 with PID 6044 (C:Usersshrireclipse-workspace-jee-codedemotargetclasses started by shrir in C:Usersshrireclipse-workspace-jee-codedemo) shree - 2019-12-11 22:58:03,228 [restartedMain] INFO [SpringApplication.java:651] No active profile set, falling back to default profiles: default shree - 2019-12-11 22:58:04,014 [restartedMain] INFO [DirectJDKLog.java:173] Initializing ProtocolHandler ["http-nio-8080"] shree - 2019-12-11 22:58:04,014 [restartedMain] INFO [DirectJDKLog.java:173] Starting service [Tomcat] shree - 2019-12-11 22:58:04,015 [restartedMain] INFO [DirectJDKLog.java:173] Starting Servlet engine: [Apache Tomcat/9.0.27] shree - 2019-12-11 22:58:04,074 [restartedMain] INFO [DirectJDKLog.java:173] Initializing Spring embedded WebApplicationContext shree - 2019-12-11 22:58:04,402 [restartedMain] INFO [DirectJDKLog.java:173] Starting ProtocolHandler ["http-nio-8080"] shree - 2019-12-11 22:58:04,423 [restartedMain] INFO [StartupInfoLogger.java:61] Started Application in 1.478 seconds (JVM running for 2.412) HELLO WORLD!!! shree - 2019-12-11 22:58:04,424 [restartedMain] ERROR [Application.java:36] HELLO WORLD!!! John Travolta shree - 2019-12-11 22:58:04,424 [restartedMain] ERROR [Application.java:40] John Travolta Julia Childs shree - 2019-12-11 22:58:04,424 [restartedMain] ERROR [Application.java:40] Julia Childs Jennifer Anniston shree - 2019-12-11 22:58:04,425 [restartedMain] ERROR [Application.java:40] Jennifer Anniston Helen Hunt shree - 2019-12-11 22:58:04,425 [restartedMain] ERROR [Application.java:40] Helen Hunt Rachel Green shree - 2019-12-11 22:58:04,425 [restartedMain] ERROR [Application.java:40] Rachel Green
This might not be your solution, but will help you to find the issue.
Adding code in Answer section as cant explain in comment section