[
https://issues.apache.org/jira/browse/HTTPCLIENT-2235?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Oleg Kalnichevski resolved HTTPCLIENT-2235.
-------------------------------------------
Resolution: Information Provided
> Spring Cloud Vault Config - SocketTimeoutException using
> HttpComponentsClientHttpRequest
> ----------------------------------------------------------------------------------------
>
> Key: HTTPCLIENT-2235
> URL: https://issues.apache.org/jira/browse/HTTPCLIENT-2235
> Project: HttpComponents HttpClient
> Issue Type: Bug
> Components: HttpClient (classic)
> Affects Versions: 4.5.14
> Environment: Production
> Reporter: Spectateur
> Priority: Major
>
> Hello,
> We are using spring cloud vault with spring boot application hosted in a
> cloud provider, and an hashicorp vault v1.11.2 on premise.
> {code:java}
> <spring-boot.version>2.3.12.RELEASE</spring-boot.version>
> <groupId>org.springframework.cloud</groupId><artifactId>spring-cloud-starter-vault-config</artifactId><version>2.2.7.RELEASE</version>{code}
> Our Spring boot application use an abstraction for interchangeable HTTP
> Clients, we are using here Apache HTTP Client httpclient-4.5.13
> {code:java}
> <dependencies>
> <dependency>
> <groupId>org.apache.httpcomponents</groupId>
> <artifactId>httpclient</artifactId>
> <version>4.5.10</version>
> <scope>compile</scope>
> <exclusions>
> <exclusion>
> <artifactId>commons-logging</artifactId>
> <groupId>commons-logging</groupId>
> </exclusion>
> </exclusions>
> </dependency>
> <dependency>
> <groupId>org.apache.httpcomponents</groupId>
> <artifactId>httpcore</artifactId>
> <version>4.4.12</version>
> <scope>compile</scope>
> </dependency> {code}
> We are experiencing randomly, timeouts during renew (in our case 48H lease)
> or authentication with the vault.
> These timeouts are produce only when the client does not ACK the FIN from the
> server.
> *Error detail :*
> {{ }}
> {code:java}
> Sep 18 17:47:08 pod-name-back WARN | | |
> o.s.v.c.l.SecretLeaseEventPublisher$LoggingErrorListener - [RequestedSecret
> [path='database/postgres/instance01/creds/own_instance01', mode=RENEW]] Lease
> [leaseId='database/postgres/instance01/creds/own_instance01/bPz8jG8SmDJXYt36f5ZVVQ3x.BXpj9',
> leaseDuration=PT48H, renewable=true] Cannot renew lease; nested exception is
> org.springframework.web.client.ResourceAccessException: I/O error on PUT
> request for "https://hvault.mysite.com:443/v1/sys/renew": Read timed out;
> nested exception is java.net.SocketTimeoutException: Read timed out
> org.springframework.vault.VaultException: Cannot renew lease; nested
> exception is org.springframework.web.client.ResourceAccessException: I/O
> error on PUT request for "https://hvault.mysite.com:443/v1/sys/renew": Read
> timed out; nested exception is java.net.SocketTimeoutException: Read timed
> out at
> org.springframework.vault.core.lease.SecretLeaseContainer.doRenewLease(SecretLeaseContainer.java:720)
> at
> org.springframework.vault.core.lease.SecretLeaseContainer.renewAndSchedule(SecretLeaseContainer.java:589)
> at
> org.springframework.vault.core.lease.SecretLeaseContainer.lambda$scheduleLeaseRenewal$0(SecretLeaseContainer.java:581)
> at
> org.springframework.vault.core.lease.SecretLeaseContainer$LeaseRenewalScheduler$1.run(SecretLeaseContainer.java:891)
> at
> org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
> at
> org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:93)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266) at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at java.lang.Thread.run(Thread.java:750) Caused by:
> org.springframework.web.client.ResourceAccessException: I/O error on PUT
> request for "https://hvault.mysite.com:443/v1/sys/renew": Read timed out;
> nested exception is java.net.SocketTimeoutException: Read timed out at
> org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:746)
> at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:672)
> at
> org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:581)
> at
> org.springframework.vault.core.lease.LeaseEndpoints$1.renew(LeaseEndpoints.java:59)
> at
> org.springframework.vault.core.lease.SecretLeaseContainer.lambda$doRenew$2(SecretLeaseContainer.java:752)
> at
> org.springframework.vault.core.VaultTemplate.doWithSession(VaultTemplate.java:388)
> at
> org.springframework.vault.core.lease.SecretLeaseContainer.doRenew(SecretLeaseContainer.java:751)
> at
> org.springframework.vault.core.lease.SecretLeaseContainer.doRenewLease(SecretLeaseContainer.java:688)
> ... 12 common frames omitted Caused by: java.net.SocketTimeoutException:
> Read timed out at java.net.SocketInputStream.socketRead0(Native Method) at
> java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at
> java.net.SocketInputStream.read(SocketInputStream.java:171) at
> java.net.SocketInputStream.read(SocketInputStream.java:141) at
> sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:464) at
> sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:68)
> at
> sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1346)
> at sun.security.ssl.SSLSocketImpl.access$300(SSLSocketImpl.java:73) at
> sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:962) at
> org.apache.http.impl.conn.LoggingInputStream.read(LoggingInputStream.java:84)
> at
> org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
> at
> org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
> at
> org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:280)
> at
> org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
> at
> org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
> at
> org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
> at
> org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
> at
> org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:157)
> at
> org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
> at
> org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
> at
> org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
> at
> org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186) at
> org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89) at
> org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110) at
> org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
> at
> org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
> at
> org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
> at
> org.springframework.http.client.HttpComponentsClientHttpRequest.executeInternal(HttpComponentsClientHttpRequest.java:87)
> at
> org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48)
> at
> org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53)
> at
> org.springframework.http.client.InterceptingClientHttpRequest$InterceptingRequestExecution.execute(InterceptingClientHttpRequest.java:109)
> at
> org.springframework.vault.core.VaultTemplate.lambda$getSessionInterceptor$1(VaultTemplate.java:200)
> at
> org.springframework.http.client.InterceptingClientHttpRequest$InterceptingRequestExecution.execute(InterceptingClientHttpRequest.java:93)
> at
> org.springframework.vault.client.VaultClients.lambda$createRestTemplate$0(VaultClients.java:128)
> at
> org.springframework.http.client.InterceptingClientHttpRequest$InterceptingRequestExecution.execute(InterceptingClientHttpRequest.java:93)
> at
> org.springframework.http.client.InterceptingClientHttpRequest.executeInternal(InterceptingClientHttpRequest.java:77)
> at
> org.springframework.http.client.AbstractBufferingClientHttpRequest.executeInternal(AbstractBufferingClientHttpRequest.java:48)
> at
> org.springframework.http.client.AbstractClientHttpRequest.execute(AbstractClientHttpRequest.java:53)
> at
> org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:737)
> ... 19 common frames omitted{code}
> {{ }}
> After digging into communications between our vault server and the clients we
> have seen that spring cloud vault framework reuse TLS sessions and TCP
> sessions that have been created with the previous renew.
> From vault perspective these sessions have been closed accordingly to the
> vault timeout as vault server didn't receive anymore communications from the
> client. All network equipments, worker nodes also dropped the original
> session in kernel table after grace period (TCP end timeout) triggered by
> receiving FIN from vault server.
> So in the following capture you can see a timeout event on 2022-09-18
> 17:47:08 that triggered a close_notify from client (see frame N°2741), and
> which is 15sec after the renew request (read-timeout = 15000ms),
> [!https://user-images.githubusercontent.com/102883284/191934711-67c6d611-55ea-44e9-8523-9c85ab27eb63.png!|https://user-images.githubusercontent.com/102883284/191934711-67c6d611-55ea-44e9-8523-9c85ab27eb63.png]
> The port used during the timeout is the same than the one used for the
> previous renew 48H before (see frame N° 2725)/
> [!https://user-images.githubusercontent.com/102883284/191936332-8503d5de-e6f8-4ef2-9ebc-8886268fafc4.png!|https://user-images.githubusercontent.com/102883284/191936332-8503d5de-e6f8-4ef2-9ebc-8886268fafc4.png]
> Note that the client does not ACK vault close_notify for TLS / TCP FIN,
> (frame N°1985 to 1988) but we are not sure that this could explain why the
> client reuse the same TLS sessions days after.
> But even if the client does not ACK (whereas most of the time it does) the
> current implementation should timed-out on the client side.
> As the vault client is reusing a session that is no longer existing, the
> worker node initiate a new port (the sequence number 1 in frame N°2726) and
> because this new TCP session isn't SYN on next hop network equipment, it is
> dropped with "first packet isn't SYN error message".
> Even if it was SYN we would end up reaching the vault with the original port
> that was FIN 48H ago by the vault server itself.
> So here we are exploring ways to understand if it's a bug in or if it a
> wrongfull use of {{org.apache.http.impl.client }}
> Thanks for your help,
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
