Hello, the blocking code could use a different reader thread, but maybe that would be too much overhead? (Having a single polling thread might have a lower footprint but could create concurrency stress)
The question is if the sync code could use available() after sending some buffers (not only the header but enough to fill a send buffer, say x*32kb? (configurable)). This might block but it also might catch early answers/closes. Gruss Bernd -- http://bernd.eckenfels.net ________________________________ Von: Oleg Kalnichevski <ol...@apache.org> Gesendet: Friday, May 22, 2020 10:18:02 PM An: HttpClient User Discussion <httpclient-users@hc.apache.org> Betreff: Re: Server-side mid-air connection close on upload On Fri, 2020-05-22 at 19:25 +0200, Michael Osipov wrote: > Hi folks, > > I believe that this is a wellknown limitation in blocking I/O, but > would > like to know how to solve/workaround this issue. The source > discussion > is here [1]. > > Bascially, I am posting a large file (~7 MB) to Tomcat 8.5.54 where > the > resource needs to be authenticated: > > > 69 [main] DEBUG > > org.apache.hc.client5.http.impl.classic.InternalHttpClient - ex- > > 00000001: preparing request execution > > 145 [main] DEBUG > > org.apache.hc.client5.http.protocol.RequestAddCookies - Cookie spec > > selected: strict > > 150 [main] DEBUG > > org.apache.hc.client5.http.protocol.RequestAuthCache - Auth cache > > not set in the context > > 150 [main] DEBUG > > org.apache.hc.client5.http.impl.classic.ProtocolExec - ex-00000001: > > target auth state: UNCHALLENGED > > 151 [main] DEBUG > > org.apache.hc.client5.http.impl.classic.ProtocolExec - ex-00000001: > > proxy auth state: UNCHALLENGED > > 151 [main] DEBUG > > org.apache.hc.client5.http.impl.classic.ConnectExec - ex-00000001: > > acquiring connection with route {s}->https://<hostname>:11111 > > 151 [main] DEBUG > > org.apache.hc.client5.http.impl.classic.InternalHttpClient - ex- > > 00000001: acquiring endpoint (3 MINUTES) > > 152 [main] DEBUG > > org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManag > > er - ex-00000001: endpoint lease request (3 MINUTES) [route: {s}-> > > https://<hostname>:11111][total available: 0; route allocated: 0 of > > 5; total allocated: 0 of 25] > > 175 [main] DEBUG > > org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManag > > er - ex-00000001: endpoint leased [route: {s}-> > > https://<hostname>:11111][total available: 0; route allocated: 1 of > > 5; total allocated: 1 of 25] > > 183 [main] DEBUG > > org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManag > > er - ex-00000001: acquired ep-00000000 > > 183 [main] DEBUG > > org.apache.hc.client5.http.impl.classic.InternalHttpClient - ex- > > 00000001: acquired endpoint ep-00000000 > > 183 [main] DEBUG > > org.apache.hc.client5.http.impl.classic.ConnectExec - ex-00000001: > > opening connection {s}->https://<hostname>:11111 > > 184 [main] DEBUG > > org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep- > > 00000000: connecting endpoint (3 MINUTES) > > 184 [main] DEBUG > > org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManag > > er - ep-00000000: connecting endpoint to https://<hostname>:11111 > > (3 MINUTES) > > 201 [main] DEBUG > > org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOpera > > tor - http-outgoing-0: connecting to <hostname>/<ip>:11111 > > 201 [main] DEBUG > > org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory - > > Connecting socket to <hostname>/<ip>:11111 with timeout 3 MINUTES > > 237 [main] DEBUG > > org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory - Enabled > > protocols: [TLSv1.3, TLSv1.2] > > 237 [main] DEBUG > > org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory - Enabled > > cipher suites:[TLS_AES_256_GCM_SHA384, TLS_AES_128_GCM_SHA256, > > TLS_CHACHA20_POLY1305_SHA256, > > TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, > > TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, > > TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256, > > TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, > > TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256, > > TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, > > TLS_DHE_RSA_WITH_AES_256_GCM_SHA384, > > TLS_DHE_RSA_WITH_CHACHA20_POLY1305_SHA256, > > TLS_DHE_DSS_WITH_AES_256_GCM_SHA384, > > TLS_DHE_RSA_WITH_AES_128_GCM_SHA256, > > TLS_DHE_DSS_WITH_AES_128_GCM_SHA256, > > TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384, > > TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384, > > TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA256, > > TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA256, > > TLS_DHE_RSA_WITH_AES_256_CBC_SHA256, > > TLS_DHE_DSS_WITH_AES_256_CBC_SHA256, > > TLS_DHE_RSA_WITH_AES_128_CBC_SHA256, > > TLS_DHE_DSS_WITH_AES_128_CBC_SHA256, > > TLS_ECDH_ECDSA_WITH_AES_256_GCM_SHA384, > > TLS_ECDH_RSA_WITH_AES_256_GCM_SHA384, > > TLS_ECDH_ECDSA_WITH_AES_128_GCM_SHA256, > > TLS_ECDH_RSA_WITH_AES_128_GCM_SHA256, > > TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384, > > TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384, > > TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA256, > > TLS_ECDH_RSA_WITH_AES_128_CBC_SHA256, > > TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, > > TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, > > TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, > > TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, > > TLS_DHE_RSA_WITH_AES_256_CBC_SHA, TLS_DHE_DSS_WITH_AES_256_CBC_SHA, > > TLS_DHE_RSA_WITH_AES_128_CBC_SHA, TLS_DHE_DSS_WITH_AES_128_CBC_SHA, > > TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA, > > TLS_ECDH_RSA_WITH_AES_256_CBC_SHA, > > TLS_ECDH_ECDSA_WITH_AES_128_CBC_SHA, > > TLS_ECDH_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_GCM_SHA384, > > TLS_RSA_WITH_AES_128_GCM_SHA256, TLS_RSA_WITH_AES_256_CBC_SHA256, > > TLS_RSA_WITH_AES_128_CBC_SHA256, TLS_RSA_WITH_AES_256_CBC_SHA, > > TLS_RSA_WITH_AES_128_CBC_SHA, TLS_EMPTY_RENEGOTIATION_INFO_SCSV] > > 237 [main] DEBUG > > org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory - > > Starting handshake > > 431 [main] DEBUG > > org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory - Secure > > session established > > 431 [main] DEBUG > > org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory > > - negotiated protocol: TLSv1.3 > > 431 [main] DEBUG > > org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory > > - negotiated cipher suite: TLS_AES_256_GCM_SHA384 > > 431 [main] DEBUG > > org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory - peer > > principal: CN=<hostname>, OU=LDA DW, O=Siemens, C=DE > > 431 [main] DEBUG > > org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory - peer > > alternative names: [<hostname>] > > 431 [main] DEBUG > > org.apache.hc.client5.http.ssl.SSLConnectionSocketFactory - issuer > > principal: CN=Siemens Issuing CA Intranet Server 2017, OU=Siemens > > Trust Center, SERIALNUMBER=ZZZZZZB7, O=Siemens, L=Muenchen, > > ST=Bayern, C=DE > > 433 [main] DEBUG > > org.apache.hc.client5.http.impl.io.DefaultHttpClientConnectionOpera > > tor - http-outgoing-0: connection established 192.168.1.12:54367<- > > ><ip>:11111 > > 433 [main] DEBUG > > org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManag > > er - ep-00000000: connected http-outgoing-0 > > 433 [main] DEBUG > > org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep- > > 00000000: endpoint connected > > 434 [main] DEBUG > > org.apache.hc.client5.http.impl.classic.MainClientExec - ex- > > 00000001: executing POST /content-dev/api/documents HTTP/1.1 > > 434 [main] DEBUG > > org.apache.hc.client5.http.impl.io.DefaultManagedHttpClientConnecti > > on - http-outgoing-0: set socket timeout to 100 MILLISECONDS > > 434 [main] DEBUG > > org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep- > > 00000000: start execution ex-00000001 > > 434 [main] DEBUG > > org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManag > > er - ep-00000000: executing exchange ex-00000001 over http- > > outgoing-0 > > 435 [main] DEBUG org.apache.hc.client5.http.headers - http- > > outgoing-0 >> POST /content-dev/api/documents HTTP/1.1 > > 435 [main] DEBUG org.apache.hc.client5.http.headers - http- > > outgoing-0 >> Accept-Encoding: gzip, x-gzip, deflate > > 435 [main] DEBUG org.apache.hc.client5.http.headers - http- > > outgoing-0 >> Content-Length: 7664149 > > 435 [main] DEBUG org.apache.hc.client5.http.headers - http- > > outgoing-0 >> Content-Type: application/zip > > 435 [main] DEBUG org.apache.hc.client5.http.headers - http- > > outgoing-0 >> Host: <hostname>:11111 > > 435 [main] DEBUG org.apache.hc.client5.http.headers - http- > > outgoing-0 >> Connection: keep-alive > > 435 [main] DEBUG org.apache.hc.client5.http.headers - http- > > outgoing-0 >> User-Agent: Apache-HttpClient/5.0 (Java/13.0.2) > > 578 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 > > >> "POST /content-dev/api/documents HTTP/1.1[\r][\n]" > > 578 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 > > >> "Accept-Encoding: gzip, x-gzip, deflate[\r][\n]" > > 578 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 > > >> "Content-Length: 7664149[\r][\n]" > > 578 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 > > >> "Content-Type: application/zip[\r][\n]" > > 578 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 > > >> "Host: <hostname>:11111[\r][\n]" > > 579 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 > > >> "Connection: keep-alive[\r][\n]" > > 579 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 > > >> "User-Agent: Apache-HttpClient/5.0 (Java/13.0.2)[\r][\n]" > > 579 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 > > >> "[\r][\n]" > > 580 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 > > >> > > "PK[0x3][0x4][0x14][0x0][0x0][0x0][0x0][0x0][0xffffffd3]~[0xffffffb > > 3]P... > > ... > > 5861 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 > > >> > > "[\r][0xffffffe0]t[0xffffffa1][0x1f][0xffffffb0][0xfffffffa][0xffff > > ffa1]... > > 5861 [main] DEBUG org.apache.hc.client5.http.wire - http-outgoing-0 > > >> "[write] I/O error: Connection or outbound has closed" > > 5862 [main] DEBUG > > org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep- > > 00000000: endpoint closed > > 5862 [main] DEBUG > > org.apache.hc.client5.http.impl.classic.InternalHttpClient - ep- > > 00000000: discarding endpoint > > 5862 [main] DEBUG > > org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManag > > er - ep-00000000: releasing endpoint > > 5862 [main] DEBUG > > org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManag > > er - ep-00000000: connection released [route: {s}-> > > https://<hostname>:11111][total available: 0; route allocated: 0 of > > 5; total allocated: 0 of 25] > > 5862 [main] DEBUG > > org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManag > > er - Shutdown connection pool GRACEFUL > > 5862 [main] DEBUG > > org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManag > > er - Connection pool shut down > > Exception in thread "main" javax.net.ssl.SSLException: Eine > > bestehende Verbindung wurde softwaregesteuert > > durch den Hostcomputer abgebrochen > > at > > java.base/sun.security.ssl.Alert.createSSLException(Alert.java:127) > > at > > java.base/sun.security.ssl.TransportContext.fatal(TransportContext. > > java:324) > > at > > java.base/sun.security.ssl.TransportContext.fatal(TransportContext. > > java:267) > > at > > java.base/sun.security.ssl.TransportContext.fatal(TransportContext. > > java:262) > > at > > java.base/sun.security.ssl.SSLSocketImpl$AppOutputStream.write(SSLS > > ocketImpl.java:1258) > > at > > org.apache.hc.client5.http.impl.io.LoggingOutputStream.write(Loggin > > gOutputStream.java:72) > > at > > org.apache.hc.core5.http.impl.io.SessionOutputBufferImpl.flushBuffe > > r(SessionOutputBufferImpl.java:117) > > at > > org.apache.hc.core5.http.impl.io.SessionOutputBufferImpl.write(Sess > > ionOutputBufferImpl.java:150) > > at > > org.apache.hc.core5.http.impl.io.ContentLengthOutputStream.write(Co > > ntentLengthOutputStream.java:113) > > at > > org.apache.hc.core5.http.io.entity.AbstractHttpEntity.writeTo(Abstr > > actHttpEntity.java:85) > > at > > org.apache.hc.core5.http.io.entity.AbstractHttpEntity.writeTo(Abstr > > actHttpEntity.java:93) > > at > > org.apache.hc.core5.http.impl.io.DefaultBHttpClientConnection.sendR > > equestEntity(DefaultBHttpClientConnection.java:153) > > at > > org.apache.hc.core5.http.impl.io.HttpRequestExecutor.execute(HttpRe > > questExecutor.java:148) > > at > > org.apache.hc.core5.http.impl.io.HttpRequestExecutor.execute(HttpRe > > questExecutor.java:225) > > at > > org.apache.hc.client5.http.impl.io.PoolingHttpClientConnectionManag > > er$InternalConnectionEndpoint.execute(PoolingHttpClientConnectionMa > > nager.java:596) > > at > > org.apache.hc.client5.http.impl.classic.InternalExecRuntime.execute > > (InternalExecRuntime.java:220) > > at > > org.apache.hc.client5.http.impl.classic.MainClientExec.execute(Main > > ClientExec.java:107) > > at > > org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(Ex > > ecChainElement.java:51) > > at > > org.apache.hc.client5.http.impl.classic.ExecChainElement$1.proceed( > > ExecChainElement.java:57) > > at > > org.apache.hc.client5.http.impl.classic.ConnectExec.execute(Connect > > Exec.java:181) > > at > > org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(Ex > > ecChainElement.java:51) > > at > > org.apache.hc.client5.http.impl.classic.ExecChainElement$1.proceed( > > ExecChainElement.java:57) > > at > > org.apache.hc.client5.http.impl.classic.ProtocolExec.execute(Protoc > > olExec.java:165) > > at > > org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(Ex > > ecChainElement.java:51) > > at > > org.apache.hc.client5.http.impl.classic.ExecChainElement$1.proceed( > > ExecChainElement.java:57) > > at > > org.apache.hc.client5.http.impl.classic.HttpRequestRetryExec.execut > > e(HttpRequestRetryExec.java:93) > > at > > org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(Ex > > ecChainElement.java:51) > > at > > org.apache.hc.client5.http.impl.classic.ExecChainElement$1.proceed( > > ExecChainElement.java:57) > > at > > org.apache.hc.client5.http.impl.classic.RedirectExec.execute(Redire > > ctExec.java:116) > > at > > org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(Ex > > ecChainElement.java:51) > > at > > org.apache.hc.client5.http.impl.classic.ExecChainElement$1.proceed( > > ExecChainElement.java:57) > > at > > org.apache.hc.client5.http.impl.classic.ContentCompressionExec.exec > > ute(ContentCompressionExec.java:128) > > at > > org.apache.hc.client5.http.impl.classic.ExecChainElement.execute(Ex > > ecChainElement.java:51) > > at > > org.apache.hc.client5.http.impl.classic.InternalHttpClient.doExecut > > e(InternalHttpClient.java:178) > > at > > org.apache.hc.client5.http.impl.classic.CloseableHttpClient.execute > > (CloseableHttpClient.java:75) > > at > > org.apache.hc.client5.http.impl.classic.CloseableHttpClient.execute > > (CloseableHttpClient.java:89) > > at sspijava.SspiAuth.main(SspiAuth.java:59) > > Suppressed: java.net.SocketException: Eine bestehende > > Verbindung wurde softwaregesteuert > > durch den Hostcomputer abgebrochen > > at > > java.base/sun.nio.ch.NioSocketImpl.implWrite(NioSocketImpl.java:421 > > ) > > at > > java.base/sun.nio.ch.NioSocketImpl.write(NioSocketImpl.java:441) > > at > > java.base/sun.nio.ch.NioSocketImpl$2.write(NioSocketImpl.java:825) > > at > > java.base/java.net.Socket$SocketOutputStream.write(Socket.java:1007 > > ) > > at > > java.base/sun.security.ssl.SSLSocketOutputRecord.encodeAlert(SSLSoc > > ketOutputRecord.java:82) > > at > > java.base/sun.security.ssl.TransportContext.fatal(TransportContext. > > java:355) > > ... 35 more > > Suppressed: java.net.SocketException: Connection or outbound > > has closed > > at > > java.base/sun.security.ssl.SSLSocketImpl$AppOutputStream.write(SSLS > > ocketImpl.java:1246) > > at > > org.apache.hc.client5.http.impl.io.LoggingOutputStream.write(Loggin > > gOutputStream.java:72) > > at > > org.apache.hc.core5.http.impl.io.SessionOutputBufferImpl.flushBuffe > > r(SessionOutputBufferImpl.java:117) > > at > > org.apache.hc.core5.http.impl.io.SessionOutputBufferImpl.flush(Sess > > ionOutputBufferImpl.java:126) > > at > > org.apache.hc.core5.http.impl.io.ContentLengthOutputStream.close(Co > > ntentLengthOutputStream.java:93) > > at > > org.apache.hc.core5.http.impl.io.DefaultBHttpClientConnection.sendR > > equestEntity(DefaultBHttpClientConnection.java:154) > > ... 25 more > > Caused by: java.net.SocketException: Eine bestehende Verbindung > > wurde softwaregesteuert > > durch den Hostcomputer abgebrochen > > at > > java.base/sun.nio.ch.NioSocketImpl.implWrite(NioSocketImpl.java:421 > > ) > > at > > java.base/sun.nio.ch.NioSocketImpl.write(NioSocketImpl.java:441) > > at > > java.base/sun.nio.ch.NioSocketImpl$2.write(NioSocketImpl.java:825) > > at > > java.base/java.net.Socket$SocketOutputStream.write(Socket.java:1007 > > ) > > at > > java.base/sun.security.ssl.SSLSocketOutputRecord.deliver(SSLSocketO > > utputRecord.java:342) > > at > > java.base/sun.security.ssl.SSLSocketImpl$AppOutputStream.write(SSLS > > ocketImpl.java:1253) > > ... 32 more > > So what happens here, HttpClient uploads the file while Tomcat > pretty > quick notices that the requests needs to be authenticated, responds > 401 > and closes the connection. > Is my understanding correct? What do I have to do to solve this? > curl seems to handle this properly, aborts the request and retries > with > proper credentials. > > The key difference I see in Tomcats logs is that headers are seen > first > first, authnz checks, then curl sends the body while HttpClient > sends > headers and the first block of the payload. I can provide the trace > output from Tomcat. > > Regards, > > Michael > > PS: Yes, I know I can use Expect, but I am trying to reproduce this > for > a failure with mod_proxy_http and py-requests. > Hi Micheal I think your analysis is quite accurate. HttpClient indeed tries to pack the request body into the same IP frame as the header for performance reasons. It also does not stop and check for any out of sequence response from the server due to high cost of such operation. The only way to properly solve the problem is to enable `expect- continue` handshake or use an async version of HttpClient. Theoretically we could enhance the classic client-side protocol handler to check if the length of the request entity is known and is greater, say, than 1MB, send the request head first, stop and wait for an early response, but this could potentially kill performance of entity enclosing requests processed in proper request-response sequence. This approach has been considered on several occasions but always decided against. Oleg --------------------------------------------------------------------- To unsubscribe, e-mail: httpclient-users-unsubscr...@hc.apache.org For additional commands, e-mail: httpclient-users-h...@hc.apache.org
