Closed
Description
Andrei Ivanov opened SPR-13886 and commented
Trying to upgrade Hibernate from 4.3.x to 5.0 throws this nice exception:
25-Jan-2016 13:34:10.985 SEVERE [localhost-startStop-2] org.apache.catalina.core.StandardContext.listenerStop Exception sending context destroyed event to listener instance of class org.springframework.web.context.ContextLoaderListener
java.lang.ClassCircularityError: org/apache/log4j/spi/ThrowableInformation
at org.apache.log4j.spi.LoggingEvent.<init>(LoggingEvent.java:165)
at org.apache.log4j.Category.forcedLog(Category.java:391)
at org.apache.log4j.Category.log(Category.java:856)
at org.slf4j.impl.Log4jLoggerAdapter.log(Log4jLoggerAdapter.java:595)
at org.apache.commons.logging.impl.SLF4JLocationAwareLog.error(SLF4JLocationAwareLog.java:216)
at org.springframework.orm.jpa.persistenceunit.ClassFileTransformerAdapter.transform(ClassFileTransformerAdapter.java:66)
at org.springframework.instrument.classloading.WeavingTransformer.transformIfNecessary(WeavingTransformer.java:95)
at org.springframework.instrument.classloading.WeavingTransformer.transformIfNecessary(WeavingTransformer.java:78)
at org.springframework.instrument.classloading.tomcat.TomcatInstrumentableClassLoader.findResourceInternal(TomcatInstrumentableClassLoader.java:127)
at org.apache.catalina.loader.WebappClassLoaderBase.findClassInternal(WebappClassLoaderBase.java:2427)
at org.apache.catalina.loader.WebappClassLoaderBase.findClass(WebappClassLoaderBase.java:860)
at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1302)
at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1167)
at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:963)
at org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:934)
at org.springframework.web.context.ContextLoader.closeWebApplicationContext(ContextLoader.java:583)
at org.springframework.web.context.ContextLoaderListener.contextDestroyed(ContextLoaderListener.java:116)
at org.apache.catalina.core.StandardContext.listenerStop(StandardContext.java:4859)
at org.apache.catalina.core.StandardContext.stopInternal(StandardContext.java:5478)
at org.apache.catalina.util.LifecycleBase.stop(LifecycleBase.java:232)
at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:160)
at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:725)
at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:701)
at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:717)
at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:945)
at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1795)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
It hides the actual ClassCircularityError, thrown here:
EnhancingClassTransformerImpl.transform(ClassLoader, String, Class<?>, ProtectionDomain, byte[]) line: 44
ClassFileTransformerAdapter.transform(ClassLoader, String, Class<?>, ProtectionDomain, byte[]) line: 56
WeavingTransformer.transformIfNecessary(String, String, byte[], ProtectionDomain) line: 95
WeavingTransformer.transformIfNecessary(String, byte[]) line: 78
TomcatInstrumentableClassLoader.findResourceInternal(String, String, boolean) line: 127
TomcatInstrumentableClassLoader(WebappClassLoaderBase).findClassInternal(String) line: 2427
TomcatInstrumentableClassLoader(WebappClassLoaderBase).findClass(String) line: 860
TomcatInstrumentableClassLoader(WebappClassLoaderBase).loadClass(String, boolean) line: 1302
TomcatInstrumentableClassLoader(WebappClassLoaderBase).loadClass(String) line: 1167
EnhancingClassTransformerImpl.transform(ClassLoader, String, Class<?>, ProtectionDomain, byte[]) line: 44
ClassFileTransformerAdapter.transform(ClassLoader, String, Class<?>, ProtectionDomain, byte[]) line: 56
WeavingTransformer.transformIfNecessary(String, String, byte[], ProtectionDomain) line: 95
WeavingTransformer.transformIfNecessary(String, byte[]) line: 78
TomcatInstrumentableClassLoader.findResourceInternal(String, String, boolean) line: 127
TomcatInstrumentableClassLoader(WebappClassLoaderBase).findClassInternal(String) line: 2427
TomcatInstrumentableClassLoader(WebappClassLoaderBase).findClass(String) line: 860
TomcatInstrumentableClassLoader(WebappClassLoaderBase).loadClass(String, boolean) line: 1302
TomcatInstrumentableClassLoader(WebappClassLoaderBase).loadClass(String) line: 1167
MetadataBuildingProcess.handleTypes(MetadataBuildingOptions) line: 327
MetadataBuildingProcess.complete(ManagedResources, MetadataBuildingOptions) line: 111
EntityManagerFactoryBuilderImpl.metadata() line: 847
EntityManagerFactoryBuilderImpl.build() line: 874
SpringHibernateJpaPersistenceProvider.createContainerEntityManagerFactory(PersistenceUnitInfo, Map) line: 60
LocalContainerEntityManagerFactoryBean.createNativeEntityManagerFactory() line: 343
LocalContainerEntityManagerFactoryBean(AbstractEntityManagerFactoryBean).afterPropertiesSet() line: 318
DefaultListableBeanFactory(AbstractAutowireCapableBeanFactory).invokeInitMethods(String, Object, RootBeanDefinition) line: 1637
DefaultListableBeanFactory(AbstractAutowireCapableBeanFactory).initializeBean(String, Object, RootBeanDefinition) line: 1574
DefaultListableBeanFactory(AbstractAutowireCapableBeanFactory).doCreateBean(String, RootBeanDefinition, Object[]) line: 545
DefaultListableBeanFactory(AbstractAutowireCapableBeanFactory).createBean(String, RootBeanDefinition, Object[]) line: 482
AbstractBeanFactory$1.getObject() line: 306
DefaultListableBeanFactory(DefaultSingletonBeanRegistry).getSingleton(String, ObjectFactory<?>) line: 230
DefaultListableBeanFactory(AbstractBeanFactory).doGetBean(String, Class<T>, Object[], boolean) line: 302
DefaultListableBeanFactory(AbstractBeanFactory).getBean(String) line: 197
XmlWebApplicationContext(AbstractApplicationContext).getBean(String) line: 1054
XmlWebApplicationContext(AbstractApplicationContext).finishBeanFactoryInitialization(ConfigurableListableBeanFactory) line: 829
XmlWebApplicationContext(AbstractApplicationContext).refresh() line: 538
ContextLoaderListener(ContextLoader).configureAndRefreshWebApplicationContext(ConfigurableWebApplicationContext, ServletContext) line: 446
ContextLoaderListener(ContextLoader).initWebApplicationContext(ServletContext) line: 328
ContextLoaderListener.contextInitialized(ServletContextEvent) line: 107
StandardContext.listenerStart() line: 4812
StandardContext.startInternal() line: 5255
StandardContext(LifecycleBase).start() line: 150
StandardHost(ContainerBase).addChildInternal(Container) line: 725
StandardHost(ContainerBase).addChild(Container) line: 701
StandardHost.addChild(Container) line: 717
HostConfig.deployWAR(ContextName, File) line: 945
HostConfig$DeployWar.run() line: 1795
Executors$RunnableAdapter<T>.call() line: 511
FutureTask<V>.run() line: 266
ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker) line: 1142
ThreadPoolExecutor$Worker.run() line: 617
Thread.run() line: 745
MetadataBuildingProcess.handleTypes(MetadataBuildingOptions) line: 327 -> triggers loading of org.hibernate.type.BasicTypeRegistry
1st. call to EnhancingClassTransformerImpl.transform(ClassLoader, String, Class<?>, ProtectionDomain, byte[]) line: 44 triggers the loading of org.hibernate.bytecode.enhance.spi.Enhancer
2nd. call triggers the ClassCircularityError
Investigating the issue, I see that org.hibernate.jpa.boot.internal.EntityManagerFactoryBuilderImpl calls persistenceUnit.getTempClassLoader(),
which ends up in org.springframework.instrument.classloading.ReflectiveLoadTimeWeaver#getThrowawayClassLoader, invoking
org.springframework.instrument.classloading.tomcat.TomcatInstrumentableClassLoader#getThrowawayClassLoader.
In theory, this should handle this scenario.
There are 2 problems here:
- It returns
org.apache.catalina.loader.WebappClassLoader, which is not aDecoratingClassLoader, so the exclude package (org.hibernate) is not set:
SpringPersistenceUnitInfo#getNewTempClassLoader
public ClassLoader getNewTempClassLoader() {
ClassLoader tcl = (this.loadTimeWeaver != null ? this.loadTimeWeaver.getThrowawayClassLoader() :
new SimpleThrowawayClassLoader(this.classLoader));
String packageToExclude = getPersistenceProviderPackageName();
if (packageToExclude != null && tcl instanceof DecoratingClassLoader) {
((DecoratingClassLoader) tcl).excludePackage(packageToExclude);
}
return tcl;
}Even if it did, just org.hibernate wouldn't be enough here.
- This temp classloader is no longer used when the error occurs
EntityManagerFactoryBuilderImpl, on line 227, pushes the class transformer but 3 lines after (230) it sets the temp classloader to null.
After this,EntityManagerFactoryBuilderImpl#buildis called, and that triggers the error.
Now for the workaround.
Inspired by the AspectJClassBypassingClassFileTransformer, I've created my own:
public class HibernateClassBypassingLoadTimeWeaver implements LoadTimeWeaver {
private final LoadTimeWeaver loadTimeWeaver;
public HibernateClassBypassingLoadTimeWeaver(LoadTimeWeaver loadTimeWeaver) {
Assert.notNull(loadTimeWeaver);
this.loadTimeWeaver = loadTimeWeaver;
}
@Override
public ClassLoader getInstrumentableClassLoader() {
return loadTimeWeaver.getInstrumentableClassLoader();
}
@Override
public ClassLoader getThrowawayClassLoader() {
return loadTimeWeaver.getThrowawayClassLoader();
}
@Override
public void addTransformer(ClassFileTransformer transformer) {
loadTimeWeaver.addTransformer(new HibernateClassBypassingClassFileTransformer(transformer));
}
/**
* ClassFileTransformer decorator that suppresses processing of Hibernate
* classes in order to avoid potential LinkageErrors.
* @see org.springframework.context.annotation.LoadTimeWeavingConfiguration
*/
private static class HibernateClassBypassingClassFileTransformer implements ClassFileTransformer {
private static final Logger LOGGER = LoggerFactory.getLogger(HibernateClassBypassingClassFileTransformer.class);
private final ClassFileTransformer delegate;
public HibernateClassBypassingClassFileTransformer(ClassFileTransformer delegate) {
this.delegate = delegate;
}
@Override
public byte[] transform(ClassLoader loader, String className, Class<?> classBeingRedefined, ProtectionDomain protectionDomain, byte[] classfileBuffer)
throws IllegalClassFormatException {
if (className.startsWith("org.hibernate") || className.startsWith("org/hibernate") || className.startsWith("javassist")) {
LOGGER.trace("Bypassing class: {}", className);
return classfileBuffer;
}
return this.delegate.transform(loader, className, classBeingRedefined, protectionDomain, classfileBuffer);
}
}As you can see in the code, ignoring just the Hibernate classes isn't enough, the Javassist classes must also be ignored.
The problem with the workaround so far is that it cannot injected:
<context:load-time-weaver />
<bean id="testEmf" class="org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean">
<property name="dataSource" ref="testDS" />
<property name="jpaVendorAdapter">
<bean class="org.springframework.orm.jpa.vendor.HibernateJpaVendorAdapter" />
</property>
<!-- this is normally initialized from the jpaVendorAdapter in afterPropertiesSet(), but it is needed earlier
by the post-processor -->
<property name="jpaDialect">
<bean class="org.springframework.orm.jpa.vendor.HibernateJpaDialect" />
</property>
<property name="persistenceUnitName" value="testPU" />
<property name="jpaPropertyMap">
<map>
<entry key="hibernate.dialect" value="org.hibernate.dialect.MySQL5InnoDBDialect" />
<entry key="hibernate.enable_lazy_load_no_trans" value="true" />
<!-- this deprecated setting enables all 3 new setting following -->
<entry key="hibernate.ejb.use_class_enhancer" value="true" />
<!--
<entry key="hibernate.enhancer.enableDirtyTracking" value="true" />
<entry key="hibernate.enhancer.enableLazyInitialization" value="true" />
<entry key="hibernate.enhancer.enableAssociationManagement" value="true" />
-->
<entry key="hibernate.id.new_generator_mappings" value="false" />
</map>
</property>
<property name="packagesToScan">
<list>
<value>org.springframework.issues.entity</value>
</list>
</property>
<property name="loadTimeWeaver">
<bean class="org.springframework.issues.hibernate.HibernateClassBypassingLoadTimeWeaver">
<constructor-arg ref="loadTimeWeaver" />
</bean>
</property>
</bean>My LTW initially gets injected, but then the LoadTimeWeaverAwareProcessor comes along and injects back the original LTW (DefaultContextLoadTimeWeaver).
I even tried with a DefaultPersistenceUnitManager, but that also implements LoadTimeWeaverAware.
So, to get my LTW injected, I've created my own processor:
public class HibernateLoadTimeWeaverAwareProcessor implements BeanPostProcessor {
private static final Logger LOGGER = LoggerFactory.getLogger(HibernateLoadTimeWeaverAwareProcessor.class);
private final LoadTimeWeaver loadTimeWeaver;
public HibernateLoadTimeWeaverAwareProcessor(LoadTimeWeaver loadTimeWeaver) {
this.loadTimeWeaver = new HibernateClassBypassingLoadTimeWeaver(loadTimeWeaver);
}
@Override
public Object postProcessBeforeInitialization(Object bean, String beanName) throws BeansException {
if (bean instanceof LoadTimeWeaverAware && bean instanceof EntityManagerFactoryInfo) {
JpaDialect jpaDialect = ((EntityManagerFactoryInfo) bean).getJpaDialect();
boolean isHibernate = jpaDialect instanceof HibernateJpaDialect;
LOGGER.info("EMF {} has Hibernate dialect: {}", bean, isHibernate);
if (isHibernate) {
LOGGER.info("Injecting custom LTW: {}", loadTimeWeaver);
((LoadTimeWeaverAware) bean).setLoadTimeWeaver(loadTimeWeaver);
}
}
return bean;
}
@Override
public Object postProcessAfterInitialization(Object bean, String beanName) throws BeansException {
return bean;
}
}This finally makes it run.
So, did I miss something in the configuration?
Is this supposed to run using standard Spring configuration?
Or maybe Hibernate + bytecode enhancement wasn't tested thoroughly?
The app is running inside a Tomcat 8.0.30 with LTW active.
Affects: 4.2.4
Issue Links:
- LocalSessionFactoryBean (hibernate5) does not correctly pass custom ClassLoader to Hibernate [SPR-13879] #18452 LocalSessionFactoryBean (hibernate5) does not correctly pass custom ClassLoader to Hibernate
- Detect LoadTimeWeaver bean when declared through @Bean method as well [SPR-10856] #15483 Detect LoadTimeWeaver bean when declared through
@Beanmethod as well - Documentation for running hibernate with bytecode enhancement on a spring stack [SPR-17089] #21626 Documentation for running hibernate with bytecode enhancement on a spring stack
- Doc: Load-time weaving limitations with Tomcat and Hibernate [SPR-7440] #12098 Doc: Load-time weaving limitations with Tomcat and Hibernate
- Compatibility with Hibernate ORM 5.1 [SPR-13480] #18059 Compatibility with Hibernate ORM 5.1
- Callback interfaces such as LoadTimeWeaverAware should allow for local overriding [SPR-13892] #18466 Callback interfaces such as LoadTimeWeaverAware should allow for local overriding
Referenced from: pull request spring-attic/spring-framework-issues#117, and commits bdb9473, 836a321, b82df14
0 votes, 5 watchers