Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

FastInfosetTest.fastInfoset fails intemittently #1636

Open
ppalaga opened this issue Dec 1, 2024 · 2 comments
Open

FastInfosetTest.fastInfoset fails intemittently #1636

ppalaga opened this issue Dec 1, 2024 · 2 comments

Comments

@ppalaga
Copy link
Contributor

ppalaga commented Dec 1, 2024

Seen twice on the CI today:

Error:  Tests run: 2, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 37.73 s <<< FAILURE! -- in io.quarkiverse.cxf.it.fastinfoset.FastInfosetTest
Error:  io.quarkiverse.cxf.it.fastinfoset.FastInfosetTest.fastInfoset -- Time elapsed: 30.10 s <<< ERROR!
java.net.SocketTimeoutException: Read timed out
	at java.base/sun.nio.ch.NioSocketImpl.timedRead(NioSocketImpl.java:288)
	at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:314)
	at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:355)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:569)
	at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:154)
	at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:118)
	at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:560)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:452)
	at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:413)
	at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:321)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:415)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:378)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:356)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:70)
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:429)
	at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invokePropagateNotFound$6(SynchronousDispatcher.java:275)
	at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:154)
	at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:321)
	at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:157)
	at org.jboss.resteasy.core.SynchronousDispatcher.invokePropagateNotFound(SynchronousDispatcher.java:260)
	at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:86)
	at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:151)
	at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler$1.run(VertxRequestHandler.java:97)
	at io.quarkus.vertx.core.runtime.VertxCoreRecorder$15.runWith(VertxCoreRecorder.java:637)
	at org.jboss.threads.EnhancedQueueExecutor$Task.doRunWith(EnhancedQueueExecutor.java:2675)
	at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2654)
	at org.jboss.threads.EnhancedQueueExecutor.runThreadBody(EnhancedQueueExecutor.java:1627)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1594)
	at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:11)
	at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:11)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:840)
2024-12-01 12:21:10,689 INFO  [io.quarkus] (main) quarkus-cxf-integration-test-fast-infoset stopped in 10.042s
[INFO] 
[INFO] Results:
[INFO] 
Error:  Errors: 
Error:    FastInfosetTest.fastInfoset:51 » SocketTimeout Read timed out
@ppalaga
Copy link
Contributor Author

ppalaga commented Dec 4, 2024

On Windows:

[INFO] Running io.quarkiverse.cxf.it.fastinfoset.FastInfosetTest
2024-12-04 15:11:27,511 INFO  [org.apa.cxf.end.ServerImpl] (build-75) Setting the server's publish address to be /QuarkusCxfProcessor/dummy-7808757518188794136
2024-12-04 15:11:27,511 INFO  [io.qua.cxf.dep.QuarkusCxfProcessor] (build-75) Generated 9 ancillary classes for service io.quarkiverse.cxf.it.FastInfosetHelloServiceImpl
2024-12-04 15:11:27,542 INFO  [org.apa.cxf.end.ServerImpl] (build-75) Setting the server's publish address to be /QuarkusCxfProcessor/dummy-5650348013172389722
2024-12-04 15:11:27,542 INFO  [io.qua.cxf.dep.QuarkusCxfProcessor] (build-75) Generated 0 ancillary classes for service io.quarkiverse.cxf.it.GzipHelloServiceImpl
2024-12-04 15:11:27,558 INFO  [io.qua.cxf.dep.QuarkusCxfProcessor] (build-75) Generated 0 ancillary classes for client io.quarkiverse.cxf.it.FastInfosetHelloService
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)

2024-12-04 15:12:06,716 INFO  [io.qua.thread-pool] (main) Awaiting thread pool shutdown; 1 thread(s) running with -1 task(s) waiting
2024-12-04 15:12:11,720 INFO  [io.qua.thread-pool] (main) Awaiting thread pool shutdown; 1 thread(s) running with -1 task(s) waiting
java.lang.NullPointerException: Cannot invoke "org.apache.cxf.endpoint.Client.getEndpoint()" because the return value of "org.apache.cxf.jaxws.JaxWsClientProxy.getClient()" is null
	at org.apache.cxf.jaxws.JaxWsClientProxy.addressChanged(JaxWsClientProxy.java:297)
	at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:147)
	at jdk.proxy6/jdk.proxy6.$Proxy150.hello(Unknown Source)
	at io.quarkiverse.cxf.it.FastInfosetResource.hello(FastInfosetResource.java:31)
	at io.quarkiverse.cxf.it.FastInfosetResource$quarkusrestinvoker$hello_9cad462cf1be2fc6e183f7950377a9070692c9a5.invoke(Unknown Source)
	at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
	at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
	at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)
	at io.quarkus.vertx.core.runtime.VertxCoreRecorder$15.runWith(VertxCoreRecorder.java:637)
	at org.jboss.threads.EnhancedQueueExecutor$Task.doRunWith(EnhancedQueueExecutor.java:2675)
	at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2654)
	at org.jboss.threads.EnhancedQueueExecutor.runThreadBody(EnhancedQueueExecutor.java:1627)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1594)
	at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:11)
	at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:11)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:840)
