Hallo,
with new CXF versions (3.6.x and 4.x) we have problems when transferring large
files via SOAP.
I believe the problem stems from the handling of request/read timeouts (set via
HTTPClientPolicy#setReceiveTimeout) in new CXF versions.
In the past (3.5.x and earlier) these timeouts seemed equivalent to setting the
Read Timeout of a socket. Newer CXF versions (3.6.x and 4.x) seem to have
switched to using the new JDK HttpClient. When using a newer CXF version it
seems to be the "Request Timeout" that is set in the new JDK
java.net.http.HttpClient (in particular the
"rb.timeout(Duration.ofMillis(rtimeout));" call in
HttpClientWrappedOutputStream#setProtocolHeaders).
As far as I can tell, a big difference is, that a socket timeout will start
counting down, when a client has finished transmitting the request and starts
waiting for the response. The "Request Timeout" of the new HttpClient seems to
start, when sending the request.
That means, when a client sends a large file, it may trigger its own "Request
Timeout" while transferring the request.
Please correct me if I am wrong here. However, it matches the behaviour I see,
when watching a CXF connection in Wireshark. It will be busy transferring data
to the server and then suddenly close the connection (from the client) with a
FIN package. This corresponds to a TimeoutEvent that is handled by the
HttpClient I see in the debugger.
Surprisingly I do not see an exception mentioning a Timeout in the client
output. The server logs an "early EOF" (because the client has unexpectedly
closed the connection). The client however only logs the following error:
org.apache.cxf.interceptor.Fault: Could not write attachments.
at
org.apache.cxf.interceptor.AttachmentOutInterceptor$AttachmentOutEndingInterceptor.handleMessage(AttachmentOutInterceptor.java:128)
at
org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:307)
at
org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:530)
at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:441)
at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:356)
at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:314)
at
org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96)
at
org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:140)
[...]
Caused by: java.io.IOException: Read end dead
at
java.base/java.io.PipedInputStream.checkStateForReceive(PipedInputStream.java:268)
at
java.base/java.io.PipedInputStream.awaitSpace(PipedInputStream.java:274)
at
java.base/java.io.PipedInputStream.receive(PipedInputStream.java:237)
at
java.base/java.io.PipedOutputStream.write(PipedOutputStream.java:154)
at
org.apache.cxf.transport.http.HttpClientHTTPConduit$HttpClientPipedOutputStream.write(HttpClientHTTPConduit.java:390)
at
org.apache.cxf.io.AbstractWrappedOutputStream.write(AbstractWrappedOutputStream.java:51)
at
org.apache.cxf.io.AbstractThresholdOutputStream.write(AbstractThresholdOutputStream.java:69)
at javax.activation.DataHandler.writeTo(DataHandler.java:292)
at
org.apache.cxf.attachment.AttachmentSerializer.writeAttachments(AttachmentSerializer.java:322)
at
org.apache.cxf.interceptor.AttachmentOutInterceptor$AttachmentOutEndingInterceptor.handleMessage(AttachmentOutInterceptor.java:126)
... 41 common frames omitted
Which seems to be a consequence of the thread having stopped to send data.
I see this output, when enabling trace logging for the JDK HttpClient:
INFORMATION: MISC: purgeTimeoutsAndReturnNextDeadline: handling 1 events,
remaining 0, next deadline: 0
Mai 15, 2024 6:02:34 PM jdk.internal.net.http.HttpClientImpl
purgeTimeoutsAndReturnNextDeadline
INFORMATION: MISC: Firing timer ResponseTimerEvent[TimeoutEvent[id=11,
duration=PT9S, deadline=2024-05-15T16:02:34.622262100Z]]
Mai 15, 2024 6:02:34 PM jdk.internal.net.http.PlainHttpConnection close
My questions are:
1) Do I understand the new/changed behaviour of timeouts correctly or am I
missing something?
2) Does the CXF client really not report these timeouts? I am not sure what to
tell my clients how to diagnose the problem.
3) Our application receives a lot of files. 99% are only a couple of kb big.
Some are 10 GB. If my understanding, that the time it takes to transfer a file
is included in the timeout, how are we supposed to tell our clients to
configure their timeouts? In the past (with read timeouts) the only important
thing was, that our application replied quickly enough after receiving the
data. Now it seems, when you send a bigger file, the timeout configured needs
to be bigger?
I would really appreciate any clarification. I am worried, I am
misunderstanding the situation.
Thank you for your help,
Johannes
