Details
-
Bug
-
Resolution: Unresolved
-
Major
-
None
-
28.0.0.Beta1
-
None
-
-
---
-
---
Description
When running rest-client tck tests in WF TS in our lab we experience failures of Timeout*Test (TimeoutBuilderIndependentOfMPConfigTest,TimeoutViaMPConfigWithConfigKeyTest,TimeoutViaMPConfigWithConfigKeyTest, ...)
Failures seems intermittent but are very often (like stable). We do not see this errors in Wildfly CI neither I can't reproduce it locally. I do not see yet what could be special about our lab, maybe just machines are slower than usual. Failures of tests are presented like that.
Method TimeoutTestBase.testConnectTimeout()[pri:0, instance:org.eclipse.microprofile.rest.client.tck.timeout.TimeoutBuilderIndependentOfMPConfigTest@209da20d] should have thrown an exception of type class jakarta.ws.rs.ProcessingException
Method TimeoutTestBase.testConnectTimeout()[pri:0, instance:org.eclipse.microprofile.rest.client.tck.timeout.TimeoutBuilderIndependentOfMPConfigTest@209da20d] should have thrown an exception of type class jakarta.ws.rs.ProcessingException at org.testng.internal.ExpectedExceptionsHolder.noException(ExpectedExceptionsHolder.java:82) at org.testng.internal.TestInvoker.considerExceptions(TestInvoker.java:749) at org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:634) at org.testng.internal.TestInvoker.invokeTestMethod(TestInvoker.java:173) at org.testng.internal.MethodRunner.runInSequence(MethodRunner.java:46) at org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:824) at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:146) at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146) at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128) at java.base/java.util.ArrayList.forEach(ArrayList.java:1511) at org.testng.TestRunner.privateRun(TestRunner.java:794) at org.testng.TestRunner.run(TestRunner.java:596) at org.testng.SuiteRunner.runTest(SuiteRunner.java:377) at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:371) at org.testng.SuiteRunner.privateRun(SuiteRunner.java:332) at org.testng.SuiteRunner.run(SuiteRunner.java:276) at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53) at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96) at org.testng.TestNG.runSuitesSequentially(TestNG.java:1212) at org.testng.TestNG.runSuitesLocally(TestNG.java:1134) at org.testng.TestNG.runSuites(TestNG.java:1063) at org.testng.TestNG.run(TestNG.java:1031) at org.apache.maven.surefire.testng.TestNGExecutor.run(TestNGExecutor.java:135) at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.executeMulti(TestNGDirectoryTestSuite.java:193) at org.apache.maven.surefire.testng.TestNGDirectoryTestSuite.execute(TestNGDirectoryTestSuite.java:94) at org.apache.maven.surefire.testng.TestNGProvider.invoke(TestNGProvider.java:146) at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384) at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345) at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
Digging deeper it shows up in server log there is this exception.
[[0m^[[31m09:38:36,581 ERROR [io.undertow.request] (default task-1) UT005023: Exception handling request to /TimeoutTest/ArquillianServletRunnerEE9: java.lang.RuntimeException: Could not write to output at deployment.TimeoutTest.war//org.jboss.arquillian.protocol.servlet5.runner.ServletTestRunner.writeObject(ServletTestRunner.java:204) at deployment.TimeoutTest.war//org.jboss.arquillian.protocol.servlet5.runner.ServletTestRunner.execute(ServletTestRunner.java:125) at deployment.TimeoutTest.war//org.jboss.arquillian.protocol.servlet5.runner.ServletTestRunner.doGet(ServletTestRunner.java:86) at jakarta.servlet.api@6.0.0//jakarta.servlet.http.HttpServlet.service(HttpServlet.java:527) at jakarta.servlet.api@6.0.0//jakarta.servlet.http.HttpServlet.service(HttpServlet.java:614) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129) at io.smallrye.opentracing-contrib@3.0.0//io.smallrye.opentracing.contrib.jaxrs2.server.SpanFinishingFilter.doFilter(SpanFinishingFilter.java:69) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:67) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36) at org.wildfly.security.elytron-web.undertow-server@3.0.0.Final//org.wildfly.elytron.web.undertow.server.ElytronRunAsHandler.lambda$handleRequest$1(ElytronRunAsHandler.java:68) at org.wildfly.security.elytron-base@2.0.0.Final//org.wildfly.security.auth.server.FlexibleIdentityAssociation.runAsFunctionEx(FlexibleIdentityAssociation.java:103) at org.wildfly.security.elytron-base@2.0.0.Final//org.wildfly.security.auth.server.Scoped.runAsFunctionEx(Scoped.java:161) at org.wildfly.security.elytron-base@2.0.0.Final//org.wildfly.security.auth.server.Scoped.runAs(Scoped.java:73) at org.wildfly.security.elytron-web.undertow-server@3.0.0.Final//org.wildfly.elytron.web.undertow.server.ElytronRunAsHandler.handleRequest(ElytronRunAsHandler.java:67) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.RedirectDirHandler.handleRequest(RedirectDirHandler.java:68) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:117) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57) at io.undertow.core@2.3.0.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.core@2.3.0.Final//io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64) at io.undertow.core@2.3.0.Final//io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43) at org.wildfly.security.elytron-web.undertow-server-servlet@3.0.0.Final//org.wildfly.elytron.web.undertow.server.servlet.CleanUpHandler.handleRequest(CleanUpHandler.java:38) at io.undertow.core@2.3.0.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at org.wildfly.extension.undertow@28.0.0.Beta1-SNAPSHOT//org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61) at io.undertow.core@2.3.0.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at org.wildfly.extension.undertow@28.0.0.Beta1-SNAPSHOT//org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.SendErrorPageHandler.handleRequest(SendErrorPageHandler.java:52) at io.undertow.core@2.3.0.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:275) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:134) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:131) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43) at org.wildfly.extension.undertow@28.0.0.Beta1-SNAPSHOT//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1430) at org.wildfly.extension.undertow@28.0.0.Beta1-SNAPSHOT//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1430) at org.wildfly.extension.undertow@28.0.0.Beta1-SNAPSHOT//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1430) at org.wildfly.extension.undertow@28.0.0.Beta1-SNAPSHOT//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1430) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:255) at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:100) at io.undertow.core@2.3.0.Final//io.undertow.server.Connectors.executeRootHandler(Connectors.java:391) at io.undertow.core@2.3.0.Final//io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:859) at org.jboss.threads@2.4.0.Final//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35) at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990) at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486) at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377) at org.jboss.xnio@3.8.8.Final//org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1282) at java.base/java.lang.Thread.run(Thread.java:834) Caused by: java.lang.IllegalStateException: UT010019: Response already commited at io.undertow.servlet@2.3.0.Final//io.undertow.servlet.spec.HttpServletResponseImpl.sendError(HttpServletResponseImpl.java:128) at deployment.TimeoutTest.war//org.jboss.arquillian.protocol.servlet5.runner.ServletTestRunner.writeObject(ServletTestRunner.java:202) ... 51 more
So seems to me jakarta.ws.rs.ProcessingException is not thrown from RestClient, because Server error (500) was emitted. Now question is how it can happen series of rest calls produce UT010019: Response already commited on server side. If this is not actual a bug in Undertow/Arquillian. Can it be that timeouting requests makes UT010019: Response already commited happen?
