Uploaded image for project: 'HttpComponents HttpClient'
  1. HttpComponents HttpClient
  2. HTTPCLIENT-1478

https calls ignore http.socket.timeout during SSL Handshake

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: 4.3 Final, 4.3.1, 4.3.2, 4.3.3
    • Fix Version/s: 4.3.4
    • Component/s: HttpClient (classic)
    • Labels:
      None
    • Environment:
      All

      Description

      https calls ignore http.socket.timeout during SSL Handshake. This can result in a https call hanging forever waiting for socket read.

      In both SSLSocketFactory and SSLConnectionSocketFactory, sslsock.startHandshake(); is called before socket timeout is set on the socket. This means timeout is not respected during the SSL handshake, and the thread can hang with a stacktrace that looks like this:

      org.apache.http.impl.client.AbstractHttpClient.doExecute
      org.apache.http.impl.client.DefaultRequestDirector.execute
      org.apache.http.impl.client.DefaultRequestDirector.tryConnect
      org.apache.http.impl.conn.ManagedClientConnectionImpl.open
      org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection
      org.apache.http.conn.ssl.SSLSocketFactory.connectSocket
      org.apache.http.conn.ssl.SSLSocketFactory.connectSocket
      sun.security.ssl.SSLSocketImpl.startHandshake
      sun.security.ssl.SSLSocketImpl.startHandshake
      sun.security.ssl.SSLSocketImpl.performInitialHandshake
      sun.security.ssl.SSLSocketImpl.readRecord
      sun.security.ssl.InputRecord.read
      sun.security.ssl.InputRecord.readV3Record
      sun.security.ssl.InputRecord.readFully
      java.net.SocketInputStream.read
      java.net.SocketInputStream.socketRead0

        Activity

        Hide
        olegk Oleg Kalnichevski added a comment -

        Jonah,

        Please note that HttpClientConnectionOperator sets timeout on the socket prior to calling #connectSocket method [1]. I do not quite see how sockets can get stuck indefinitely during SSL handshake if the socket timeout is correctly set up at the connection manager level.

        Am I missing something?

        Please also note that your code apparently is using code deprecated in 4.3.

        Oleg

        [1] http://hc.apache.org/httpcomponents-client-4.3.x/httpclient/xref/org/apache/http/impl/conn/HttpClientConnectionOperator.html#115

        Show
        olegk Oleg Kalnichevski added a comment - Jonah, Please note that HttpClientConnectionOperator sets timeout on the socket prior to calling #connectSocket method [1] . I do not quite see how sockets can get stuck indefinitely during SSL handshake if the socket timeout is correctly set up at the connection manager level. Am I missing something? Please also note that your code apparently is using code deprecated in 4.3. Oleg [1] http://hc.apache.org/httpcomponents-client-4.3.x/httpclient/xref/org/apache/http/impl/conn/HttpClientConnectionOperator.html#115
        Hide
        schwartzdev Jonah Schwartz added a comment -

        Oleg,

        As you say, HttpClientConnectionOperator sets the timeout on the socket.

        I am using DefaultHttpClient which calls DefaultClientConnectionOperator.openConnection which does not set the timeout on the socket before calling connectSocket. I understand that DefaultHttpClient is deprecated, but I have third-party code that relies on it. 4.2.x did not have this bug.

        -Jonah

        Show
        schwartzdev Jonah Schwartz added a comment - Oleg, As you say, HttpClientConnectionOperator sets the timeout on the socket. I am using DefaultHttpClient which calls DefaultClientConnectionOperator.openConnection which does not set the timeout on the socket before calling connectSocket. I understand that DefaultHttpClient is deprecated, but I have third-party code that relies on it. 4.2.x did not have this bug. -Jonah
        Hide
        olegk Oleg Kalnichevski added a comment -

        Fixed in SVN trunk and 4.3.x branch.

        Please review / test.

        Oleg

        Show
        olegk Oleg Kalnichevski added a comment - Fixed in SVN trunk and 4.3.x branch. Please review / test. Oleg
        Hide
        robin Robin Sander added a comment -

        Is this really fixed in the 4.3.4? The release notes don't mention this bug as fixed and by looking into the sources I got confused because there are two source roots src/main/java and java-deprecated and only the latter seems to have these changes.

        Show
        robin Robin Sander added a comment - Is this really fixed in the 4.3.4? The release notes don't mention this bug as fixed and by looking into the sources I got confused because there are two source roots src/main/java and java-deprecated and only the latter seems to have these changes.
        Hide
        olegk Oleg Kalnichevski added a comment -

        The bug did not affect non-deprecated code in the first place.

        Oleg

        Show
        olegk Oleg Kalnichevski added a comment - The bug did not affect non-deprecated code in the first place. Oleg
        Hide
        robin Robin Sander added a comment -

        Ok, now I understand, thanks Oleg!

        Show
        robin Robin Sander added a comment - Ok, now I understand, thanks Oleg!
        Hide
        jgracin Josip Gracin added a comment -

        I think I'm also having this problem, and using 4.3.4 does not help, it hangs forever. I'm using something like this to instantiate Spring's RestTemplate:
        <bean id="restTemplate" class="org.springframework.web.client.RestTemplate">
        <constructor-arg>
        <bean class="org.springframework.http.client.HttpComponentsClientHttpRequestFactory">
        <property name="connectTimeout" value="10000" />
        <property name="readTimeout" value="10000" />
        </bean>
        </constructor-arg>
        </bean>

        I start 'nc -l localhost:12000' to mock a non-responding server, and here's the log:

        12:06:57.455 [scheduler-1] DEBUG o.a.h.c.protocol.RequestAddCookies - CookieSpec selected: best-match
        12:06:57.480 [scheduler-1] DEBUG o.a.h.c.protocol.RequestAuthCache - Auth cache not set in the context
        12:06:57.484 [scheduler-1] DEBUG o.a.h.i.c.PoolingHttpClientConnectionManager - Connection request: [route:

        {s}->https://localhost:12000][total kept alive: 0; route allocated: 0 of 5; total allocated: 0 of 10]
        12:06:57.527 [scheduler-1] DEBUG o.a.h.i.c.PoolingHttpClientConnectionManager - Connection leased: [id: 0][route: {s}

        ->https://localhost:12000][total kept alive: 0; route allocated: 1 of 5; total allocated: 1 of 10]
        12:06:57.531 [scheduler-1] DEBUG o.a.h.impl.execchain.MainClientExec - Opening connection

        {s}

        ->https://localhost:12000
        12:06:57.536 [scheduler-1] DEBUG o.a.h.i.c.HttpClientConnectionOperator - Connecting to localhost/127.0.0.1:12000

        Show
        jgracin Josip Gracin added a comment - I think I'm also having this problem, and using 4.3.4 does not help, it hangs forever. I'm using something like this to instantiate Spring's RestTemplate: <bean id="restTemplate" class="org.springframework.web.client.RestTemplate"> <constructor-arg> <bean class="org.springframework.http.client.HttpComponentsClientHttpRequestFactory"> <property name="connectTimeout" value="10000" /> <property name="readTimeout" value="10000" /> </bean> </constructor-arg> </bean> I start 'nc -l localhost:12000' to mock a non-responding server, and here's the log: 12:06:57.455 [scheduler-1] DEBUG o.a.h.c.protocol.RequestAddCookies - CookieSpec selected: best-match 12:06:57.480 [scheduler-1] DEBUG o.a.h.c.protocol.RequestAuthCache - Auth cache not set in the context 12:06:57.484 [scheduler-1] DEBUG o.a.h.i.c.PoolingHttpClientConnectionManager - Connection request: [route: {s}-> https://localhost:12000][total kept alive: 0; route allocated: 0 of 5; total allocated: 0 of 10] 12:06:57.527 [scheduler-1] DEBUG o.a.h.i.c.PoolingHttpClientConnectionManager - Connection leased: [id: 0] [route: {s} -> https://localhost:12000][total kept alive: 0; route allocated: 1 of 5; total allocated: 1 of 10] 12:06:57.531 [scheduler-1] DEBUG o.a.h.impl.execchain.MainClientExec - Opening connection {s} -> https://localhost:12000 12:06:57.536 [scheduler-1] DEBUG o.a.h.i.c.HttpClientConnectionOperator - Connecting to localhost/127.0.0.1:12000
        Hide
        tth Thijs ten Hoeve added a comment - - edited

        I too think this bug hasn't been completely fixed.
        I have the following trace of an application that blocked indefinitely on a get request.

           java.lang.Thread.State: RUNNABLE
                at java.net.SocketInputStream.socketRead0(Native Method)
                at java.net.SocketInputStream.read(SocketInputStream.java:150)
                at java.net.SocketInputStream.read(SocketInputStream.java:121)
                at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
                at sun.security.ssl.InputRecord.read(InputRecord.java:503)
                at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:954)
                - locked <0x00000000e0a6a860> (a java.lang.Object)
                at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1343)
                - locked <0x00000000e0a6a870> (a java.lang.Object)
                at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1371)
                at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1355)
                at org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:275)
                at org.apache.http.impl.conn.HttpClientConnectionOperator.upgrade(HttpClientConnectionOperator.java:169)
                at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.upgrade(PoolingHttpClientConnectionManager.java:333)
                at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:398)
                at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:219)
                at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195)
                at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86)
                at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108)
                at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
                at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
                at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106)
        

        Unfortunately this scenario is very difficult te reproduce.
        However I have been able to get similar traces (that didn't block forever since the server was responsive) in a debugger, and I think I have identified a possible cause for this.

        A connection timeout is not necessarily set on the socket used in the handshake.
        This socket is created here: http://hc.apache.org/httpcomponents-client-4.3.x/httpclient/xref/org/apache/http/conn/ssl/SSLConnectionSocketFactory.html#234
        The connection is then opened (With a connectionTimeout) on http://hc.apache.org/httpcomponents-client-4.3.x/httpclient/xref/org/apache/http/conn/ssl/SSLConnectionSocketFactory.html#239.
        However there is no SoTimeout set on the socket (getSoTimeout() returns 0), so the startHandshake() call in createLayeredSocket (http://hc.apache.org/httpcomponents-client-4.3.x/httpclient/xref/org/apache/http/conn/ssl/SSLConnectionSocketFactory.html#275) might block forever.

        Note that the Request passed to the execute() call in CloseableHttpClient did have a SocketTimeout set. ((request.getConfig().getSocketTimeout() == 60000)

        Show
        tth Thijs ten Hoeve added a comment - - edited I too think this bug hasn't been completely fixed. I have the following trace of an application that blocked indefinitely on a get request. java.lang. Thread .State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:150) at java.net.SocketInputStream.read(SocketInputStream.java:121) at sun.security.ssl.InputRecord.readFully(InputRecord.java:465) at sun.security.ssl.InputRecord.read(InputRecord.java:503) at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:954) - locked <0x00000000e0a6a860> (a java.lang. Object ) at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1343) - locked <0x00000000e0a6a870> (a java.lang. Object ) at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1371) at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1355) at org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:275) at org.apache.http.impl.conn.HttpClientConnectionOperator.upgrade(HttpClientConnectionOperator.java:169) at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.upgrade(PoolingHttpClientConnectionManager.java:333) at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:398) at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:219) at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195) at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86) at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108) at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106) Unfortunately this scenario is very difficult te reproduce. However I have been able to get similar traces (that didn't block forever since the server was responsive) in a debugger, and I think I have identified a possible cause for this. A connection timeout is not necessarily set on the socket used in the handshake. This socket is created here: http://hc.apache.org/httpcomponents-client-4.3.x/httpclient/xref/org/apache/http/conn/ssl/SSLConnectionSocketFactory.html#234 The connection is then opened (With a connectionTimeout) on http://hc.apache.org/httpcomponents-client-4.3.x/httpclient/xref/org/apache/http/conn/ssl/SSLConnectionSocketFactory.html#239 . However there is no SoTimeout set on the socket (getSoTimeout() returns 0), so the startHandshake() call in createLayeredSocket ( http://hc.apache.org/httpcomponents-client-4.3.x/httpclient/xref/org/apache/http/conn/ssl/SSLConnectionSocketFactory.html#275 ) might block forever. Note that the Request passed to the execute() call in CloseableHttpClient did have a SocketTimeout set. ((request.getConfig().getSocketTimeout() == 60000)
        Show
        olegk Oleg Kalnichevski added a comment - http://hc.apache.org/httpcomponents-client-4.3.x/httpclient/xref/org/apache/http/impl/conn/HttpClientConnectionOperator.html#108 Oleg
        Hide
        tth Thijs ten Hoeve added a comment -

        Oleg: Thanks for your quick reply. Unfortunately I do still think there is a bug there.
        If I set a breakpoint on the line that you mentioned, and evaluate socketConfig.getSoTimeout() there then I get 0. So a timeout is never set on the created socket.
        The socketConfig == SocketConfig.DEFAULT and is set in the calling function on line 316 http://hc.apache.org/httpcomponents-client-4.3.x/httpclient/xref/org/apache/http/impl/conn/PoolingHttpClientConnectionManager.html#316

        We use a custom RoutePlanner because we are working with a number of proxies, but I don't think that is the cause of this problem (Of course I'd gladly hear it if it were), and besides that we do not really do any odd things in this use case.
        As a work around we are going to use an SSLConnectionSocketFactory that sets a timeout in the prepareSocket function, but of course we'd rather forgo that extra bit of code.

        Show
        tth Thijs ten Hoeve added a comment - Oleg: Thanks for your quick reply. Unfortunately I do still think there is a bug there. If I set a breakpoint on the line that you mentioned, and evaluate socketConfig.getSoTimeout() there then I get 0. So a timeout is never set on the created socket. The socketConfig == SocketConfig.DEFAULT and is set in the calling function on line 316 http://hc.apache.org/httpcomponents-client-4.3.x/httpclient/xref/org/apache/http/impl/conn/PoolingHttpClientConnectionManager.html#316 We use a custom RoutePlanner because we are working with a number of proxies, but I don't think that is the cause of this problem (Of course I'd gladly hear it if it were), and besides that we do not really do any odd things in this use case. As a work around we are going to use an SSLConnectionSocketFactory that sets a timeout in the prepareSocket function, but of course we'd rather forgo that extra bit of code.
        Hide
        olegk Oleg Kalnichevski added a comment -

        So a timeout is never set on the created socket. The socketConfig == SocketConfig.DEFAULT

        So, what does this tell you? How about using a custom SocketConfig?

        Oleg

        Show
        olegk Oleg Kalnichevski added a comment - So a timeout is never set on the created socket. The socketConfig == SocketConfig.DEFAULT So, what does this tell you? How about using a custom SocketConfig? Oleg
        Hide
        sirpy hadar added a comment -

        I don't think this ticket should be closed. it still happens in 4.3.4.
        like stated in the above comments when calling what seems to be a depracted method
        org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket set socket timeout is never called on the created socket

        Show
        sirpy hadar added a comment - I don't think this ticket should be closed. it still happens in 4.3.4. like stated in the above comments when calling what seems to be a depracted method org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket set socket timeout is never called on the created socket
        Hide
        padakwaak Chris Kistner added a comment -

        I also reckon this ticket shouldn't be closed just yet!

        I'm still having SSL Handshake not being timed out with httpClient 4.3.5, even if I set the timeout with like:

        SocketConfig sc = SocketConfig.custom()
        		.setSoTimeout(Settings.getHttpTimeoutConnect())
        		.build();

        I went and did a crude patch on httpClient 4.3.5 of setting a default 60s timeout if the SSL socket timeout was not set:

        ---
         src/main/java/org/apache/http/conn/ssl/SSLConnectionSocketFactory.java | 3 +++
         1 file changed, 3 insertions(+)
        
        diff --git a/src/main/java/org/apache/http/conn/ssl/SSLConnectionSocketFactory.java b/src/main/java/org/apache/http/conn/ssl/SSLConnectionSocketFactory.java
        index c175fd2..9e7d7b9 100644
        --- a/src/main/java/org/apache/http/conn/ssl/SSLConnectionSocketFactory.java
        +++ b/src/main/java/org/apache/http/conn/ssl/SSLConnectionSocketFactory.java
        @@ -265,6 +265,9 @@ public class SSLConnectionSocketFactory implements LayeredConnectionSocketFactor
                         target,
                         port,
                         true);
        +         if (sslsock.getSoTimeout() == 0) {
        +             sslsock.setSoTimeout(60000);
        +         }
                 if (supportedProtocols != null) {
                     sslsock.setEnabledProtocols(supportedProtocols);
                 }
        -- 
        Show
        padakwaak Chris Kistner added a comment - I also reckon this ticket shouldn't be closed just yet! I'm still having SSL Handshake not being timed out with httpClient 4.3.5, even if I set the timeout with like: SocketConfig sc = SocketConfig.custom() .setSoTimeout(Settings.getHttpTimeoutConnect()) .build(); I went and did a crude patch on httpClient 4.3.5 of setting a default 60s timeout if the SSL socket timeout was not set: --- src/main/java/org/apache/http/conn/ssl/SSLConnectionSocketFactory.java | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/main/java/org/apache/http/conn/ssl/SSLConnectionSocketFactory.java b/src/main/java/org/apache/http/conn/ssl/SSLConnectionSocketFactory.java index c175fd2..9e7d7b9 100644 --- a/src/main/java/org/apache/http/conn/ssl/SSLConnectionSocketFactory.java +++ b/src/main/java/org/apache/http/conn/ssl/SSLConnectionSocketFactory.java @@ -265,6 +265,9 @@ public class SSLConnectionSocketFactory implements LayeredConnectionSocketFactor target, port, true); + if (sslsock.getSoTimeout() == 0) { + sslsock.setSoTimeout(60000); + } if (supportedProtocols != null) { sslsock.setEnabledProtocols(supportedProtocols); } --
        Hide
        dominik.stadler@gmx.at Dominik Stadler added a comment -

        Same here for me, not fixed in latest version when using SSL. Non-SSL works fine.

        SocketTimeout is 0 when I debug the code in the SSLConnectionSocketFactory. I am using the RequestConfig.custom().setSocketTimeout(timeoutMs)... and no DefaultHttpClient() or anything so I believe I use the latest way to configure the HttpClient, or?

        My current workaround is a custom SSLConnectionSocketFactory which sets the timeout on the socket in prepareSocket(), this seems to help.

        Show
        dominik.stadler@gmx.at Dominik Stadler added a comment - Same here for me, not fixed in latest version when using SSL. Non-SSL works fine. SocketTimeout is 0 when I debug the code in the SSLConnectionSocketFactory. I am using the RequestConfig.custom().setSocketTimeout(timeoutMs)... and no DefaultHttpClient() or anything so I believe I use the latest way to configure the HttpClient, or? My current workaround is a custom SSLConnectionSocketFactory which sets the timeout on the socket in prepareSocket(), this seems to help.
        Hide
        ruralhunter Rural Hunter added a comment -

        Seems it's actually fixed in 4.3.6

        Show
        ruralhunter Rural Hunter added a comment - Seems it's actually fixed in 4.3.6
        Show
        dominik.stadler@gmx.at Dominik Stadler added a comment - seems to be this commit: http://svn.apache.org/viewvc/httpcomponents/httpclient/branches/4.3.x/httpclient/src/main/java/org/apache/http/conn/ssl/SSLConnectionSocketFactory.java?r1=1560975&r2=1626784
        Hide
        padakwaak Chris Kistner added a comment -

        Fantastic! My test code confirms that 4.3.6 does indeed fix this SSL handshake timeout issue.

        Show
        padakwaak Chris Kistner added a comment - Fantastic! My test code confirms that 4.3.6 does indeed fix this SSL handshake timeout issue.
        Hide
        ondrej.burkert Ondrej Burkert added a comment -

        Yup, same here, test works without the workaround with the newer version. Excellent!

        Show
        ondrej.burkert Ondrej Burkert added a comment - Yup, same here, test works without the workaround with the newer version. Excellent!
        Hide
        hijon89 Jonathan Haber added a comment -

        I believe we ran into this yesterday using httpclient 4.3.6 and httpcore 4.3.3. We had multiple services hang indefinitely during an SSL handshake (process had to be restarted), the stack trace on all of them looked like:

           java.lang.Thread.State: RUNNABLE
        	at java.net.SocketInputStream.socketRead0(Native Method)
        	at java.net.SocketInputStream.read(SocketInputStream.java:152)
        	at java.net.SocketInputStream.read(SocketInputStream.java:122)
        	at sun.security.ssl.InputRecord.readFully(InputRecord.java:442)
        	at sun.security.ssl.InputRecord.read(InputRecord.java:480)
        	at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:927)
        	- locked <0x000000074dc8e430> (a java.lang.Object)
        	at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1312)
        	- locked <0x000000074dc8e4e0> (a java.lang.Object)
        	at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1339)
        	at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1323)
        	at org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:290)
        	at org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:259)
        	at org.apache.http.impl.conn.HttpClientConnectionOperator.connect(HttpClientConnectionOperator.java:125)
        	at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:319)
        	at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:363)
        	at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:219)
        	at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195)
        	at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86)
        	at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108)
        	at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
        	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
        	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106)
        
        Show
        hijon89 Jonathan Haber added a comment - I believe we ran into this yesterday using httpclient 4.3.6 and httpcore 4.3.3. We had multiple services hang indefinitely during an SSL handshake (process had to be restarted), the stack trace on all of them looked like: java.lang. Thread .State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at sun.security.ssl.InputRecord.readFully(InputRecord.java:442) at sun.security.ssl.InputRecord.read(InputRecord.java:480) at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:927) - locked <0x000000074dc8e430> (a java.lang. Object ) at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1312) - locked <0x000000074dc8e4e0> (a java.lang. Object ) at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1339) at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1323) at org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:290) at org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:259) at org.apache.http.impl.conn.HttpClientConnectionOperator.connect(HttpClientConnectionOperator.java:125) at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:319) at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:363) at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:219) at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195) at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86) at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108) at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106)
        Hide
        padakwaak Chris Kistner added a comment -

        Ensure that you've specified a timeout value, otherwise it would still get stuck in 4.3.6:

        SocketConfig sc = SocketConfig.custom()
        		.setSoTimeout(Settings.getHttpTimeoutConnect())
        		.build();
        Show
        padakwaak Chris Kistner added a comment - Ensure that you've specified a timeout value, otherwise it would still get stuck in 4.3.6: SocketConfig sc = SocketConfig.custom() .setSoTimeout(Settings.getHttpTimeoutConnect()) .build();
        Hide
        hijon89 Jonathan Haber added a comment -

        I thought this commit made that unnecessary, is that not the case?

        Show
        hijon89 Jonathan Haber added a comment - I thought this commit made that unnecessary, is that not the case?
        Hide
        hijon89 Jonathan Haber added a comment -

        In my testing it looks like you're right and the timeout isn't making it to the SSLSocket. We're already setting the socket timeout and connection request timeout on the RequestConfig, I'll add a default socket config as well I guess

        Show
        hijon89 Jonathan Haber added a comment - In my testing it looks like you're right and the timeout isn't making it to the SSLSocket. We're already setting the socket timeout and connection request timeout on the RequestConfig, I'll add a default socket config as well I guess
        Hide
        ogolovanov Oleg Golovanov added a comment - - edited

        httpclient 4.3.6 + httpcore 4.3.3.

        I am using a lot of threads that do https requests through proxy.
        And some of those threads ( 5-20 from 300 ) hang on:

        http-outgoing-76778 >> "CONNECT host.ru:443 HTTP/1.1[\r][\n]"
        http-outgoing-76778 >> "Host: host.ru[\r][\n]"
        Http-outgoing-76778 >> "Proxy-Connection: Keep-Alive[\r][\n]"
        http-outgoing-76778 >> "[\r][\n]"

        Timeout is set with RequestConfig.setConnectTimeout and RequestConfig.setTimeout.


        Update: setting custom socket config on connection manager solved the problem.
        Why requestConfig.setTimeout does not affect "CONNECT" requests ?

        Show
        ogolovanov Oleg Golovanov added a comment - - edited httpclient 4.3.6 + httpcore 4.3.3. I am using a lot of threads that do https requests through proxy. And some of those threads ( 5-20 from 300 ) hang on: http-outgoing-76778 >> "CONNECT host.ru:443 HTTP/1.1 [\r] [\n] " http-outgoing-76778 >> "Host: host.ru [\r] [\n] " Http-outgoing-76778 >> "Proxy-Connection: Keep-Alive [\r] [\n] " http-outgoing-76778 >> " [\r] [\n] " Timeout is set with RequestConfig.setConnectTimeout and RequestConfig.setTimeout. Update: setting custom socket config on connection manager solved the problem. Why requestConfig.setTimeout does not affect "CONNECT" requests ?
        Hide
        olegk Oleg Kalnichevski added a comment -

        Because connection tunneling is still a part of connection initialization and not of request execution.

        Oleg

        Show
        olegk Oleg Kalnichevski added a comment - Because connection tunneling is still a part of connection initialization and not of request execution. Oleg
        Hide
        gpetit Gaspard Petit added a comment - - edited

        I had this issue with version 4.4.1. At first I ignored this thread because it was flagged as resolved in 4.3.

        I followed Oleg's advice and the details about how to use a custom socket configuration from this page: https://wiki.apache.org/HttpComponents/HttpClientConfiguration

        It was fairly simple to do.

        I do believe that using no timeout by default, both for the ssl socket and the request socket and connection is an inconvenient decision. It renders the HTTPClients.createDefault() useless and dangerous. At worse, a default timeout of 5 minutes would be better than none.

        That being said, thank you for giving hints on how to resolve the issue.

        Show
        gpetit Gaspard Petit added a comment - - edited I had this issue with version 4.4.1. At first I ignored this thread because it was flagged as resolved in 4.3. I followed Oleg's advice and the details about how to use a custom socket configuration from this page: https://wiki.apache.org/HttpComponents/HttpClientConfiguration It was fairly simple to do. I do believe that using no timeout by default, both for the ssl socket and the request socket and connection is an inconvenient decision. It renders the HTTPClients.createDefault() useless and dangerous. At worse, a default timeout of 5 minutes would be better than none. That being said, thank you for giving hints on how to resolve the issue.
        Hide
        olegk Oleg Kalnichevski added a comment -

        Could you please raise a separate issue or better yet discuss the matter on the dev@hc.apache.org?

        Oleg

        Show
        olegk Oleg Kalnichevski added a comment - Could you please raise a separate issue or better yet discuss the matter on the dev@hc.apache.org? Oleg
        Hide
        augustl August Lilleaas added a comment -

        I encountered this issue on verson 4.3.4. I upgraded to 4.5.1 and the issue was fixed there.

        I was able to reproduce this using a small Node.js TCP server that does nothing after the connection is opened, but closes the connection after 5 seconds. Here is the node server:

        var net = require("net");
        
        var server = net.createServer({}, function (conn) {
            console.log("a connection");
            setTimeout(function () { conn.end(); }, 5000);
        });
        
        server.listen(6171);
        

        Here is the code (Groovy) to reproduce the issue:

        url = "https://localhost:6171"
        
        res = org.apache.http.client.fluent.Request.Get(url)
                    .connectTimeout(1000)
                    .socketTimeout(1000)
                    .execute()
                    .returnResponse()
        
        org.apache.http.util.EntityUtils.toString(res.getEntity())
        

        In version 4.3.4, http:// worked fine and timed out after 1 second. With https, the request hangs beyond 1 seconds and hangs until the Node.js server closes the TCP connection.

        In version 4.5.1, the http behaviour was identical, and on https I got the following exception:

        org.apache.http.conn.ConnectTimeoutException: Connect to localhost:6171 [localhost/127.0.0.1] failed: Read timed out
            at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:143)
            at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:353)
            at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:380)
            at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)
            at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184)
            at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88)
            at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
            at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
            at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
            at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
            at org.apache.http.client.fluent.Request.internalExecute(Request.java:173)
            at org.apache.http.client.fluent.Request.execute(Request.java:177)
            at Script1.run(Script1.groovy:3)
        
        Show
        augustl August Lilleaas added a comment - I encountered this issue on verson 4.3.4. I upgraded to 4.5.1 and the issue was fixed there. I was able to reproduce this using a small Node.js TCP server that does nothing after the connection is opened, but closes the connection after 5 seconds. Here is the node server: var net = require("net"); var server = net.createServer({}, function (conn) { console.log("a connection"); setTimeout(function () { conn.end(); }, 5000); }); server.listen(6171); Here is the code (Groovy) to reproduce the issue: url = "https://localhost:6171" res = org.apache.http.client.fluent.Request.Get(url) .connectTimeout(1000) .socketTimeout(1000) .execute() .returnResponse() org.apache.http.util.EntityUtils.toString(res.getEntity()) In version 4.3.4, http:// worked fine and timed out after 1 second. With https, the request hangs beyond 1 seconds and hangs until the Node.js server closes the TCP connection. In version 4.5.1, the http behaviour was identical, and on https I got the following exception: org.apache.http.conn.ConnectTimeoutException: Connect to localhost:6171 [localhost/127.0.0.1] failed: Read timed out at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:143) at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:353) at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:380) at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236) at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184) at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88) at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110) at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55) at org.apache.http.client.fluent.Request.internalExecute(Request.java:173) at org.apache.http.client.fluent.Request.execute(Request.java:177) at Script1.run(Script1.groovy:3)
        Hide
        ricolcs LI Changshu added a comment - - edited

        I encountered this issue on verson 4.5.2, and using a proxy to access a https host. The soTimeout is set as the following:

                RequestConfig.Builder requestConfigBuilder = RequestConfig.custom()
                        .setConnectionRequestTimeout(30000)
                        .setConnectTimeout(30000)
                        .setSocketTimeout(30000);
        

        It turns out that sock.getSoTimeout() is 0 while ssl handshaking (Set breakpoint at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.upgrade(DefaultHttpClientConnectionOperator.java:192).

        The problem is fixed as the following:

                PoolingHttpClientConnectionManager cm = new PoolingHttpClientConnectionManager();
                // Set soTimeout here to affect socketRead in the phase of ssl handshake. Note that
                // the RequestConfig.setSocketTimeout will take effect only after the ssl handshake completed.
                cm.setDefaultSocketConfig(SocketConfig.custom().setSoTimeout(30000).build());
        
        Show
        ricolcs LI Changshu added a comment - - edited I encountered this issue on verson 4.5.2, and using a proxy to access a https host. The soTimeout is set as the following: RequestConfig.Builder requestConfigBuilder = RequestConfig.custom() .setConnectionRequestTimeout(30000) .setConnectTimeout(30000) .setSocketTimeout(30000); It turns out that sock.getSoTimeout() is 0 while ssl handshaking (Set breakpoint at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.upgrade(DefaultHttpClientConnectionOperator.java:192). The problem is fixed as the following: PoolingHttpClientConnectionManager cm = new PoolingHttpClientConnectionManager(); // Set soTimeout here to affect socketRead in the phase of ssl handshake. Note that // the RequestConfig.setSocketTimeout will take effect only after the ssl handshake completed. cm.setDefaultSocketConfig(SocketConfig.custom().setSoTimeout(30000).build());

          People

          • Assignee:
            Unassigned
            Reporter:
            schwartzdev Jonah Schwartz
          • Votes:
            1 Vote for this issue
            Watchers:
            18 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development