Hi Alex, Can you share your itest ? I'm not able to reproduce the issue, so hard to investigate.
Regards JB On 08/05/2019 15:31, Alex Soto wrote: > Still having this problem. I am setting log level: > > logLevel(LogLevel.TRACE), > > And > > log4j2.logger.paxexam.name=org.ops4j.pax.exam > log4j2.logger.paxexam.level=TRACE > > And > > static final long SERVICE_TIMEOUT = 300_000; > systemTimeout(SERVICE_TIMEOUT), > RBCRemoteTargetOptions.waitForRBCFor((int) SERVICE_TIMEOUT), > > I removed all services references that used the /@Inject/ annotation, > and replaced them with service lookup code. > Logs don’t show any error or warning that can help pinpoint the cause of > this error. > > Increasing the timeout just delays the reporting of the error by the > FailSafe driver, but the error is logged a lot earlier in the Karaf log > file. > > For easy reference, here is the stack trace again: > > 2019-05-08T09:15:18,654 | ERROR | BundleWatcher: 1 | BundleWatcher > | 201 - org.ops4j.pax.swissbox.extender - 1.8.2 | > Exception in executor thread > org.ops4j.pax.swissbox.tracker.ServiceLookupException: gave up waiting > for service org.ops4j.pax.exam.ProbeInvokerFactory > at > org.ops4j.pax.swissbox.tracker.ServiceLookup.getService(ServiceLookup.java:161) > ~[204:org.ops4j.pax.swissbox.tracker:1.8.2] > at > org.ops4j.pax.swissbox.tracker.ServiceLookup.getService(ServiceLookup.java:104) > ~[204:org.ops4j.pax.swissbox.tracker:1.8.2] > at > org.ops4j.pax.swissbox.tracker.ServiceLookup.getService(ServiceLookup.java:87) > ~[204:org.ops4j.pax.swissbox.tracker:1.8.2] > at > org.ops4j.pax.exam.raw.extender.intern.Parser.createInvoker(Parser.java:79) > ~[?:?] > at org.ops4j.pax.exam.raw.extender.intern.Parser.make(Parser.java:68) ~[?:?] > at org.ops4j.pax.exam.raw.extender.intern.Parser.<init>(Parser.java:54) > ~[?:?] > at > org.ops4j.pax.exam.raw.extender.intern.TestBundleObserver.addingEntries(TestBundleObserver.java:69) > ~[?:?] > at > org.ops4j.pax.swissbox.extender.BundleWatcher$3.run(BundleWatcher.java:226) > [201:org.ops4j.pax.swissbox.extender:1.8.2] > at > java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) > [?:?] > at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] > at > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) > [?:?] > at > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) > [?:?] > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) > [?:?] > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) > [?:?] > at java.lang.Thread.run(Thread.java:748) [?:?] > > > Any hint? > > Best regards, > Alex soto > > > > >> On May 1, 2019, at 3:47 PM, Alex Soto <[email protected] >> <mailto:[email protected]>> wrote: >> >> Do you mean any of these options? >> >> RBCRemoteTargetOptions.waitForRBCFor(final Integer timeoutInMillis) >> CoreOptions.systemTimeout(systemTimeout(finallongtimeoutInMillis) >> >> >> >> Best regards, >> Alex soto >> >> >> >> >>> On May 1, 2019, at 12:12 PM, Jean-Baptiste Onofré <[email protected] >>> <mailto:[email protected]>> wrote: >>> >>> You can increase the startup timeout on the @Configuration method (on >>> the distribution). >>> >>> Regards >>> JB >>> >>> On 01/05/2019 17:46, Alex Soto wrote: >>>> No, I am not waiting for the service explicitly, it comes from Pax Exam >>>> itself (AFIK, based on the stack trace below). >>>> My tests have a bunch of /@Inject/ed services, but they are all >>>> decorated with /@Filter(timeout = SERVICE_TIMEOUT) >>>> /where SERVICE_TIMEOUT = 240_000. >>>> >>>> Java version is 8. >>>> Karaf version is 4.2.0. >>>> The exception: >>>> >>>> 2019-05-01T11:28:58,500 | ERROR | BundleWatcher: 1 | BundleWatcher >>>> | 202 - org.ops4j.pax.swissbox.extender - 1.8.2 | >>>> Exception in executor thread >>>> org.ops4j.pax.swissbox.tracker.ServiceLookupException: gave up waiting >>>> for service org.ops4j.pax.exam.ProbeInvokerFactory >>>> at >>>> org.ops4j.pax.swissbox.tracker.ServiceLookup.getService(ServiceLookup.java:161) >>>> ~[205:org.ops4j.pax.swissbox.tracker:1.8.2] >>>> at >>>> org.ops4j.pax.swissbox.tracker.ServiceLookup.getService(ServiceLookup.java:104) >>>> ~[205:org.ops4j.pax.swissbox.tracker:1.8.2] >>>> at >>>> org.ops4j.pax.swissbox.tracker.ServiceLookup.getService(ServiceLookup.java:87) >>>> ~[205:org.ops4j.pax.swissbox.tracker:1.8.2] >>>> at >>>> org.ops4j.pax.exam.raw.extender.intern.Parser.createInvoker(Parser.java:79) >>>> ~[?:?] >>>> at >>>> org.ops4j.pax.exam.raw.extender.intern.Parser.make(Parser.java:68) >>>> ~[?:?] >>>> at org.ops4j.pax.exam.raw.extender.intern.Parser.<init>(Parser.java:54) >>>> ~[?:?] >>>> at >>>> org.ops4j.pax.exam.raw.extender.intern.TestBundleObserver.addingEntries(TestBundleObserver.java:69) >>>> ~[?:?] >>>> at >>>> org.ops4j.pax.swissbox.extender.BundleWatcher$3.run(BundleWatcher.java:226) >>>> [202:org.ops4j.pax.swissbox.extender:1.8.2] >>>> at >>>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) >>>> [?:?] >>>> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] >>>> at >>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) >>>> [?:?] >>>> at >>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) >>>> [?:?] >>>> at >>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) >>>> [?:?] >>>> at >>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) >>>> [?:?] >>>> at java.lang.Thread.run(Thread.java:748) [?:?] >>>> >>>> >>>> These integration tests have been working in the past, so I suspect, as >>>> the application complexity increased (i.e., more services being added >>>> overtime), it now takes more time for the container to finish >>>> initialization (my guess). I would like to increase the timeout value >>>> to accommodate for a longer startup time, but so far, what I've tried >>>> has not made a difference. >>>> >>>> >>>> Best regards, >>>> Alex soto >>>> >>>> >>>> >>>> >>>>> On May 1, 2019, at 11:31 AM, Jean-Baptiste Onofré <[email protected] >>>>> <mailto:[email protected]> >>>>> <mailto:[email protected]>> wrote: >>>>> >>>>> Are you waiting for the service in your test explicitly or does it come >>>>> from pax exam itself ? >>>>> >>>>> What JDK and Karaf version are you using ? >>>>> >>>>> As reminder, Pax Exam is used in Karaf itests themselves, and I don't >>>>> have such issue. It could be related to JDK 11 if you are using >>>>> this JDK >>>>> version. >>>>> >>>>> Regards >>>>> JB >>>>> >>>>> On 01/05/2019 17:13, Alex Soto wrote: >>>>>> Thanks JB, no there are no errors in the log file, besides this one. >>>>>> >>>>>> Best regards, >>>>>> Alex soto >>>>>> >>>>>> >>>>>> >>>>>> >>>>>>> On May 1, 2019, at 12:10 AM, Jean-Baptiste Onofré >>>>>>> <[email protected] <mailto:[email protected]> >>>>>>> <mailto:[email protected]> >>>>>>> <mailto:[email protected]>> wrote: >>>>>>> >>>>>>> Hi Alex, >>>>>>> >>>>>>> Most of the time, this is a consequence of another error. >>>>>>> >>>>>>> Can you take a look in the target/exam karaf.log to see if there's >>>>>>> something special there ? >>>>>>> >>>>>>> Regards >>>>>>> JB >>>>>>> >>>>>>> On 29/04/2019 18:09, Alex Soto wrote: >>>>>>>> Hello, >>>>>>>> >>>>>>>> I am using pax-exam 4.11.0 for integration tests. I am consistently >>>>>>>> getting the following exception. >>>>>>>> >>>>>>>> >>>>>>>> org.ops4j.pax.swissbox.tracker.ServiceLookupException: gave up >>>>>>>> waiting >>>>>>>> for service org.ops4j.pax.exam.ProbeInvoker >>>>>>>> at >>>>>>>> org.ops4j.pax.swissbox.tracker.ServiceLookup.getService(ServiceLookup.java:199) >>>>>>>> at >>>>>>>> org.ops4j.pax.swissbox.tracker.ServiceLookup.getService(ServiceLookup.java:136) >>>>>>>> at >>>>>>>> org.ops4j.pax.exam.rbc.internal.RemoteBundleContextImpl.remoteCall(RemoteBundleContextImpl.java:80) >>>>>>>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) >>>>>>>> at >>>>>>>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) >>>>>>>> at >>>>>>>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) >>>>>>>> at java.lang.reflect.Method.invoke(Method.java:498) >>>>>>>> at >>>>>>>> sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:357) >>>>>>>> at sun.rmi.transport.Transport$1.run(Transport.java:200) >>>>>>>> at sun.rmi.transport.Transport$1.run(Transport.java:197) >>>>>>>> at java.security.AccessController.doPrivileged(Native Method) >>>>>>>> at sun.rmi.transport.Transport.serviceCall(Transport.java:196) >>>>>>>> at >>>>>>>> sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:573) >>>>>>>> at >>>>>>>> sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:835) >>>>>>>> at >>>>>>>> sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:688) >>>>>>>> at java.security.AccessController.doPrivileged(Native Method) >>>>>>>> at >>>>>>>> sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:687) >>>>>>>> at >>>>>>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) >>>>>>>> at >>>>>>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) >>>>>>>> at java.lang.Thread.run(Thread.java:748) >>>>>>>> at >>>>>>>> sun.rmi.transport.StreamRemoteCall.exceptionReceivedFromServer(StreamRemoteCall.java:283) >>>>>>>> at >>>>>>>> sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:260) >>>>>>>> at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:161) >>>>>>>> at >>>>>>>> java.rmi.server.RemoteObjectInvocationHandler.invokeRemoteMethod(RemoteObjectInvocationHandler.java:227) >>>>>>>> at >>>>>>>> java.rmi.server.RemoteObjectInvocationHandler.invoke(RemoteObjectInvocationHandler.java:179) >>>>>>>> at com.sun.proxy.$Proxy14.remoteCall(Unknown Source) >>>>>>>> at >>>>>>>> org.ops4j.pax.exam.rbc.client.intern.RemoteBundleContextClientImpl$1.invoke(RemoteBundleContextClientImpl.java:102) >>>>>>>> at com.sun.proxy.$Proxy15.call(Unknown Source) >>>>>>>> at >>>>>>>> org.ops4j.pax.exam.rbc.client.intern.RemoteBundleContextClientImpl.call(RemoteBundleContextClientImpl.java:290) >>>>>>>> at >>>>>>>> org.ops4j.pax.exam.container.remote.RBCRemoteTarget.call(RBCRemoteTarget.java:60) >>>>>>>> at >>>>>>>> org.ops4j.pax.exam.karaf.container.internal.KarafTestContainer.call(KarafTestContainer.java:652) >>>>>>>> at >>>>>>>> org.ops4j.pax.exam.spi.reactors.EagerSingleStagedReactor.invoke(EagerSingleStagedReactor.java:109) >>>>>>>> at >>>>>>>> org.ops4j.pax.exam.junit.impl.ProbeRunner$2.evaluate(ProbeRunner.java:267) >>>>>>>> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) >>>>>>>> at >>>>>>>> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) >>>>>>>> at >>>>>>>> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) >>>>>>>> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) >>>>>>>> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) >>>>>>>> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) >>>>>>>> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) >>>>>>>> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) >>>>>>>> at org.junit.runners.ParentRunner.run(ParentRunner.java:363) >>>>>>>> at >>>>>>>> org.ops4j.pax.exam.junit.impl.ProbeRunner.run(ProbeRunner.java:98) >>>>>>>> at org.ops4j.pax.exam.junit.PaxExam.run(PaxExam.java:93) >>>>>>>> at >>>>>>>> org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365) >>>>>>>> at >>>>>>>> org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273) >>>>>>>> at >>>>>>>> org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238) >>>>>>>> at >>>>>>>> org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159) >>>>>>>> at >>>>>>>> org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:379) >>>>>>>> at >>>>>>>> org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:340) >>>>>>>> at >>>>>>>> org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:125) >>>>>>>> at >>>>>>>> org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:413) >>>>>>>> >>>>>>>> >>>>>>>> What causes this? How to troubleshoot or how to increase the >>>>>>>> timeout? >>>>>>>> >>>>>>>> Best regards, >>>>>>>> Alex soto >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>> >>>>>>> -- >>>>>>> Jean-Baptiste Onofré >>>>>>> [email protected] <mailto:[email protected]> >>>>>>> <mailto:[email protected]> <mailto:[email protected]> >>>>>>> http://blog.nanthrax.net >>>>>>> <http://blog.nanthrax.net/> <http://blog.nanthrax.net/> >>>>>>> Talend - http://www.talend.com >>>>>>> <http://www.talend.com/> <http://www.talend.com/> >>>>>> >>>>> >>>>> -- >>>>> Jean-Baptiste Onofré >>>>> [email protected] >>>>> <mailto:[email protected]> <mailto:[email protected]> >>>>> http://blog.nanthrax.net >>>>> <http://blog.nanthrax.net/> <http://blog.nanthrax.net/> >>>>> Talend - http://www.talend.com >>>>> <http://www.talend.com/> <http://www.talend.com/> >>>> >>> >>> -- >>> Jean-Baptiste Onofré >>> [email protected] <mailto:[email protected]> >>> http://blog.nanthrax.net <http://blog.nanthrax.net/> >>> Talend - http://www.talend.com <http://www.talend.com/> >> > -- Jean-Baptiste Onofré [email protected] http://blog.nanthrax.net Talend - http://www.talend.com
