Hello,
We have vault installeed in kubernetes with 3 pod replicaset. We didnt face any issue since an year after we started using it. Unexpectedly in our production, we saw an issue where vault pods were locking up the backend postgres connections and started restarting themselves with below messages. where we understand it was unable to revoke the expired tokens since it was not able to aquire postgres connections.
After multiple restarts and increasing the memory of vault nodes, it somehow started running normally, but we are not able to figure out what was the cause for the issue and how to mitigate such things in future.
Below are some logs that we captures across these multiple restarts, Can someone here can give any insights on these logs and when they can possibly happen,
Vault version we are using is 1.3.2 with postgres as backend. our unseal master keys are integrated with AWS KMS.
2021-04-19T18:07:40.857Z [ERROR] expiration: core context canceled, not attempting further revocation of lease: lease_id=auth/token/create/h9de9bb08cb803c1f97d74892494b0e1b98b7097eadb6c4a209a7d1400e1c1fe8
2021-04-19T18:07:41.169Z [ERROR] expiration: core context canceled, not attempting further revocation of lease: lease_id=auth/token/create/h5f94254b91839f85c832016092593dabfaa8755c7e9d1e346374aa5e3f5e0999
2021-04-19T18:07:42.578Z [ERROR] expiration: core context canceled, not attempting further revocation of lease: lease_id=auth/token/create/h3ca178457c7865b8d7c9cb1504be858e6f9622de147a3b21caaec2962a9f3018
> 2021-04-19T17:06:45.825Z [INFO] expiration: revoked lease: lease_id=auth/token/create/h993b89910aeb929b5e278f64b22d1d2a93113e0eb473feccac21e7af26d940aa
2021-04-19T17:06:47.048Z [INFO] expiration: revoked lease: lease_id=auth/token/create/he41774f36911b2bf6df3571beba9247719909c96588b4fdce78ed56190392973
2021-04-19T17:06:47.126Z [ERROR] expiration: error restoring leases: error=“failed to read lease entry auth/token/create/h16107713b2540108065b1d67630ebe9d27b130846f7f2a55635678c18dad4cd9: dial tcp 172.25.4.35:5432: connect: cannot assign requested address”
2021-04-19T17:06:47.126Z [ERROR] core: shutting down
2021-04-19T17:06:47.126Z [INFO] core: marked as sealed
2021-04-19T17:06:47.126Z [INFO] core: pre-seal teardown starting
2021-04-19T17:06:47.638Z [WARN] core.cluster-listener: no TLS config found for ALPN: ALPN=[req_fw_sb-act_v1]
2021-04-19T17:06:47.671Z [INFO] rollback: stopping rollback manager
2021-04-19T17:06:47.671Z [INFO] core: pre-seal teardown complete
2021-04-19T17:06:47.676Z [INFO] core: stopping cluster listeners
2021-04-19T17:06:47.676Z [INFO] core.cluster-listener: forwarding rpc listeners stopped
2021-04-19T17:06:48.138Z [INFO] core.cluster-listener: rpc listeners successfully shut down
2021-04-19T17:06:48.138Z [INFO] core: cluster listeners successfully shut down
2021-04-19T17:06:48.138Z [INFO] core: vault is sealed
2021-04-19T17:40:18.277Z [INFO] core.cluster-listener: starting listener: listener_address=[::]:8201
2021-04-19T17:40:18.277Z [INFO] core.cluster-listener: serving cluster requests: cluster_listen_address=[::]:8201
2021-04-19T17:40:18.277Z [INFO] core: entering standby mode
2021-04-19T17:40:18.277Z [INFO] core: vault is unsealed
2021-04-19T18:00:07.140Z [ERROR] core: error during forwarded RPC request: error=“rpc error: code = Unavailable desc = transport is closing”
2021-04-19T18:00:07.140Z [ERROR] core: forward request error: error=“error during forwarding RPC request”
2021-04-19T18:00:07.140Z [ERROR] core: error during forwarded RPC request: error=“rpc error: code = Unavailable desc = transport is closing”
2021-04-19T18:00:07.140Z [ERROR] core: forward request error: error=“error during forwarding RPC request”
2021-04-19T18:00:07.140Z [ERROR] core: error during forwarded RPC request: error=“rpc error: code = Unavailable desc = transport is closing”
2021-04-19T16:55:55.558Z [INFO] proxy environment: http_proxy= https_proxy= no_proxy=
2021-04-19T16:55:55.680Z [INFO] core: stored unseal keys supported, attempting fetch
2021-04-19T16:55:55.744Z [INFO] core.cluster-listener: starting listener: listener_address=[::]:8201
2021-04-19T16:55:55.744Z [INFO] core.cluster-listener: serving cluster requests: cluster_listen_address=[::]:8201
2021-04-19T16:55:55.744Z [INFO] core: entering standby mode
2021-04-19T16:55:55.745Z [INFO] core: vault is unsealed
2021-04-19T16:55:55.745Z [INFO] core: unsealed with stored keys: stored_keys_used=1
2021-04-19T16:55:56.360Z [WARN] core.cluster-listener: no TLS config found for ALPN: ALPN=[req_fw_sb-act_v1]
2021-04-19T16:55:56.361Z [ERROR] core: error during forwarded RPC request: error=“rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = “transport: Error while dialing remote error: tls: internal error””
2021-04-19T16:55:56.361Z [ERROR] core: forward request error: error=“error during forwarding RPC request”
2021-04-19T16:55:56.375Z [ERROR] core: error during forwarded RPC request: error=“rpc error: code = Unavailable desc = all SubConns are in TransientFailure, latest connection error: connection error: desc = “transport: Error while dialing remote error: tls: internal error””