I have upgraded from Spring Boot 1.3.2 to 1.4.0, and now fail to start my application -
My BeanPostProcessor invokes the 3d party open source Lazy Chopper, which in turns, when attempting to getTransaction(), fails here:
public abstract class AbstractPlatformTransactionManager implements PlatformTransactionManager, Serializable {
protected transient Log logger = LogFactory.getLog(getClass());
// ...
@Override
public final TransactionStatus getTransaction(TransactionDefinition definition) throws TransactionException {
Object transaction = doGetTransaction();
// Cache debug flag to avoid repeated checks.
boolean debugEnabled = logger.isDebugEnabled(); // logger is null here
When I place a breakpoint right there, I can see logger is indeed null, but if it's worth mentioning that if I invoke LogFactory.getLog(getClass()) myself right there, I do get the right logger.
It seems as if somehow my bean's invoking that method prior to the right Logger being initialized?..
Here's the full stack trace I got:
Caused by: java.lang.NullPointerException: null
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:340) ~[spring-tx-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:426) ~[spring-tx-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:275) ~[spring-tx-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) ~[spring-tx-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168) ~[spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:85) ~[spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at com.tikal.lazychopper.DefaultLazyInitializationChopperAdvice.chop(DefaultLazyInitializationChopperAdvice.java:76) ~[lazy-chopper-1.2.8.jar:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_101]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_101]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_101]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_101]
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:629) ~[spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:618) ~[spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70) ~[spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168) ~[spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) ~[spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655) ~[spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at com.sapiens.bdms.core.service.impl.sign.hash.MD5StringCalculator$$EnhancerBySpringCGLIB$$b5747fb.getSignTypes(<generated>) ~[classes/:na]
at com.sapiens.bdms.core.service.impl.sign.EntitySignCalculatorManagerImpl.postProcessAfterInitialization(EntitySignCalculatorManagerImpl.java:105) ~[classes/:na]
at com.sapiens.bdms.core.service.impl.sign.EntitySignCalculatorManagerImpl$$FastClassBySpringCGLIB$$80ef4d8e.invoke(<generated>) ~[classes/:na]
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ~[spring-core-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:720) ~[spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) ~[spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) ~[spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:655) ~[spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at com.sapiens.bdms.core.service.impl.sign.EntitySignCalculatorManagerImpl$$EnhancerBySpringCGLIB$$91a9897b.postProcessAfterInitialization(<generated>) ~[classes/:na]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsAfterInitialization(AbstractAutowireCapableBeanFactory.java:422) ~[spring-beans-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1583) ~[spring-beans-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:545) ~[spring-beans-4.3.2.RELEASE.jar:4.3.2.RELEASE]
I'm using the default logback auto configuration, no tweaks.
Update #1: There's point cut defined around that method.
<aop:pointcut id="transactionManagerPointcut"
expression="(execution(* org.springframework.transaction.PlatformTransactionManager.getTransaction(..)))"/>
Update #2: So it seems getting rid of that aspect did the trick.. Still trying to figure out why and how to overcome this.
Here's aspect definition:
<aop:pointcut id="transactionManagerPointcut"
expression="(execution(* org.springframework.transaction.PlatformTransactionManager.getTransaction(..)))"/>
<aop:pointcut id="allServices"
expression="(execution(* com.decision..tx..*.*(..))) or (execution(* com.sapiens.bdms..tx..*.*(..))) && !@annotation(com.sapiens.bdms.core.persistence.annotation.NotTransactional)"/>
<aop:aspect ref="sessionFilterConfigurator">
<aop:before method="setupFilter"
pointcut-ref="allServices"/>
<aop:after-returning method="setupFilter"
pointcut-ref="transactionManagerPointcut"/>
</aop:aspect>
And here's the aspect method:
@Component("sessionFilterConfigurator")
public class SessionFilterConfigurator {
@Resource
private Collection<FilterConfiguration> filterConfigurations;
@Resource
private SessionFactory sessionFactory;
@Resource
private FiltersDisconnector filtersDisconnector;
public void setupFilter() throws Throwable {
Session session = sessionFactory.getCurrentSession();
if (AutoEnableConfig.isFiltersEnabled()) {
for (FilterConfiguration filterConfiguration : filterConfigurations) {
Filter filter = session.enableFilter(filterConfiguration.getFilterName());
for (Map.Entry<String, Object> entry : filterConfiguration.getFilterParameters().entrySet()) {
filter.setParameter(entry.getKey(), entry.getValue());
}
}
AutoEnableConfig.disableFilterEnabling();
((EventSource) session).getActionQueue().registerProcess(filtersDisconnector);
}
}
}
Still not clear as to why would that break the logger in this instance, and why only after upgrading to 1.4.0 ...
I had the very same problem. My fault was that due to wrong pointcut definition I ended up applying aspect onto TransactionManager (I had the standard one extended). So the null logger was the one of the CGLIB's generated extended class. The real bean had its logger nicely instantiated.