Details
Description
Problem
Sockets which perform CONNECT tunneling have an infinite timeout. These sockets could be used whenever Nexus makes a secure TLS connection through a proxy server - for example certificate retriever, automatic routing, repository status checker, etc.
https://en.wikipedia.org/wiki/HTTP_tunnel#HTTP_tunneling_without_using_CONNECT
Symptoms
Thread dumps contain unexplained RUNNABLE threads stuck on socketRead which never go away.
proxy-3-thread-1 id=83 state=RUNNABLE (running in native)
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:136)
at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:152)
at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:270)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:260)
at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:161)
at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:153)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:271)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:123)
at org.apache.http.impl.execchain.MainClientExec.createTunnelToTarget(MainClientExec.java:455)
at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:380)
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:57)
at org.sonatype.nexus.proxy.storage.remote.httpclient.HttpClientRemoteStorage.doExecuteRequest(HttpClientRemoteStorage.java:569)
at org.sonatype.nexus.proxy.storage.remote.httpclient.HttpClientRemoteStorage.executeRequest(HttpClientRemoteStorage.java:521)
at org.sonatype.nexus.proxy.storage.remote.httpclient.HttpClientRemoteStorage.executeRequestAndRelease(HttpClientRemoteStorage.java:634)
at org.sonatype.nexus.proxy.storage.remote.httpclient.HttpClientRemoteStorage.checkRemoteAvailability(HttpClientRemoteStorage.java:371)
at org.sonatype.nexus.proxy.storage.remote.AbstractHTTPRemoteRepositoryStorage.isReachable(AbstractHTTPRemoteRepositoryStorage.java:50)
at org.sonatype.nexus.proxy.repository.AbstractProxyRepository.isRemoteStorageReachable(AbstractProxyRepository.java:1679)
at org.sonatype.nexus.proxy.repository.AbstractProxyRepository$RemoteStatusUpdateCallable.call(AbstractProxyRepository.java:1653)
at org.sonatype.nexus.threads.MDCAwareCallable.call(MDCAwareCallable.java:44)
at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Locked synchronizers: count = 1
- java.util.concurrent.ThreadPoolExecutor$Worker@38b38b36
Alternative stack which one may see ( stepping through a debugger can prove the socket being used in this stack also has infinite timeout ). Note the call to 'upgrade' the connection:
proxy-3-thread-273 id=14969 state=RUNNABLE (running in native)
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
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:973)
at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1375)
- locked java.lang.Object@191ccd2e
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1403)
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1387)
at org.sonatype.nexus.apachehttpclient.NexusSSLConnectionSocketFactory.createLayeredSocket(NexusSSLConnectionSocketFactory.java:150)
at org.apache.http.impl.conn.HttpClientConnectionOperator.upgrade(HttpClientConnectionOperator.java:175)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.upgrade(PoolingHttpClientConnectionManager.java:334)
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:57)
at org.sonatype.nexus.proxy.storage.remote.httpclient.HttpClientRemoteStorage.doExecuteRequest(HttpClientRemoteStorage.java:569)
at org.sonatype.nexus.proxy.storage.remote.httpclient.HttpClientRemoteStorage.executeRequest(HttpClientRemoteStorage.java:521)
at org.sonatype.nexus.proxy.storage.remote.httpclient.HttpClientRemoteStorage.executeRequestAndRelease(HttpClientRemoteStorage.java:634)
at org.sonatype.nexus.proxy.storage.remote.httpclient.HttpClientRemoteStorage.checkRemoteAvailability(HttpClientRemoteStorage.java:396)
at org.sonatype.nexus.proxy.storage.remote.AbstractHTTPRemoteRepositoryStorage.isReachable(AbstractHTTPRemoteRepositoryStorage.java:50)
at org.sonatype.nexus.proxy.repository.AbstractProxyRepository.isRemoteStorageReachable(AbstractProxyRepository.java:1679)
at org.sonatype.nexus.proxy.repository.AbstractProxyRepository$RemoteStatusUpdateCallable.call(AbstractProxyRepository.java:1653)
at org.sonatype.nexus.threads.MDCAwareCallable.call(MDCAwareCallable.java:44)
at org.apache.shiro.subject.support.SubjectCallable.doCall(SubjectCallable.java:90)
at org.apache.shiro.subject.support.SubjectCallable.call(SubjectCallable.java:83)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Locked synchronizers: count = 1
- java.util.concurrent.ThreadPoolExecutor$Worker@61e7f15c
Reproduce
- an auto-blocking enabled proxy repository with https remote url
- an HTTP proxy server in Nexus which handles CONNECT tunnel upgrade of the proxy server connection to the secure TLS remote url ( proxy servers must support this if they are to be used with Nexus )
- the HTTP Proxy server hangs on the CONNECT/initial handshake
Simple reproduce is configure Charles Proxy throttling to have Download and Upload speeds of zero ( 0 ). Another alternative is have something listening on the proxy server port which never responds to CONNECT. For example use bane.
bane -a 8888 NeverRespond
Then refresh the Nexus repository list or reboot Nexus. This causes a status check and a CONNECT which hangs forever.
jvm 1 | 2016-01-14 00:26:49,569-0400 INFO [proxy-3-thread-1] *SYSTEM org.sonatype.nexus.proxy.storage.remote.httpclient.HttpClientRemoteStorage - Initializing remote transport for proxy repository "Central" [id=central]...
jvm 1 | 2016-01-14 00:26:49,576-0400 INFO [RepositoryStatusChecker-central] *SYSTEM org.sonatype.nexus.proxy.maven.maven2.M2Repository-central - Next attempt to auto-unblock the "Central" (id=central) repository by checking its remote peer health will occur in 5 minutes.
jvm 1 | 2016-01-14 00:26:49,582-0400 DEBUG [proxy-3-thread-1] *SYSTEM org.sonatype.nexus.apachehttpclient.Hc4ProviderImpl - http proxy setup with host 'localhost'
jvm 1 | 2016-01-14 00:26:49,607-0400 DEBUG [proxy-3-thread-1] *SYSTEM com.sonatype.central.secure.nexus.plugin.internal.SecureCentralServiceImpl - Base URI: https://secure.central.sonatype.com:443
jvm 1 | 2016-01-14 00:26:49,607-0400 DEBUG [proxy-3-thread-1] *SYSTEM com.sonatype.central.secure.nexus.plugin.internal.SecureCentralServiceImpl - Service URI: https://secure.central.sonatype.com:443/service
jvm 1 | 2016-01-14 00:26:49,609-0400 DEBUG [proxy-3-thread-1] *SYSTEM remote.storage.outbound - [central] HEAD https://repo1.maven.org/maven2/
jvm 1 | 2016-01-14 00:26:49,609-0400 DEBUG [proxy-3-thread-1] *SYSTEM org.sonatype.nexus.proxy.storage.remote.httpclient.HttpClientRemoteStorage - Invoking HTTP HEAD method against remote location https://repo1.maven.org/maven2/
jvm 1 | 2016-01-14 00:26:49,619-0400 DEBUG [proxy-3-thread-1] *SYSTEM org.apache.http.client.protocol.RequestAddCookies - CookieSpec selected: ignoreCookies
jvm 1 | 2016-01-14 00:26:49,621-0400 DEBUG [proxy-3-thread-1] *SYSTEM org.apache.http.client.protocol.RequestAuthCache - Auth cache not set in the context
jvm 1 | 2016-01-14 00:26:49,622-0400 DEBUG [proxy-3-thread-1] *SYSTEM org.sonatype.nexus.apachehttpclient.Hc4ProviderImpl$ManagedClientConnectionManager - Connection request: [route: {tls}->http://localhost:8888->https://repo1.maven.org:443][total kept alive: 0; route allocated: 0 of 20; total allocated: 0 of 200]
jvm 1 | 2016-01-14 00:26:49,634-0400 DEBUG [proxy-3-thread-1] *SYSTEM org.sonatype.nexus.apachehttpclient.Hc4ProviderImpl$ManagedClientConnectionManager - Connection leased: [id: 0][route: {tls}->http://localhost:8888->https://repo1.maven.org:443][total kept alive: 0; route allocated: 1 of 20; total allocated: 1 of 200]
jvm 1 | 2016-01-14 00:26:49,635-0400 DEBUG [proxy-3-thread-1] *SYSTEM org.apache.http.impl.execchain.MainClientExec - Opening connection {tls}->http://localhost:8888->https://repo1.maven.org:443
jvm 1 | 2016-01-14 00:26:49,637-0400 DEBUG [proxy-3-thread-1] *SYSTEM org.apache.http.impl.conn.HttpClientConnectionOperator - Connecting to localhost/127.0.0.1:8888
jvm 1 | 2016-01-14 00:26:49,638-0400 DEBUG [proxy-3-thread-1] *SYSTEM org.apache.http.impl.conn.HttpClientConnectionOperator - Connection established 127.0.0.1:58576<->127.0.0.1:8888
jvm 1 | 2016-01-14 00:26:49,640-0400 DEBUG [proxy-3-thread-1] *SYSTEM org.apache.http.headers - http-outgoing-0 >> CONNECT repo1.maven.org:443 HTTP/1.1
jvm 1 | 2016-01-14 00:26:49,640-0400 DEBUG [proxy-3-thread-1] *SYSTEM org.apache.http.headers - http-outgoing-0 >> User-Agent: Nexus/2.12.0-01 (PRO; Mac OS X; 10.11.2; x86_64; 1.8.0_45)
jvm 1 | 2016-01-14 00:26:49,640-0400 DEBUG [proxy-3-thread-1] *SYSTEM org.apache.http.headers - http-outgoing-0 >> Host: repo1.maven.org
jvm 1 | 2016-01-14 00:26:49,640-0400 DEBUG [proxy-3-thread-1] *SYSTEM org.apache.http.headers - http-outgoing-0 >> Proxy-Connection: Keep-Alive
Supplemental
Connections which do not use CONNECT ( plain http urls ) but attempt to use the Nexus HTTP proxy server which does not respond do have their socket timeout set correctly and respect the standard retries and connect timeout settings in Nexus.
Workaround
Use the plain HTTP remote url of the target repository if one is available. This bypasses CONNECT and the problem.
Do not configure your HTTP proxy or firewall to hang socket connections.
Attachments
Issue Links
- is related to
-
NEXUS-12685 upgrade httpclient dependency to 4.5.4 or greater
-
- Closed
-
