You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cxf.apache.org by Andrei Shakirin <as...@talend.com> on 2018/02/09 09:12:57 UTC

CXF startup error in OSGi container (checkBindingFactory)

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(BeanRecipe.java:361)[16:org.apache.aries.blueprint.core:1.6.2]
	at org.apache.aries.blueprint.container.BeanRecipe.getInstanceFromType(BeanRecipe.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(BeanRecipe.java:830)[16:org.apache.aries.blueprint.core:1.6.2]
	at org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.java: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.java:88)[16:org.apache.aries.blueprint.core:1.6.2]
	at org.apache.aries.blueprint.container.BlueprintRepository.createInstances(BlueprintRepository.java:255)[16:org.apache.aries.blueprint.core:1.6.2]
	at org.apache.aries.blueprint.container.BlueprintRepository.createAll(BlueprintRepository.java:186)[16:org.apache.aries.blueprint.core:1.6.2]
	at org.apache.aries.blueprint.container.BlueprintContainerImpl.instantiateEagerComponents(BlueprintContainerImpl.java:724)[16:org.apache.aries.blueprint.core:1.6.2]
	at org.apache.aries.blueprint.container.BlueprintContainerImpl.doRun(BlueprintContainerImpl.java:411)[16:org.apache.aries.blueprint.core:1.6.2]
	at org.apache.aries.blueprint.container.BlueprintContainerImpl.run(BlueprintContainerImpl.java:276)[16:org.apache.aries.blueprint.core:1.6.2]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[: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(ExecutorServiceWrapper.java:106)[16:org.apache.aries.blueprint.core:1.6.2]
	at org.apache.aries.blueprint.utils.threading.impl.DiscardableRunnable.run(DiscardableRunnable.java:48)[16:org.apache.aries.blueprint.core:1.6.2]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[: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(ScheduledThreadPoolExecutor.java:293)[:1.8.0_151]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)[: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(JAXRSClientFactoryBean.java:233)
	at org.apache.cxf.jaxrs.client.WebClient.create(WebClient.java:176)[246:org.apache.cxf.cxf-rt-rs-client:3.1.7]
	at org.apache.cxf.jaxrs.client.WebClient.create(WebClient.java:136)[246:org.apache.cxf.cxf-rt-rs-client:3.1.7]
	at de.conrad.ccp.basit.bee.core.ika.impl.IkaEventServiceConnectorImpl.createClient(IkaEventServiceConnectorImpl.java:83)[126:de.conrad.ccp.basit.core-domain-bee:10.13.3]
	at de.conrad.ccp.basit.bee.core.ika.impl.IkaEventServiceConnectorImpl.<init>(IkaEventServiceConnectorImpl.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(NativeConstructorAccessorImpl.java:62)[:1.8.0_151]
	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.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(ReflectionUtils.java:331)[16:org.apache.aries.blueprint.core:1.6.2]
	at org.apache.aries.blueprint.container.BeanRecipe.newInstance(BeanRecipe.java:984)[16:org.apache.aries.blueprint.core:1.6.2]
	at org.apache.aries.blueprint.container.BeanRecipe.getInstanceFromType(BeanRecipe.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(AbstractJAXRSFactoryBean.java:104)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
	at org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.getBus(AbstractJAXRSFactoryBean.java:86)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
	at org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.createEndpointInfo(AbstractJAXRSFactoryBean.java:130)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
	at org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.createEndpoint(AbstractJAXRSFactoryBean.java:219)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
	at org.apache.cxf.jaxrs.client.JAXRSClientFactoryBean.createWebClient(JAXRSClientFactoryBean.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.

RE: CXF startup error in OSGi container (checkBindingFactory)

Posted by Andrei Shakirin <as...@talend.com>.
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:sberyozkin@gmail.com]
> Sent: Freitag, 9. Februar 2018 18:02
> To: Andrei Shakirin
> Cc: users@cxf.apache.org; a.vinogradov@itos.eu.org
> 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:sberyozkin@gmail.com]
> >> Sent: Freitag, 9. Februar 2018 12:06
> >> To: Andrei Shakirin
> >> Cc: users@cxf.apache.org; a.vinogradov@itos.eu.org
> >> 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.
> >>>
> >


Re: CXF startup error in OSGi container (checkBindingFactory)

Posted by Sergey Beryozkin <sb...@gmail.com>.
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:sberyozkin@gmail.com]
>> Sent: Freitag, 9. Februar 2018 12:06
>> To: Andrei Shakirin
>> Cc: users@cxf.apache.org; a.vinogradov@itos.eu.org
>> 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/AbstractJAXRSFact
>> 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/BindingFactoryManag
>> 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(BeanReci
>> pe.java:361)[16:org.apache.aries.blueprint.core:1.6.2]
>>> 	at
>> org.apache.aries.blueprint.container.BeanRecipe.getInstanceFromType(BeanRe
>> 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(BeanRecipe.j
>> ava:830)[16:org.apache.aries.blueprint.core:1.6.2]
>>> 	at
>> org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.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.java:88)[16
>> :org.apache.aries.blueprint.core:1.6.2]
>>> 	at
>> org.apache.aries.blueprint.container.BlueprintRepository.createInstances(Bluep
>> rintRepository.java:255)[16:org.apache.aries.blueprint.core:1.6.2]
>>> 	at
>> org.apache.aries.blueprint.container.BlueprintRepository.createAll(BlueprintRe
>> pository.java:186)[16:org.apache.aries.blueprint.core:1.6.2]
>>> 	at
>> org.apache.aries.blueprint.container.BlueprintContainerImpl.instantiateEagerC
>> omponents(BlueprintContainerImpl.java:724)[16:org.apache.aries.blueprint.cor
>> e:1.6.2]
>>> 	at
>> org.apache.aries.blueprint.container.BlueprintContainerImpl.doRun(BlueprintC
>> ontainerImpl.java:411)[16:org.apache.aries.blueprint.core:1.6.2]
>>> 	at
>> org.apache.aries.blueprint.container.BlueprintContainerImpl.run(BlueprintCont
>> ainerImpl.java:276)[16:org.apache.aries.blueprint.core:1.6.2]
>>> 	at
>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[: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(ExecutorSer
>> viceWrapper.java:106)[16:org.apache.aries.blueprint.core:1.6.2]
>>> 	at
>> org.apache.aries.blueprint.utils.threading.impl.DiscardableRunnable.run(Discar
>> dableRunnable.java:48)[16:org.apache.aries.blueprint.core:1.6.2]
>>> 	at
>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[: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(JAXRSClie
>> 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.createClie
>> 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.<init>(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(NativeConstructorAcce
>> ssorImpl.java:62)[:1.8.0_151]
>>> 	at
>> sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstru
>> 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(ReflectionUtils.java
>> :331)[16:org.apache.aries.blueprint.core:1.6.2]
>>> 	at
>> org.apache.aries.blueprint.container.BeanRecipe.newInstance(BeanRecipe.java
>> :984)[16:org.apache.aries.blueprint.core:1.6.2]
>>> 	at
>> org.apache.aries.blueprint.container.BeanRecipe.getInstanceFromType(BeanRe
>> 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(AbstractJA
>> XRSFactoryBean.java:104)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
>>> 	at
>> org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.getBus(AbstractJAXRSFactoryBe
>> an.java:86)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
>>> 	at
>> org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.createEndpointInfo(AbstractJAX
>> RSFactoryBean.java:130)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
>>> 	at
>> org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.createEndpoint(AbstractJAXRSF
>> actoryBean.java:219)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
>>> 	at
>> org.apache.cxf.jaxrs.client.JAXRSClientFactoryBean.createWebClient(JAXRSClie
>> 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.
>>>
> 


RE: CXF startup error in OSGi container (checkBindingFactory)

Posted by Andrei Shakirin <as...@talend.com>.
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:sberyozkin@gmail.com]
> Sent: Freitag, 9. Februar 2018 12:06
> To: Andrei Shakirin
> Cc: users@cxf.apache.org; a.vinogradov@itos.eu.org
> 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/AbstractJAXRSFact
> 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/BindingFactoryManag
> 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(BeanReci
> pe.java:361)[16:org.apache.aries.blueprint.core:1.6.2]
> > 	at
> org.apache.aries.blueprint.container.BeanRecipe.getInstanceFromType(BeanRe
> 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(BeanRecipe.j
> ava:830)[16:org.apache.aries.blueprint.core:1.6.2]
> > 	at
> org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.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.java:88)[16
> :org.apache.aries.blueprint.core:1.6.2]
> > 	at
> org.apache.aries.blueprint.container.BlueprintRepository.createInstances(Bluep
> rintRepository.java:255)[16:org.apache.aries.blueprint.core:1.6.2]
> > 	at
> org.apache.aries.blueprint.container.BlueprintRepository.createAll(BlueprintRe
> pository.java:186)[16:org.apache.aries.blueprint.core:1.6.2]
> > 	at
> org.apache.aries.blueprint.container.BlueprintContainerImpl.instantiateEagerC
> omponents(BlueprintContainerImpl.java:724)[16:org.apache.aries.blueprint.cor
> e:1.6.2]
> > 	at
> org.apache.aries.blueprint.container.BlueprintContainerImpl.doRun(BlueprintC
> ontainerImpl.java:411)[16:org.apache.aries.blueprint.core:1.6.2]
> > 	at
> org.apache.aries.blueprint.container.BlueprintContainerImpl.run(BlueprintCont
> ainerImpl.java:276)[16:org.apache.aries.blueprint.core:1.6.2]
> > 	at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[: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(ExecutorSer
> viceWrapper.java:106)[16:org.apache.aries.blueprint.core:1.6.2]
> > 	at
> org.apache.aries.blueprint.utils.threading.impl.DiscardableRunnable.run(Discar
> dableRunnable.java:48)[16:org.apache.aries.blueprint.core:1.6.2]
> > 	at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[: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(JAXRSClie
> 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.createClie
> 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.<init>(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(NativeConstructorAcce
> ssorImpl.java:62)[:1.8.0_151]
> > 	at
> sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstru
> 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(ReflectionUtils.java
> :331)[16:org.apache.aries.blueprint.core:1.6.2]
> > 	at
> org.apache.aries.blueprint.container.BeanRecipe.newInstance(BeanRecipe.java
> :984)[16:org.apache.aries.blueprint.core:1.6.2]
> > 	at
> org.apache.aries.blueprint.container.BeanRecipe.getInstanceFromType(BeanRe
> 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(AbstractJA
> XRSFactoryBean.java:104)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
> > 	at
> org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.getBus(AbstractJAXRSFactoryBe
> an.java:86)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
> > 	at
> org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.createEndpointInfo(AbstractJAX
> RSFactoryBean.java:130)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
> > 	at
> org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.createEndpoint(AbstractJAXRSF
> actoryBean.java:219)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
> > 	at
> org.apache.cxf.jaxrs.client.JAXRSClientFactoryBean.createWebClient(JAXRSClie
> 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.
> >


Re: CXF startup error in OSGi container (checkBindingFactory)

Posted by Sergey Beryozkin <sb...@gmail.com>.
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/AbstractJAXRSFactoryBean.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/BindingFactoryManagerImpl.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(BeanRecipe.java:361)[16:org.apache.aries.blueprint.core:1.6.2]
> 	at org.apache.aries.blueprint.container.BeanRecipe.getInstanceFromType(BeanRecipe.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(BeanRecipe.java:830)[16:org.apache.aries.blueprint.core:1.6.2]
> 	at org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.java: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.java:88)[16:org.apache.aries.blueprint.core:1.6.2]
> 	at org.apache.aries.blueprint.container.BlueprintRepository.createInstances(BlueprintRepository.java:255)[16:org.apache.aries.blueprint.core:1.6.2]
> 	at org.apache.aries.blueprint.container.BlueprintRepository.createAll(BlueprintRepository.java:186)[16:org.apache.aries.blueprint.core:1.6.2]
> 	at org.apache.aries.blueprint.container.BlueprintContainerImpl.instantiateEagerComponents(BlueprintContainerImpl.java:724)[16:org.apache.aries.blueprint.core:1.6.2]
> 	at org.apache.aries.blueprint.container.BlueprintContainerImpl.doRun(BlueprintContainerImpl.java:411)[16:org.apache.aries.blueprint.core:1.6.2]
> 	at org.apache.aries.blueprint.container.BlueprintContainerImpl.run(BlueprintContainerImpl.java:276)[16:org.apache.aries.blueprint.core:1.6.2]
> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[: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(ExecutorServiceWrapper.java:106)[16:org.apache.aries.blueprint.core:1.6.2]
> 	at org.apache.aries.blueprint.utils.threading.impl.DiscardableRunnable.run(DiscardableRunnable.java:48)[16:org.apache.aries.blueprint.core:1.6.2]
> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[: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(ScheduledThreadPoolExecutor.java:293)[:1.8.0_151]
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)[: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(JAXRSClientFactoryBean.java:233)
> 	at org.apache.cxf.jaxrs.client.WebClient.create(WebClient.java:176)[246:org.apache.cxf.cxf-rt-rs-client:3.1.7]
> 	at org.apache.cxf.jaxrs.client.WebClient.create(WebClient.java:136)[246:org.apache.cxf.cxf-rt-rs-client:3.1.7]
> 	at de.conrad.ccp.basit.bee.core.ika.impl.IkaEventServiceConnectorImpl.createClient(IkaEventServiceConnectorImpl.java:83)[126:de.conrad.ccp.basit.core-domain-bee:10.13.3]
> 	at de.conrad.ccp.basit.bee.core.ika.impl.IkaEventServiceConnectorImpl.<init>(IkaEventServiceConnectorImpl.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(NativeConstructorAccessorImpl.java:62)[:1.8.0_151]
> 	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.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(ReflectionUtils.java:331)[16:org.apache.aries.blueprint.core:1.6.2]
> 	at org.apache.aries.blueprint.container.BeanRecipe.newInstance(BeanRecipe.java:984)[16:org.apache.aries.blueprint.core:1.6.2]
> 	at org.apache.aries.blueprint.container.BeanRecipe.getInstanceFromType(BeanRecipe.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(AbstractJAXRSFactoryBean.java:104)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
> 	at org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.getBus(AbstractJAXRSFactoryBean.java:86)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
> 	at org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.createEndpointInfo(AbstractJAXRSFactoryBean.java:130)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
> 	at org.apache.cxf.jaxrs.AbstractJAXRSFactoryBean.createEndpoint(AbstractJAXRSFactoryBean.java:219)[240:org.apache.cxf.cxf-rt-frontend-jaxrs:3.1.7]
> 	at org.apache.cxf.jaxrs.client.JAXRSClientFactoryBean.createWebClient(JAXRSClientFactoryBean.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.
>