mybatis / cdi

MyBatis CDI Extension
Apache License 2.0
25 stars 19 forks source link

NullPointerException in stacktrace when deploying an EJB with an Injected Mapper om TomEE #40

Closed mcbeelen closed 7 years ago

mcbeelen commented 8 years ago

We have a stateless bean part of our deployment and we use MyBatis CDI to inject a Mapper:

@Stateless
public class MyBatisMerchantOrderRepository implements MerchantOrderRepository {
    @Inject
    @Mapper
    private MerchantOrderMapper mapper;

    public MyBatisMerchantOrderRepository() {
    }
}

When we deploy this, we see the following stacktrace, but the application does work as it is supposed to do.

Caused by: java.lang.NullPointerException: null
    at org.mybatis.cdi.SerializableMapperProxy.getMapper(SerializableMapperProxy.java:61)
    at org.mybatis.cdi.SerializableMapperProxy.<init>(SerializableMapperProxy.java:47)
    at org.mybatis.cdi.MyBatisBean.create(MyBatisBean.java:117)
    at org.apache.webbeans.component.third.ThirdpartyBeanImpl.create(ThirdpartyBeanImpl.java:96)
    at org.apache.webbeans.context.DependentContext.getInstance(DependentContext.java:68)
    at org.apache.webbeans.context.AbstractContext.get(AbstractContext.java:125)
    at org.apache.webbeans.container.BeanManagerImpl.getReference(BeanManagerImpl.java:754)
    at org.apache.webbeans.container.BeanManagerImpl.getInjectableReference(BeanManagerImpl.java:628)
    at org.apache.webbeans.inject.AbstractInjectable.inject(AbstractInjectable.java:95)
    at org.apache.webbeans.inject.InjectableField.doInjection(InjectableField.java:65)
    at org.apache.webbeans.portable.InjectionTargetImpl.injectFields(InjectionTargetImpl.java:208)
    at org.apache.webbeans.portable.InjectionTargetImpl.inject(InjectionTargetImpl.java:194)
    at org.apache.webbeans.portable.InjectionTargetImpl.inject(InjectionTargetImpl.java:184)
    at org.apache.openejb.cdi.CdiEjbBean$EjbInjectionTargetImpl.inject(CdiEjbBean.java:388)
    at org.apache.openejb.BeanContext.inject(BeanContext.java:1660)
    at org.apache.openejb.BeanContext.newInstance(BeanContext.java:1489)
    at org.apache.openejb.core.stateless.StatelessInstanceManager.createInstance(StatelessInstanceManager.java:207)
    at org.apache.openejb.core.stateless.StatelessInstanceManager.getInstance(StatelessInstanceManager.java:199)
    at org.apache.openejb.core.stateless.StatelessContainer.invoke(StatelessContainer.java:186)
    at org.apache.openejb.core.ivm.EjbObjectProxyHandler.synchronizedBusinessMethod(EjbObjectProxyHandler.java:317)
    at org.apache.openejb.core.ivm.EjbObjectProxyHandler.businessMethod(EjbObjectProxyHandler.java:312)
    at org.apache.openejb.core.ivm.EjbObjectProxyHandler._invoke(EjbObjectProxyHandler.java:92)
    at org.apache.openejb.core.ivm.BaseEjbProxyHandler.invoke(BaseEjbProxyHandler.java:325)
mnesarco commented 7 years ago

If this happens only at deploy time, it looks like the ejb container is instantiating the cdi proxy before some CDI scoped resources are in place, but at that time no real mapper method is called. So if the stateless bean is then returned to the pool just to wait for a client, the proxy will be serialized and then deserialized when a real client uses the stateless bean, but at that time all the CDI beans are ready so it works. Its just a theory, apparently this case is not present in weld, maybe only in webbeans?

mcbeelen commented 7 years ago

Recently we change some of the design of our application. Since we made that change this issue has resurfaced and now it is interfering with the proper functionality of our application.

We have a MessageDrivenBean (the Receiver) in our application, which receives a JMS Message and delegates processing that message to another Stateless Session Bean(the MessageRouter). After going through some of our classes it will invoke a method on a another Stateless Session Bean (the MyBatisPaymentRequestRepository), which needs the Mapper.

