No visibility in Vault service log to check dynamic DB secret engine error/timeout

Hi Hashi Communitu:

In a lot of cases, when we are trying to demo dynamic db pipeline to the program sponsor, more often or not, we are seeing the following issue on our mysql/oracle db secret engine

$ vault read db/mysql/creds/dbascode_auditlog
Error reading db/mysql/creds/dbascode_auditlog: context deadline exceeded

This issue happens intermittently, in some other cases the same DB secret engine is working fine.
This seems like the connection gets timeout after around 50s of no response, but we are not seeing any useful info from our application log either

journalctl -u vault --no-pager

Is there a way to tail the log from vault application to see what would be the issue

Thanks in advance!

To give more context, not sure if we are running into the same problem here


Out vault OSS version is 1.3.2
using consul as storage backend

After sometime, there are logs in the vault server which could indicate the connection got timeout

Sep 23 17:18:09 dev-tev-secretsmanagement-vault-i-08a42c5f88f9309bf vault[11321]: 2020-09-23T17:18:09.040-0400 [ERROR] expiration: failed to revoke lease: lease_id=db/mysql/creds/dbascode_auditlog/US3KaBG93Sn0CWjfhpy3IiRp error="failed to revoke entry: resp: (*logical.Response)(nil) err: context deadline exceeded"
Sep 23 17:19:59 dev-tev-secretsmanagement-vault-i-08a42c5f88f9309bf vault[11321]: 2020-09-23T17:19:59.041-0400 [ERROR] expiration: failed to revoke lease: lease_id=db/mysql/creds/dbascode_auditlog/US3KaBG93Sn0CWjfhpy3IiRp error="failed to revoke entry: resp: (*logical.Response)(nil) err: context deadline exceeded"
Sep 23 17:21:16 dev-tev-secretsmanagement-vault-i-08a42c5f88f9309bf vault[11321]: 2020-09-23T17:21:16.986-0400 [ERROR] secrets.system.system_2c324c91: error occurred during enable mount: path=db/mysql/ error="path is already in use at db/mysql/"
Sep 23 17:22:09 dev-tev-secretsmanagement-vault-i-08a42c5f88f9309bf vault[11321]: 2020-09-23T17:22:09.041-0400 [ERROR] expiration: failed to revoke lease: lease_id=db/mysql/creds/dbascode_auditlog/US3KaBG93Sn0CWjfhpy3IiRp error="failed to revoke entry: resp: (*logical.Response)(nil) err: context deadline exceeded"
Sep 23 17:24:59 dev-tev-secretsmanagement-vault-i-08a42c5f88f9309bf vault[11321]: 2020-09-23T17:24:59.042-0400 [ERROR] expiration: failed to revoke lease: lease_id=db/mysql/creds/dbascode_auditlog/US3KaBG93Sn0CWjfhpy3IiRp error="failed to revoke entry: resp: (*logical.Response)(nil) err: context deadline exceeded"
Sep 23 17:29:09 dev-tev-secretsmanagement-vault-i-08a42c5f88f9309bf vault[11321]: 2020-09-23T17:29:09.044-0400 [ERROR] expiration: failed to revoke lease: lease_id=db/mysql/creds/dbascode_auditlog/US3KaBG93Sn0CWjfhpy3IiRp error="failed to revoke entry: resp: (*logical.Response)(nil) err: context deadline exceeded"

Would like to have more in depth understanding of how this behaviour happened. In our experience, this could happen sporadically but if we could reproduce this bug, then maybe we can understand more of the issue.

Thanks