After the integration test finished (with error) I ran Karaf in the same
Pax-Exam directory:
target/exam/621f714b-cc7e-4a0c-91cc-b8ce65d02340/bin/karaf
The command list shows everything as ACTIVE.
Also command scr:list shows all components either as active or satisfied.
The only anomaly in the logs is:
2019-05-08T09:57:46,133 | WARN | Thread-47 | Activator
| 196 - org.ops4j.pax.exam.rbc - 4.11.0 | Registration of RBC failed:
java.rmi.ConnectException: Connection refused to host: 127.0.0.1; nested
exception is:
java.net.ConnectException: Connection refused (Connection refused)
at sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:619)
~[?:?]
at
sun.rmi.transport.tcp.TCPChannel.createConnection(TCPChannel.java:216) ~[?:?]
at sun.rmi.transport.tcp.TCPChannel.newConnection(TCPChannel.java:202)
~[?:?]
at sun.rmi.server.UnicastRef.newCall(UnicastRef.java:338) ~[?:?]
at
sun.rmi.registry.RegistryImpl_Stub.rebind(RegistryImpl_Stub.java:147) ~[?:?]
at
org.ops4j.pax.exam.rbc.internal.Activator.bindRBC(Activator.java:145) ~[?:?]
at
org.ops4j.pax.exam.rbc.internal.Activator.access$600(Activator.java:47) ~[?:?]
at org.ops4j.pax.exam.rbc.internal.Activator$2.call(Activator.java:121)
~[?:?]
at
org.ops4j.pax.swissbox.core.ContextClassLoaderUtils.doWithClassLoader(ContextClassLoaderUtils.java:60)
~[200:org.ops4j.pax.swissbox.core:1.8.2]
at
org.ops4j.pax.exam.rbc.internal.Activator.register(Activator.java:105)
[196:org.ops4j.pax.exam.rbc:4.11.0]
at
org.ops4j.pax.exam.rbc.internal.Activator.access$000(Activator.java:47)
[196:org.ops4j.pax.exam.rbc:4.11.0]
at org.ops4j.pax.exam.rbc.internal.Activator$1.run(Activator.java:85)
[196:org.ops4j.pax.exam.rbc:4.11.0]
at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.net.ConnectException: Connection refused (Connection refused)
at java.net.PlainSocketImpl.socketConnect(Native Method) ~[?:?]
at
java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
~[?:?]
at
java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
~[?:?]
at
java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
~[?:?]
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[?:?]
at java.net.Socket.connect(Socket.java:589) ~[?:?]
at java.net.Socket.connect(Socket.java:538) ~[?:?]
at java.net.Socket.<init>(Socket.java:434) ~[?:?]
at java.net.Socket.<init>(Socket.java:211) ~[?:?]
at
sun.rmi.transport.proxy.RMIDirectSocketFactory.createSocket(RMIDirectSocketFactory.java:40)
~[?:?]
at
sun.rmi.transport.proxy.RMIMasterSocketFactory.createSocket(RMIMasterSocketFactory.java:148)
~[?:?]
at sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:613)
~[?:?]
... 12 more
But I think that is expected, since the Integration Test is not running.
> On May 8, 2019, at 9:35 AM, Jean-Baptiste Onofré <[email protected]> wrote:
>
> 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] <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]>
>>>> <mailto:[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] <mailto:[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]>>
>>>>>>>> <mailto:[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]>>
>>>>>>>> <mailto:[email protected] <mailto:[email protected]>>
>>>>>>>> <mailto:[email protected] <mailto:[email protected]>>
>>>>>>>> http://blog.nanthrax.net <http://blog.nanthrax.net/>
>>>>>>>> <http://blog.nanthrax.net/ <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/ <http://www.talend.com/>>
>>>>>>>> <http://www.talend.com/ <http://www.talend.com/>>
>>>>>>>
>>>>>>
>>>>>> --
>>>>>> Jean-Baptiste Onofré
>>>>>> [email protected] <mailto:[email protected]>
>>>>>> <mailto:[email protected] <mailto:[email protected]>>
>>>>>> <mailto:[email protected] <mailto:[email protected]>>
>>>>>> http://blog.nanthrax.net <http://blog.nanthrax.net/>
>>>>>> <http://blog.nanthrax.net/ <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/ <http://www.talend.com/>>
>>>>>> <http://www.talend.com/ <http://www.talend.com/>>
>>>>>
>>>>
>>>> --
>>>> 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/ <http://blog.nanthrax.net/>>
>>>> Talend - http://www.talend.com <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/>