The injection of the Mapper into the constructed MyBatisPaymentRequestRepository fails due to this NullPointerException in getting the Mapper from the SerializableMapperProxy. After some time the initialization of the SerializableMapperProxy or the SqlSessionFactory is complete and then the application is going to work properly, but processing the first couple of JMS-message has already failed.

2017-01-25 15:27:33 [Default JMS Resource Adapter-worker- - 7] ERROR OpenEJB - The bean instance MyBatisPaymentRequestRepository threw a system exception:java.lang.NullPointerException
java.lang.NullPointerException: null
    at org.mybatis.cdi.SerializableMapperProxy.getMapper(SerializableMapperProxy.java:61)
    at org.mybatis.cdi.SerializableMapperProxy.<init>(SerializableMapperProxy.java:47)
    at org.mybatis.cdi.MyBatisBean.create(MyBatisBean.java:117)
    at org.apache.webbeans.component.third.ThirdpartyBeanImpl.create(ThirdpartyBeanImpl.java:96)
    at org.apache.webbeans.context.DependentContext.getInstance(DependentContext.java:68)
    at org.apache.webbeans.context.AbstractContext.get(AbstractContext.java:125)
    at org.apache.webbeans.container.BeanManagerImpl.getReference(BeanManagerImpl.java:754)
    at org.apache.webbeans.container.BeanManagerImpl.getInjectableReference(BeanManagerImpl.java:628)
    at org.apache.webbeans.inject.AbstractInjectable.inject(AbstractInjectable.java:95)
    at org.apache.webbeans.inject.InjectableField.doInjection(InjectableField.java:65)
    at org.apache.webbeans.portable.InjectionTargetImpl.injectFields(InjectionTargetImpl.java:208)
    at org.apache.webbeans.portable.InjectionTargetImpl.inject(InjectionTargetImpl.java:194)
    at org.apache.webbeans.portable.InjectionTargetImpl.inject(InjectionTargetImpl.java:184)
    at org.apache.openejb.cdi.CdiEjbBean$EjbInjectionTargetImpl.inject(CdiEjbBean.java:388)
    at org.apache.openejb.BeanContext.inject(BeanContext.java:1660)
    at org.apache.openejb.BeanContext.newInstance(BeanContext.java:1489)
    at org.apache.openejb.core.stateless.StatelessInstanceManager.createInstance(StatelessInstanceManager.java:207)
    at org.apache.openejb.core.stateless.StatelessInstanceManager.getInstance(StatelessInstanceManager.java:199)
    at org.apache.openejb.core.stateless.StatelessContainer.invoke(StatelessContainer.java:186)
    at org.apache.openejb.core.ivm.EjbObjectProxyHandler.synchronizedBusinessMethod(EjbObjectProxyHandler.java:317)
    at org.apache.openejb.core.ivm.EjbObjectProxyHandler.businessMethod(EjbObjectProxyHandler.java:312)
    at org.apache.openejb.core.ivm.EjbObjectProxyHandler._invoke(EjbObjectProxyHandler.java:92)
    at org.apache.openejb.core.ivm.BaseEjbProxyHandler.invoke(BaseEjbProxyHandler.java:325)
    at xx.xx.xx.xx.transaction.TransactionStartedMessageOrchestrator.doProcess(TransactionStartedMessageOrchestrator.java:42) [1 skipped]
    at xx.xx.xx.xx.transaction.TransactionStartedMessageOrchestrator.doProcess(TransactionStartedMessageOrchestrator.java:26)
    at xx.xx.xx.xx.AbstractMessageOrchestrator.process(AbstractMessageOrchestrator.java:10)
    at xx.xx.xx.xx.MessageProcessorFactory.buildProcessorAndStartProcessing(MessageProcessorFactory.java:59)
    at xx.xx.xx.xx.MessageRouter.unmarshalMessageAndRouteToProcessor(MessageRouter.java:90)
    at xx.xx.xx.xx.MessageRouter.routeMessageToProcessor(MessageRouter.java:72)
    at org.apache.openejb.core.interceptor.ReflectionInvocationContext$Invocation.invoke(ReflectionInvocationContext.java:192) [4 skipped]
    at org.apache.openejb.core.interceptor.ReflectionInvocationContext.proceed(ReflectionInvocationContext.java:173)
    at org.apache.openejb.monitoring.StatsInterceptor.record(StatsInterceptor.java:181)
    at org.apache.openejb.monitoring.StatsInterceptor.invoke(StatsInterceptor.java:100)
    at org.apache.openejb.core.interceptor.ReflectionInvocationContext$Invocation.invoke(ReflectionInvocationContext.java:192) [4 skipped]
    at org.apache.openejb.core.interceptor.ReflectionInvocationContext.proceed(ReflectionInvocationContext.java:173)
    at org.apache.openejb.core.interceptor.InterceptorStack.invoke(InterceptorStack.java:85)
    at org.apache.openejb.core.stateless.StatelessContainer._invoke(StatelessContainer.java:227)
    at org.apache.openejb.core.stateless.StatelessContainer.invoke(StatelessContainer.java:194)
    at org.apache.openejb.core.ivm.EjbObjectProxyHandler.synchronizedBusinessMethod(EjbObjectProxyHandler.java:317)
    at org.apache.openejb.core.ivm.EjbObjectProxyHandler.businessMethod(EjbObjectProxyHandler.java:312)
    at org.apache.openejb.core.ivm.EjbObjectProxyHandler._invoke(EjbObjectProxyHandler.java:92)
    at org.apache.openejb.core.ivm.BaseEjbProxyHandler.invoke(BaseEjbProxyHandler.java:325)
    at xx.xx.xx.xx.MessageRouter$$LocalBeanProxy.routeMessageToProcessor(xx.xx.xx.xx.xx/MessageRouter.java)
    at xx.xx.xx.xx.Receiver.processMessageText(Receiver.java:82)
    at xx.xx.xx.xx.Receiver.onMessage(Receiver.java:69)
    at org.apache.openejb.core.interceptor.ReflectionInvocationContext$Invocation.invoke(ReflectionInvocationContext.java:192) [4 skipped]
    at org.apache.openejb.core.interceptor.ReflectionInvocationContext.proceed(ReflectionInvocationContext.java:173)
    at org.apache.openejb.monitoring.StatsInterceptor.record(StatsInterceptor.java:181)
    at org.apache.openejb.monitoring.StatsInterceptor.invoke(StatsInterceptor.java:100)
    at org.apache.openejb.core.interceptor.ReflectionInvocationContext$Invocation.invoke(ReflectionInvocationContext.java:192) [4 skipped]
    at org.apache.openejb.core.interceptor.ReflectionInvocationContext.proceed(ReflectionInvocationContext.java:173)
    at org.apache.openejb.core.interceptor.InterceptorStack.invoke(InterceptorStack.java:85)
    at org.apache.openejb.core.mdb.MdbContainer._invoke(MdbContainer.java:402)
    at org.apache.openejb.core.mdb.MdbContainer.invoke(MdbContainer.java:373)
    at org.apache.openejb.core.mdb.EndpointHandler.deliverMessage(EndpointHandler.java:228)
    at org.apache.openejb.core.mdb.EndpointHandler.invoke(EndpointHandler.java:169)
    at xx.xx.xx.xx.Receiver$$LocalBeanProxy.onMessage(xx.xx.xx.xx.xx/Receiver.java)
    at org.apache.activemq.ra.MessageEndpointProxy$MessageEndpointAlive.onMessage(MessageEndpointProxy.java:123)
    at org.apache.activemq.ra.MessageEndpointProxy.onMessage(MessageEndpointProxy.java:64)
    at org.apache.activemq.ActiveMQSession.run(ActiveMQSession.java:994)
    at org.apache.activemq.ra.ServerSessionImpl.run(ServerSessionImpl.java:169)
    at org.apache.geronimo.connector.work.WorkerContext.run(WorkerContext.java:366)
    at org.apache.geronimo.connector.work.pool.NamedRunnable.run(NamedRunnable.java:32)
    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)
