Hi Sergey, I think I know now the reason of an issue: race condition is caused by programmatic instantiation of WebClient in constructor of class created by blueprint context. Sometimes the programmatic WebClient client instantiation happens too early, before blueprint container creates CXF bus and registers the bus extensions.
Workarounds: a) Inject WebClient from blueprint instead programmatic instantiation (the safest way) b) Create WebClient programmatically on first request, not on blueprint initialization phase. Regards, Andrei. > -----Original Message----- > From: Sergey Beryozkin [mailto:[email protected]] > Sent: Freitag, 9. Februar 2018 18:02 > To: Andrei Shakirin > Cc: [email protected]; [email protected] > Subject: Re: CXF startup error in OSGi container (checkBindingFactory) > > Modifying the code with may be the log entries (in various > BindingFactoryManagerImpl parts and AbstractJAXRSFactoryBean NPE poit > level) to get a better idea of the ordering and then redeploying might > help...It is > tricky > > Sergey > > > > On 09/02/18 16:51, Andrei Shakirin wrote: > > Hi Sergey, > > > > Thanks for your response. > > Yeah ... these are my favourite issues: happens once per 20 starts, only on > some environments, not really debuggable. > > > > Thanks for the hints, will fighting. > > > > Regards, > > Andrei. > > > > > >> -----Original Message----- > >> From: Sergey Beryozkin [mailto:[email protected]] > >> Sent: Freitag, 9. Februar 2018 12:06 > >> To: Andrei Shakirin > >> Cc: [email protected]; [email protected] > >> Subject: Re: CXF startup error in OSGi container > >> (checkBindingFactory) > >> > >> Hi Andrei > >> > >> Looks like the problem is happening earlier, > >> > >> https://github.com/apache/cxf/blob/cxf- > >> 3.1.7/rt/frontend/jaxrs/src/main/java/org/apache/cxf/jaxrs/AbstractJA > >> XRSFact > >> oryBean.java#L99 > >> > >> and the stack-trace suggests that BindingFactoryManager is null, it > >> is not set as a bus extension. > >> > >> Why is that manager is null I'm not sure. > >> May make sense debugging what is happening inside > >> > >> https://github.com/apache/cxf/blob/cxf- > >> 3.1.7/core/src/main/java/org/apache/cxf/bus/managers/BindingFactoryMa > >> nag > >> erImpl.java, > >> may be even recompile with some printlns there and in > >> AbstractJAXRSFactoryBean.java to confirm it is actually a race condition... > >> May be also try 3.1.14 > >> > >> Sergey > >> > >> > >> > >> On 09/02/18 09:12, Andrei Shakirin wrote: > >>> Hi Sergey, > >>> > >>> Could you quick look in following stack trace, occurs sometimes by > >>> startup > >> CXF client in OSGi Karaf container: > >>> > >>> 2018-02-09 04:02:11,452 WARN [{{bundle.name,org.apache.cxf.cxf-rt- > >> transports-http}{bundle.version,3.1.7}{bundle.id,252}}] [null] > >> org.apache.cxf.transport.servlet.ServletController Can't find the > >> the request for > >> http://172.16.4.38/basit/services/1/server-availability's > >> Observer > >>> 2018-02-09 04:02:11,502 ERROR [{{bundle.name,org.apache.cxf.cxf-rt- > >> rs-client}{bundle.version,3.1.7}{bundle.id,246}}] [null] > >> org.apache.cxf.jaxrs.client.JAXRSClientFactoryBean > >> java.lang.NullPointerException : null > >>> 2018-02-09 04:02:11,503 WARN > >> [{{bundle.name,org.apache.aries.blueprint.core}{bundle.version,1.6.2}{ > >> bundle.id,16}}] [null] > org.apache.aries.blueprint.container.BeanRecipe > >> Object to be destroyed is not an instance of UnwrapperedBeanHolder, > >> type: null > >>> 2018-02-09 04:02:11,504 INFO > >> [{{bundle.name,org.apache.camel.camel- > >> core}{bundle.version,2.17.3}{bundle.id,199}}] [null] > >> org.apache.camel.blueprint.BlueprintCamelContext Apache Camel > >> 2.17.3 (CamelContext: schedulingCamelContext) is shutting down > >>> 2018-02-09 04:02:11,511 INFO > >> [{{bundle.name,org.apache.camel.camel- > >> core}{bundle.version,2.17.3}{bundle.id,199}}] [null] > >> org.apache.camel.blueprint.BlueprintCamelContext Apache Camel > >> 2.17.3 (CamelContext: schedulingCamelContext) uptime 0.236 seconds > >>> 2018-02-09 04:02:11,511 INFO > >> [{{bundle.name,org.apache.camel.camel- > >> core}{bundle.version,2.17.3}{bundle.id,199}}] [null] > >> org.apache.camel.blueprint.BlueprintCamelContext Apache Camel > >> 2.17.3 (CamelContext: schedulingCamelContext) is shutdown in 0.007 > >> seconds > >> > >>> 2018-02-09 04:02:11,518 ERROR > >> [{{bundle.name,org.apache.aries.blueprint.core}{bundle.version,1.6.2}{ > >> bundle.id,16}}] [null] > >> org.apache.aries.blueprint.container.BlueprintContainerImpl > >> Unable to start blueprint container for bundle > >> de.conrad.ccp.basit.core- > >> domain-bee/10.13.3 > >> org.osgi.service.blueprint.container.ComponentDefinitionException: > >> Error when instantiating bean ikaEventServiceConnector of class > >> de.conrad.ccp.basit.bee.core.ika.impl.IkaEventServiceConnectorImpl > >>> at > >> org.apache.aries.blueprint.container.BeanRecipe.wrapAsCompDefEx(BeanR > >> eci pe.java:361)[16:org.apache.aries.blueprint.core:1.6.2] > >>> at > >> org.apache.aries.blueprint.container.BeanRecipe.getInstanceFromType(B > >> eanRe cipe.java:351)[16:org.apache.aries.blueprint.core:1.6.2] > >>> at > >> > org.apache.aries.blueprint.container.BeanRecipe.getInstance(BeanRecipe.java: > >> 282)[16:org.apache.aries.blueprint.core:1.6.2] > >>> at > >> org.apache.aries.blueprint.container.BeanRecipe.internalCreate2(BeanR > >> ecipe.j ava:830)[16:org.apache.aries.blueprint.core:1.6.2] > >>> at > >> org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRe > >> cipe.ja va:811)[16:org.apache.aries.blueprint.core:1.6.2] > >>> at > >> > org.apache.aries.blueprint.di.AbstractRecipe$1.call(AbstractRecipe.java:79)[16: > >> org.apache.aries.blueprint.core:1.6.2] > >>> at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_151] > >>> at > >> org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.ja > >> va:88)[16 :org.apache.aries.blueprint.core:1.6.2] > >>> at > >> org.apache.aries.blueprint.container.BlueprintRepository.createInstan > >> ces(Bluep > >> rintRepository.java:255)[16:org.apache.aries.blueprint.core:1.6.2] > >>> at > >> org.apache.aries.blueprint.container.BlueprintRepository.createAll(Bl > >> ueprintRe > >> pository.java:186)[16:org.apache.aries.blueprint.core:1.6.2] > >>> at > >> org.apache.aries.blueprint.container.BlueprintContainerImpl.instantia > >> teEagerC > >> omponents(BlueprintContainerImpl.java:724)[16:org.apache.aries.bluepr > >> int.cor > >> e:1.6.2] > >>> at > >> org.apache.aries.blueprint.container.BlueprintContainerImpl.doRun(Blu > >> eprintC > >> ontainerImpl.java:411)[16:org.apache.aries.blueprint.core:1.6.2] > >>> at > >> org.apache.aries.blueprint.container.BlueprintContainerImpl.run(Bluep > >> rintCont > >> ainerImpl.java:276)[16:org.apache.aries.blueprint.core:1.6.2] > >>> at > >> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:51 > >> 1)[:1.8.0 > >> _151] > >>> at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_151] > >>> at > >> org.apache.aries.blueprint.container.ExecutorServiceWrapper.run(Execu > >> torSer > >> viceWrapper.java:106)[16:org.apache.aries.blueprint.core:1.6.2] > >>> at > >> org.apache.aries.blueprint.utils.threading.impl.DiscardableRunnable.r > >> un(Discar > >> dableRunnable.java:48)[16:org.apache.aries.blueprint.core:1.6.2] > >>> at > >> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:51 > >> 1)[:1.8.0 > >> _151] > >>> at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_151] > >>> at > >> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask. > >> access $201(ScheduledThreadPoolExecutor.java:180)[:1.8.0_151] > >>> at > >> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask. > >> run(Sc heduledThreadPoolExecutor.java:293)[:1.8.0_151] > >>> at > >> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor. > >> java:1 > >> 149)[:1.8.0_151] > >>> at > >> > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java: > >> 624)[:1.8.0_151] > >>> at java.lang.Thread.run(Thread.java:748)[:1.8.0_151] > >>> Caused by: java.lang.RuntimeException: java.lang.NullPointerException > >>> at > >> org.apache.cxf.jaxrs.client.JAXRSClientFactoryBean.createWebClient(JA > >> XRSClie > >> ntFactoryBean.java:233) > >>> at > >> org.apache.cxf.jaxrs.client.WebClient.create(WebClient.java:176)[246: > >> org.apac > >> he.cxf.cxf-rt-rs-client:3.1.7] > >>> at > >> org.apache.cxf.jaxrs.client.WebClient.create(WebClient.java:136)[246: > >> org.apac > >> he.cxf.cxf-rt-rs-client:3.1.7] > >>> at > >> de.conrad.ccp.basit.bee.core.ika.impl.IkaEventServiceConnectorImpl.cr > >> eateClie > >> nt(IkaEventServiceConnectorImpl.java:83)[126:de.conrad.ccp.basit.core > >> - > >> domain-bee:10.13.3] > >>> at > >> de.conrad.ccp.basit.bee.core.ika.impl.IkaEventServiceConnectorImpl.<i > >> nit>(IkaE > >> ventServiceConnectorImpl.java:41)[126:de.conrad.ccp.basit.core-domain > >> - > >> bee:10.13.3] > >>> at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native > >> Method)[:1.8.0_151] > >>> at > >> sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstruct > >> orAcce > >> ssorImpl.java:62)[:1.8.0_151] > >>> at > >> sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingC > >> onstru ctorAccessorImpl.java:45)[:1.8.0_151] > >>> at > >> java.lang.reflect.Constructor.newInstance(Constructor.java:423)[:1.8. > >> 0_151] > >>> at > >> org.apache.aries.blueprint.utils.ReflectionUtils.newInstance(Reflecti > >> onUtils.java :331)[16:org.apache.aries.blueprint.core:1.6.2] > >>> at > >> org.apache.aries.blueprint.container.BeanRecipe.newInstance(BeanRecip > >> e.java :984)[16:org.apache.aries.blueprint.core:1.6.2] > >>> at > >> org.apache.aries.blueprint.container.BeanRecipe.getInstanceFromType(B > >> eanRe cipe.java:349)[16:org.apache.aries.blueprint.core:1.6.2] > >>> ... 22 more > >>> Caused by: java.lang.NullPointerException > >>> at > >> org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.checkBindingFactory(Abs > >> tractJA > >> XRSFactoryBean.java:104)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1 > >> .7] > >>> at > >> org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.getBus(AbstractJAXRSFac > >> toryBe an.java:86)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7] > >>> at > >> org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.createEndpointInfo(Abst > >> ractJAX > >> RSFactoryBean.java:130)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1. > >> 7] > >>> at > >> org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.createEndpoint(Abstract > >> JAXRSF > >> actoryBean.java:219)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7] > >>> at > >> org.apache.cxf.jaxrs.client.JAXRSClientFactoryBean.createWebClient(JA > >> XRSClie > >> ntFactoryBean.java:220)[246:org.apache.cxf.cxf-rt-rs-client:3.1.7] > >>> ... 33 more > >>> > >>> It looks for me like startup race condition issue, any clue how we > >>> can > >> workaround this? > >>> > >>> Regards, > >>> Andrei. > >>> > >