2024-12-04 15:12:11,720 WARN  [io.qua.ver.htt.run.QuarkusErrorHandler] (executor-thread-1) Worker thread pool exhaustion, no more worker threads available - returning a `503 - SERVICE UNAVAILABLE` response.
2024-12-04 15:12:11,720 INFO  [io.quarkus] (main) quarkus-cxf-integration-test-fast-infoset stopped in 10.038s
[INFO] 
[INFO] Results:
[INFO] 
Error:  Errors: 
Error:    FastInfosetTest.fastInfoset:51 � SocketTimeout Read timed out
[INFO] 
Error:  Tests run: 2, Failures: 0, Errors: 1, Skipped: 0

ppalaga added a commit to ppalaga/quarkus-cxf that referenced this issue Dec 6, 2024
@ppalaga
Increase the RestAssured socket timeout in hope to see some Vert.x st…
aa954ff 
…ack trace for quarkiverse#1636
ppalaga added a commit to ppalaga/quarkus-cxf that referenced this issue Dec 6, 2024
@ppalaga
Increase the RestAssured socket timeout in hope to see some Vert.x st…
4ddc3d3 
…ack trace for quarkiverse#1636
ppalaga added a commit that referenced this issue Dec 6, 2024
@ppalaga
Increase the RestAssured socket timeout in hope to see some Vert.x st…
4df9d45 
…ack trace for #1636
@ppalaga
Copy link
Contributor Author

ppalaga commented Dec 13, 2024

Another similar timeout:

Error:  io.quarkiverse.cxf.deployment.test.Client3xx4xx5xxTest.endpointUri404OnEventLoop -- Time elapsed: 30.05 s <<< ERROR!
java.net.SocketTimeoutException: Read timed out
	at java.base/sun.nio.ch.NioSocketImpl.timedRead(NioSocketImpl.java:288)
	at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:314)
	at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:355)
	at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:808)
	at java.base/java.net.Socket$SocketInputStream.read(Socket.java:966)
	at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:161)
	at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:82)
	at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:276)
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
	at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
	at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:294)
	at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:328)
	at groovy.lang.MetaClassImpl.doInvokeMethod(MetaClassImpl.java:1333)
	at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1088)
	at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1007)
	at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:790)
	at io.restassured.internal.RequestSpecificationImpl.invokeMethod(RequestSpecificationImpl.groovy)
	at org.codehaus.groovy.runtime.callsite.PogoInterceptableSite.call(PogoInterceptableSite.java:46)
	at org.codehaus.groovy.runtime.callsite.PogoInterceptableSite.callCurrent(PogoInterceptableSite.java:57)
	at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:203)
	at io.restassured.internal.RequestSpecificationImpl.applyPathParamsAndSendRequest(RequestSpecificationImpl.groovy:1710)
	at io.restassured.internal.RequestSpecificationImpl.this$2$applyPathParamsAndSendRequest(RequestSpecificationImpl.groovy)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:569)
	at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:343)
	at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:328)
	at groovy.lang.MetaClassImpl.doInvokeMethod(MetaClassImpl.java:1333)
	at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1088)
	at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1007)
	at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:790)
	at io.restassured.internal.RequestSpecificationImpl.invokeMethod(RequestSpecificationImpl.groovy)
	at org.codehaus.groovy.runtime.callsite.PogoInterceptableSite.call(PogoInterceptableSite.java:46)
	at org.codehaus.groovy.runtime.callsite.PogoInterceptableSite.callCurrent(PogoInterceptableSite.java:57)
	at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:203)
	at io.restassured.internal.RequestSpecificationImpl.post(RequestSpecificationImpl.groovy:176)
	at io.restassured.internal.RequestSpecificationImpl.post(RequestSpecificationImpl.groovy)
	at io.quarkiverse.cxf.deployment.test.Client3xx4xx5xxTest.endpointUri404OnEventLoop(Client3xx4xx5xxTest.java:213)
	at java.base/java.lang.reflect.Method.invoke(Method.java:569)
	at io.quarkus.test.QuarkusUnitTest.runExtensionMethod(QuarkusUnitTest.java:513)
	at io.quarkus.test.QuarkusUnitTest.interceptTestMethod(QuarkusUnitTest.java:427)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)

ppalaga added a commit that referenced this issue Dec 23, 2024
@ppalaga
Put some sleep into the FastInfoset test to be able to investigate #1636
01e3b75
ppalaga added a commit that referenced this issue Dec 23, 2024
@ppalaga
Put some sleep into the FastInfoset test to be able to investigate #1636
41e1e2b
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@ppalaga