Benjamin ZAEHRINGER created HTTPCLIENT-2235:
-----------------------------------------------
Summary: 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: Benjamin ZAEHRINGER
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
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]
