java.lang.NoClassDefFoundError: Unable to find Log4j2 as default logging library
logback+slf4j+log4jdbc를 사용하여 쿼리 로깅을 하고 있었다.
수정된 소스 배포를 하고 나면 항상 수동으로 WAS 재기동을 해줬어야 했는데
날을 잡고 트래킹 해보았다.
원인분석
에러로그
왜 log4jdbc에서 log4j를 찾는지 도대체가 이해할 수 없었다.
이미 전에도 구글링을 해보았지만 log4j를 추가하라는 등 나에게는 맞지 않는 내용 뿐이었다.
Caused by: org.springframework.beans.BeanInstantiationException: Failed to instantiate [com.zaxxer.hikari.HikariDataSource]: Constructor threw exception; nested exception is java.lang.NoClassDefFoundError: Unable to find Log4j2 as default logging library. Please provide a logging library and configure a valid spyLogDelegator name in the properties file.
at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:224)
at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:117)
at org.springframework.beans.factory.support.ConstructorResolver.instantiate(ConstructorResolver.java:311)
... 111 common frames omitted
Caused by: java.lang.NoClassDefFoundError: Unable to find Log4j2 as default logging library. Please provide a logging library and configure a valid spyLogDelegator name in the properties file.
at net.sf.log4jdbc.log.SpyLogFactory.loadSpyLogDelegator(SpyLogFactory.java:94)
at net.sf.log4jdbc.Properties.<clinit>(Properties.java:203)
at net.sf.log4jdbc.log.SpyLogFactory.getSpyLogDelegator(SpyLogFactory.java:69)
at net.sf.log4jdbc.sql.jdbcapi.DriverSpy.<clinit>(DriverSpy.java:135)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:348)
at java.sql.DriverManager.isDriverAllowed(DriverManager.java:556)
at java.sql.DriverManager.isDriverAllowed(DriverManager.java:548)
at java.sql.DriverManager.getDrivers(DriverManager.java:446)
at com.zaxxer.hikari.util.DriverDataSource.<init>(DriverDataSource.java:60)
at com.zaxxer.hikari.pool.PoolBase.initializeDataSource(PoolBase.java:331)
at com.zaxxer.hikari.pool.PoolBase.<init>(PoolBase.java:114)
at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:108)
at com.zaxxer.hikari.HikariDataSource.<init>(HikariDataSource.java:81)
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.springframework.beans.BeanUtils.instantiateClass(BeanUtils.java:211)
... 113 common frames omitted
SpyLogFactory.java 94 라인
그렇다!!
spyLogDelegatorName가 NULL일 경우 명성에 맞게 log4j를 기본으로 찾고 있었던 것이다.
그런데 왜 spyLogDelegatorName가 NULL일까?
SpyLogFactory.java
public static void loadSpyLogDelegator(String spyLogDelegatorName)
{
if (spyLogDelegatorName == null) {
try{
setSpyLogDelegator(new Log4j2SpyLogDelegator());
}
catch(NoClassDefFoundError e){
throw new NoClassDefFoundError("Unable to find Log4j2 as default logging library. " +
"Please provide a logging library and configure a valid spyLogDelegator name in the properties file."); // 94 라인
}
} else {
try {
Object loadedClass =
Class.forName(spyLogDelegatorName).newInstance();
if (loadedClass == null) {
throw new IllegalArgumentException(
"spyLogDelegatorName loads a null SpyLogDelegator");
}
setSpyLogDelegator((SpyLogDelegator) loadedClass);
} catch (Exception e) {
throw new IllegalArgumentException(
"spyLogDelegatorName does not allow to load a valid SpyLogDelegator: " +
e.getMessage());
} catch (NoClassDefFoundError e) {
throw new NoClassDefFoundError("Cannot find a library corresponding to the property log4jdbc.spylogdelegator.name. " +
"Please provide a logging library and configure a valid spyLogDelegator name in the properties file.");
}
}
}
Properties.java 203 라인
SpyLogDelegatorName이 NULL일 거라는 확신이 들었다.
그렇다면 getProperties() 메소드에서 log4jdbc.log4j2.properties를 제대로 로드하지 못할 가능성이 있다.
Properties.java
static final String SpyLogDelegatorName;
static
{
//first we init the logger
log = null;
//then we need the properties to define which logger to use
java.util.Properties props = getProperties();
SpyLogDelegatorName = props.getProperty("log4jdbc.spylogdelegator.name");
SpyLogFactory.loadSpyLogDelegator(getSpyLogDelegatorName()); // 203 라인
log = SpyLogFactory.getSpyLogDelegator();
Properties.java - getProperties()
getResourceAsStream을 보자마자 지난날 WAS 재기동을 했던 무수히 많은 날들이 떠올랐다.
문제는 너였어!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
Properties.java
private static java.util.Properties getProperties()
{
java.util.Properties props = new java.util.Properties(System.getProperties());
String propertyFile = props.getProperty("log4jdbc.log4j2.properties.file", "/log4jdbc.log4j2.properties");
if (log != null) {
log.debug("Trying to use properties file " + propertyFile);
}
InputStream propStream = Properties.class.getResourceAsStream(propertyFile);
원인분석 결과
WAS를 처음 구동하게되면 Properties.class.getResourceAsStream 가 올바로 로드 된다.
하지만 reload를 하게 되면 이미 로드된 WebAppClassLoader가 있으므로 jar내부에서 Resource를 찾았던 것이고 존재하지 않기 때문에 log4j를 로드하려 했던 것이다.
해결
매번 WAS를 재기동할 수도 없는 노릇이고 Properties.java를 수정하기로 했다.
Properties.java - getProperties() 수정
Thread로부터 ClassLoader를 가져오면 깔끔하게 해결된다.
Spring에서는 ClassPathResource를 제공하지만 참조하기 싫어서 직접 구현했다.
이렇게 하면 SpringBoot에서도 이상없이 동작했다.
Properties.java
private static java.util.Properties getProperties()
{
java.util.Properties props = new java.util.Properties(System.getProperties());
String propertyFile = props.getProperty("log4jdbc.log4j2.properties.file", "/log4jdbc.log4j2.properties");
if (log != null) {
log.debug("Trying to use properties file " + propertyFile);
}
//InputStream propStream = Properties.class.getResourceAsStream(propertyFile);
ClassLoader cl = Thread.currentThread().getContextClassLoader();
InputStream propStream = cl.getResourceAsStream("log4jdbc.log4j2.properties");
log4jdbc-log4j2-jdbc4.1-1.16.jar 의 클래스 교체
우선 WAS 재기동을 하지 않는데에만 집중했다.
반디집으로 jar를 열어서 Properties.class를 드래그앤드랍 하면 쉽게 교체할 수 있다.
이걸 WAS에 강제로 배포하면 향후엔 문제가 없을 것이다.
