Hi Roman,
Sorry, took me a bit longer to troubleshoot the test cases but at this point
the picture
is very clear. So yeah, test in question is not deterministic (flaky, in other
words) due
to the way CXF handles async flows (in this case, on client side). The
interceptors are
called in the context of the dedicated work pool. The response completion is
tied to the moment
the stream is closed, after that the interceptors chain is resumed. Which
essentially
is the cause why the test may fail from time to time:
1) Response is completed, the callback is triggered (worker thread), completing
the CompletableFuture
2) The interceptor chain is still ongoing (worker thread)
3) The test unblocks (main thread) and proceed with assertions
4) Here we come with the timing issue
It turned out to be very easy to reproduce, however it also seems to be the
issue
specific to CXF implementation. We could make the test more reliable (but it
would leak
CXF specifics, either directly or indirectly) or we could delay the response
completion
till the moment interceptors do actually finish the processing, could be not
trivial change
though. Do you have any thoughts on that?
Best Regards,
Andriy Redko
AR> Hi Romain,
AR> Run the test suite probably few dozen times on Windows and Ubuntu boxes,
got it failing a few times on Ubuntu (but no failures on Windows):
AR> [INFO] RequestHandlerClass from context returned
com.github.tomakehurst.wiremock.http.AdminRequestHandler. Normalized mapped
under returned 'null'
AR> [ERROR] Tests run: 145, Failures: 1, Errors: 0, Skipped: 1, Time elapsed:
90.181 s <<< FAILURE! - in TestSuitealized mapped under returned 'null'
AR> [ERROR]
testAsyncInvocationInterceptorProvider(org.eclipse.microprofile.rest.client.tck.asynctests.AsyncMethodTest)
Time elapsed: 0.103 s <<< FAILURE!
AR> java.lang.AssertionError: expected [80] but found [null]
AR> at
AR>
org.eclipse.microprofile.rest.client.tck.asynctests.AsyncMethodTest.testAsyncInvocationInterceptorProvider(AsyncMethodTest.java:235)
AR> [INFO]
AR> [INFO] Results:
AR> [INFO]
AR> [ERROR] Failures:
AR> [ERROR]
AsyncMethodTest>Arquillian.run:138->testAsyncInvocationInterceptorProvider:235
expected [80] but found [null]
AR> [INFO]
AR> [ERROR] Tests run: 145, Failures: 1, Errors: 0, Skipped: 1
AR> [INFO]
AR> Yes, you are right, the test is non-deterministic. Trying to understand
what is going on, may take some time.
AR> Thanks for noticing it.
AR> Best Regards,
AR> Andriy Redko
RMB>> Hi Andriy,
RMB>> Result is random but it is
RMB>>
org.eclipse.microprofile.rest.client.tck.asynctests.AsyncMethodTest.testAsyncInvocationInterceptorProvider
RMB>> Le dim. 2 juin 2019 à 19:12, Andriy Redko <[email protected]> a écrit :
RMB>> Hi Romain,
RMB>> Yes, the async flows are difficult to test, which test cases for MP rest
client are
RMB>> intermittently failing for you? I would be able to take a look. Thanks.
RMB>> Best Regards,
RMB>> Andriy Redko
RMB>>> Hi everyone,
RMB>>> I just realize - thanks for failling test on jenkins, that part of the
test
RMB>>> suite is not deterministic.
RMB>>> It mainly affects async calls. I found some opentracing ones - fixed by
RMB>>>
https://github.com/apache/cxf/pull/561/commits/23cbbb9db73a74913fd4294f805032f923ffcf09
RMB>>> -
RMB>>> and there are some in MP rest client TCK (async interceptor provider).
RMB>>> I didn't dig deep into the root cause but I suspect we ack the client
RMB>>> before the full chain is processed on the server side.
RMB>>> Does it ring any bell to anyone?
RMB>>> Romain Manni-Bucau
RMB>>> @rmannibucau <https://twitter.com/rmannibucau> | Blog
RMB>>> <https://rmannibucau.metawerx.net/> | Old Blog
RMB>>> <http://rmannibucau.wordpress.com> | Github
<https://github.com/rmannibucau> |
RMB>>> LinkedIn <https://www.linkedin.com/in/rmannibucau> | Book
RMB>>>
<https://www.packtpub.com/application-development/java-ee-8-high-performance>