mnesarco commented 7 years ago

Hi @mcbeelen, I have done some important changes in beta5. please take a look at: http://www.mybatis.org/cdi/changes.html So please upgrade to beta5 and tell me if the problem is still there.

mcbeelen commented 7 years ago

Hi @mnesarco ,

We upgraded to beta5 and tweaked our logging.

The behaviour as we currently see it, is this:

  1. mybatis.cdi.Extension finds 5 Mappers in processAnnotatedType().
  2. mybatis.cdi.Extension does not create a bean for all found mappers in afterBeanDiscovery()
  3. As soon a OpenEJB.startup finds a object, which needs on of the 'uninitialized mappers' to throws an UnsatisfiedResolutionException.
10:48:23 [localhost-startStop-1] INFO  org.mybatis.cdi.Extension - MyBatis CDI Module - Mapper type MerchantOrderMapper
10:48:23 [localhost-startStop-1] INFO  org.mybatis.cdi.Extension - MyBatis CDI Module - Mapper type PoiInfoMapper
10:48:23 [localhost-startStop-1] INFO  org.mybatis.cdi.Extension - MyBatis CDI Module - Mapper type TransactionMapper
10:48:23 [localhost-startStop-1] INFO  org.mybatis.cdi.Extension - MyBatis CDI Module - Mapper type PaymentRequestMapper
10:48:23 [localhost-startStop-1] INFO  org.mybatis.cdi.Extension - MyBatis CDI Module - Mapper type FailedMessageMapper

