[Spring] Hibernate에서 "Could not build ClassFile" 발생하는 오류 해결

안녕하세요, 하마연구소입니다.

spring-boot 버전 1.4.2에서 현재 1.X 버전 최고인 1.5.19로 업데이트 하였습니다.
한 프로젝트에 Maven 모듈로 여러 어플리케이션이 존재하는 구성입니다.
2개 어플리케이션만 제외하고 나머지 어플리케이션은 잘 수행됩니다.
이 2개 어플리케이션에서는 처음 로딩 중 아래와 같은 예외가 발생합니다.
더 특이한 것은 IDE에서 바로 실행시키면(로컬환경) 잘 됩니다.
서버환경에서만 안 됩니다.
환장하겠습니다.

Exception in thread "main" java.lang.ExceptionInInitializerError
 at com.hippolab.MyTopologyRunner.getApplicationContext(MyTopologyRunner.java:39)
 at com.hippolab.AbstractTopologyRunner.run(AbstractTopologyRunner.java:30)
 at com.hippolab.MyTopologyRunner.main(MyTopologyRunner.java:34)
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'entityManagerFactory' defined in class path resource [com/hippolab/config/MyDatabaseConfig.class]: Invocation of init method failed; nested exception is org.hibernate.boot.archive.spi.ArchiveException: Could not build ClassFile
 at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1628)
 at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:555)
 at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:483)
 at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306)
 at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
 at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302)
 at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
 at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1081)
 at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:856)
 at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:542)
 at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:737)
 at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:370)
 at org.springframework.boot.SpringApplication.run(SpringApplication.java:314)
 at com.hippolab.MyApplicationContext.<clinit>(MyApplicationContext.java:29)
 ... 3 more
Caused by: org.hibernate.boot.archive.spi.ArchiveException: Could not build ClassFile
 at org.hibernate.boot.archive.scan.spi.ClassFileArchiveEntryHandler.toClassFile(ClassFileArchiveEntryHandler.java:64)
 at org.hibernate.boot.archive.scan.spi.ClassFileArchiveEntryHandler.handleEntry(ClassFileArchiveEntryHandler.java:47)
 at org.hibernate.boot.archive.internal.JarFileBasedArchiveDescriptor.visitArchive(JarFileBasedArchiveDescriptor.java:152)
 at org.hibernate.boot.archive.scan.spi.AbstractScannerImpl.scan(AbstractScannerImpl.java:47)
 at org.hibernate.boot.model.process.internal.ScanningCoordinator.coordinateScan(ScanningCoordinator.java:75)
 at org.hibernate.boot.model.process.spi.MetadataBuildingProcess.prepare(MetadataBuildingProcess.java:98)
 at org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl.<init>(EntityManagerFactoryBuilderImpl.java:199)
 at org.hibernate.jpa.boot.spi.Bootstrap.getEntityManagerFactoryBuilder(Bootstrap.java:34)
 at org.hibernate.jpa.HibernatePersistenceProvider.getEntityManagerFactoryBuilder(HibernatePersistenceProvider.java:165)
 at org.hibernate.jpa.HibernatePersistenceProvider.getEntityManagerFactoryBuilder(HibernatePersistenceProvider.java:160)
 at org.hibernate.jpa.HibernatePersistenceProvider.createContainerEntityManagerFactory(HibernatePersistenceProvider.java:135)
 at org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean.createNativeEntityManagerFactory(LocalContainerEntityManagerFactoryBean.java:353)
 at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.buildNativeEntityManagerFactory(AbstractEntityManagerFactoryBean.java:370)
 at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.afterPropertiesSet(AbstractEntityManagerFactoryBean.java:359)
 at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1687)
 at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1624)
 ... 16 more 

entityManagerFactory을 빈으로 못만들었다는 오류입니다.
Hibernate를 이용한 JPA에서 사용하는 EntityManager 입니다.
핵심 오류 메시지는 "Caused by: org.hibernate.boot.archive.spi.ArchiveException: Could not build ClassFile" 입니다.

ClassFileArchiveEntryHandler.java 이 파일을 살펴보았습니다.

private ClassFile toClassFile(ArchiveEntry entry) {
   final InputStream inputStream = entry.getStreamAccess().accessInputStream();
   final DataInputStream dataInputStream = new DataInputStream( inputStream );
   try {
      return new ClassFile( dataInputStream );
   }
   catch (IOException e) {
      throw new ArchiveException( "Could not build ClassFile" );
   }
   finally {
      try {
         dataInputStream.close();
      }
      catch (Exception ignore) {
      }

      try {
         inputStream.close();
      }
      catch (IOException ignore) {
      }
   }
}