10:48:23 [localhost-startStop-1] INFO  org.mybatis.cdi.Extension - MyBatis CDI Module - SqlSessionFactory producer DataSourceConfig.produceFactory

10:48:24 [localhost-startStop-1] INFO  org.mybatis.cdi.Extension - MyBatis CDI Module - Activated

10:48:24 [localhost-startStop-1] INFO  org.mybatis.cdi.Extension - MyBatis CDI Module - Managed Mapper dependency: xx.xx.xx.PaymentRequestMapper, xx.xx.xx.PaymentRequestMapper
10:48:24 [localhost-startStop-1] INFO  org.mybatis.cdi.Extension - MyBatis CDI Module - Managed Mapper dependency: xx.xx.xx.PoiInfoMapper, xx.xx.xx.PoiInfoMapper
10:48:24 [localhost-startStop-1] INFO  org.mybatis.cdi.Extension - MyBatis CDI Module - Managed Mapper dependency: xx.xx.xx.persistence.mapper.TransactionMapper, xx.xx.xx.TransactionMapper

10:48:24 [localhost-startStop-1] INFO  org.mybatis.cdi.Extension - MyBatis CDI Module - Managed SqlSession: org.apache.ibatis.session.SqlSession, org.apache.ibatis.session.SqlSession

10:48:24 [localhost-startStop-1] ERROR OpenEJB.startup - CDI Beans module deployment failed
org.apache.webbeans.exception.inject.DeploymentException: 
javax.enterprise.inject.UnsatisfiedResolutionException: 
    Api type [xx.xx.xx.MerchantOrderMapper] is not found with the qualifiers 
Qualifiers: [@javax.enterprise.inject.Default()]
for injection into Field Injection Point, field name :  mapper, 
    Bean Owner : [MyBatisMerchantOrderRepository, Name:null, WebBeans Type:ENTERPRISE, 
    API Types:[xx.xx.xx.MerchantOrderRepository,java.io.Serializable,java.lang.Object], Qualifiers:[javax.enterprise.inject.Default,javax.enterprise.inject.Any]]

Further debugging gave us the insight that processInjectionTarget() is not being called for the Field Injection Point, which later causes the UnsatisfiedResolutionException.

mcbeelen commented 7 years ago

@mnesarco : Could the process to make a 1.0.0-beta6 release be started? We would like to use the solution for this issue in our project, but prefer to use released versions instead of SNAPSHOTs.

mnesarco commented 7 years ago

Hi @mcbeelen : I think it would be great to wait some news from issues #19 and #5. If they test the beta6 and confirm it solves the issues we can then release it and help more users.

But if it is critical to you, you can ask to @hazendaz, maybe if he has time he can push the release sooner.

On Sat, Jan 28, 2017 at 9:22 AM, Marco Beelen notifications@github.com wrote:

@mnesarco https://github.com/mnesarco : Could the process to make a 1.0.0-beta6 release be started? We would like to use the solution for this issue in our project, but prefer to use released versions instead of SNAPSHOTs.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/mybatis/cdi/issues/40#issuecomment-275850804, or mute the thread https://github.com/notifications/unsubscribe-auth/ABCXVVnNd-DJkXRd0jcSAXgPXC9FkI1aks5rW08VgaJpZM4IhAXI .

-- Frank D. Martínez M.

hazendaz commented 7 years ago

I did a quick overall review, cleaned up a few very trivial issues, upgraded mockito to 2.7.0 and fixed mockito deprecations. I'll push the release for beta6. It's rather simple to do and takes about 10 minutes max. The binary should show up though in central in about 2 to 3 hours from now.