hibernate-core쪽 소스인데, ArchiveException을 발생시키는 곳에서 넘어온 IOException을 그냥 먹어버리고, 로그도 출력안하고 throw 하고있습니다.
결국 new ClassFile() 실행하다가 오류난 것인데, javassist 라이브러리이며, 자바 바이트코드를 다루는 기능입니다.
아마도 Hibernate가 로딩되면서 AOP 관련 바이트코드를 조작하다가 오류나는 것 같습니다.

그런데 왜? 넘어온 Exception을 먹어버리게 코딩해 놨냐고!!!

너무 답답해서 커맨드로 디버깅하려고 이것저것 정보를 습득하다가, 그냥 ClassFileArchiveEntryHandler.java 이 파일을 동일한 패키지에 만들어서 어플리케이션에 포함시켜버렸습니다.
물론 아래와 같이 변경하였습니다.

catch (IOException e) {
    throw new ArchiveException( "Could not build ClassFile", e );
}

그랬더니 다음 오류로그를 확인할 수 있었습니다.

Caused by: java.io.IOException: bad magic number: efbfbdef   at javassist.bytecode.ClassFile.read(ClassFile.java:825)   at javassist.bytecode.ClassFile.<init>(ClassFile.java:154)   at org.hibernate.boot.archive.scan.spi.ClassFileArchiveEntryHandler.toClassFile(ClassFileArchiveEntryHandler.java:60)   ... 31 more

Bytecode 조작을 위하여 런타임중에 만들어진 클래스파일의 매직넘버가 달라서 오류난 것으로 보입니다.
통밥으로 이런건 뭔가 JVM 버전, 라이브러리 버전, OS 버전 등의 문제일 가능성이 큽니다.

그런데 뭐가 잘못된건지 모르겠다.

계속해서 뚫어져라 쳐다보고 이것저것 바꿔가면서 해보았습니다.
얻은 중간 결론은 스프링부트 버전 1.5.2까지는 잘된다는 것입니다.
1.5.3부터 오류 발생합니다.

이 두 버전으로 패키징된 어플리케이션 파일을 하나하나 까보면서 어떤 라이브러리 버전이 잘못되었을까 확인해보았습니다.
분명 bytecode를 다루는 AOP, asm 등과 관련있을 것이고...

그러던 중 드디어 찾았다.

aspectjweaver와 aspectjtools 라이브러리가 동시에 포함되었는데, 이 두 라이브러리 내의 클래스 930개가 중복되어 있었습니다.
물론 다른 라이브러리들도 서로 중복되는 것이 몇 개 있었지만, AOP와 관련된 aspectj 라이브러리 중복을 해결해야만 할 것 같은 느낌이었습니다.

잘 수행되는 spring-boot 1.5.2에서는 aspectjweaver와 aspectjtools의 버전은 둘 다 1.8.9 입니다.
제가 지정하진 않았습니다.
spring-boot에서 기본으로 정의된 버전입니다.
오류가 발생하는 spring-boot 1.5.3에서는 aspectjweaver와 aspectjtools의 버전은 둘 다 1.8.10 입니다.

살펴보니 aspectjweaver은 스프링부트 spring-boot-starter-aop 에서 dependency로 포함된 것이고, aspectjtools은 어플리케이션에서 임의로 dependency 걸었습니다.
왜 그랬을까요?
모르겠습니다.
우선 aspectjtools 라이브러리 제거하고 실행해보니 잘됩니다.

너무 깔끔하게 잘된다.

spring-boot 버전 1.X의 현재 최신버전은 1.5.19에서도 잘됩니다.
우선 해결은 했고, aspectjtools 라이브러리를 진짜 제거해도 되나?
aspectjweaver와 aspectjtools의 기능을 살펴보니 aspectjtools는 포함시키지 않아도 됩니다.
아마도 spring-boot를 적용하지 않은 에전 소스코드를 복사해올 때, 그 잔재가 남은 것으로 보입니다.

하지만, 두 가지 의문이 생겼다.

왜 로컬환경에서는 될까?
같은 프로젝트에 포함된 어플리케이션인데, 왜 되는것이 있고 안되는 것이 있을까?

며칠동안 오류 해결하느라 너무 신경써서, 그냥 더 이상 따지지 않기로 했습니다.
예상되는 원인은, aspectjweaver와 aspectjtools 이 두 라이브러리 중에서 어떤 녀석이 먼저 로딩되느냐에 달라는 것 같습니다.
JVM 버전 다를수도 있고, 또는 각 어플리케이션 별로 dependency하는 라이브러리가 달라서 이것들을 클래스로더에 적재하는 순서가 다를수도 있습니다.

어쨌든 오류를 해결했다는 것에 만족하자!!!

감사합니다.