Service unable to obtain a Vault Token after expiring

[nyameen]

Hello,

I am wondering if anyone has faced this issue and if there is a way to solve it without restarting multiple services manually. In secure mode, each service is given a Vault Token for communicating to Vault. This token is only valid for 1 hour and is supposed to be renewed every 30 minutes. If a service is stopped, and then restarted after 1 hour, it cannot start. For example, you can stop any device or app service, in this case, device-modbus

$ docker-compose up -d
$ docker stop edgex-device-modbus
# wait 1 hour...

$ docker start edgex-device-modbus

In the device-modbus logs you will see this repeatedly until secretstore-setup is manually restarted:

Mon Apr  8 10:52:40 EDT 2024 Executing waitFor with /device-modbus -cp=consul.http://edgex-core-consul:8500 --registry waiting on tcp://edgex-security-bootstrapper:54329
level=INFO ts=2024-04-08T14:52:40.081590107Z app=security-bootstrapper source=config.go:731 msg="Loading configuration file from /edgex-init/res/configuration.yaml"
level=INFO ts=2024-04-08T14:52:40.081832254Z app=security-bootstrapper source=variables.go:462 msg="Variables override of 'StageGate/BootStrapper/Host' by environment variable: STAGEGATE_BOOTSTRAPPER_HOST=edgex-security-bootstrapper"
level=INFO ts=2024-04-08T14:52:40.081856904Z app=security-bootstrapper source=variables.go:462 msg="Variables override of 'StageGate/Registry/ReadyPort' by environment variable: STAGEGATE_REGISTRY_READYPORT=54324"
level=INFO ts=2024-04-08T14:52:40.081862251Z app=security-bootstrapper source=variables.go:462 msg="Variables override of 'StageGate/SecretStoreSetup/Host' by environment variable: STAGEGATE_SECRETSTORESETUP_HOST=edgex-security-secretstore-setup"
level=INFO ts=2024-04-08T14:52:40.081865799Z app=security-bootstrapper source=variables.go:462 msg="Variables override of 'StageGate/Registry/Host' by environment variable: STAGEGATE_REGISTRY_HOST=edgex-core-consul"
level=INFO ts=2024-04-08T14:52:40.081869091Z app=security-bootstrapper source=variables.go:462 msg="Variables override of 'StageGate/Database/ReadyPort' by environment variable: STAGEGATE_DATABASE_READYPORT=6379"
level=INFO ts=2024-04-08T14:52:40.081873297Z app=security-bootstrapper source=variables.go:462 msg="Variables override of 'StageGate/Ready/ToRunPort' by environment variable: STAGEGATE_READY_TORUNPORT=54329"
level=INFO ts=2024-04-08T14:52:40.081876504Z app=security-bootstrapper source=variables.go:462 msg="Variables override of 'StageGate/Database/Host' by environment variable: STAGEGATE_DATABASE_HOST=edgex-redis"
level=INFO ts=2024-04-08T14:52:40.081879733Z app=security-bootstrapper source=variables.go:462 msg="Variables override of 'StageGate/Database/Port' by environment variable: STAGEGATE_DATABASE_PORT=6379"
level=INFO ts=2024-04-08T14:52:40.081883198Z app=security-bootstrapper source=variables.go:462 msg="Variables override of 'StageGate/BootStrapper/StartPort' by environment variable: STAGEGATE_BOOTSTRAPPER_STARTPORT=54321"
level=INFO ts=2024-04-08T14:52:40.081886628Z app=security-bootstrapper source=variables.go:462 msg="Variables override of 'SecretStore/Host' by environment variable: SECRETSTORE_HOST=edgex-vault"
level=INFO ts=2024-04-08T14:52:40.081900796Z app=security-bootstrapper source=variables.go:462 msg="Variables override of 'StageGate/WaitFor/Timeout' by environment variable: STAGEGATE_WAITFOR_TIMEOUT=60s"
level=INFO ts=2024-04-08T14:52:40.081906437Z app=security-bootstrapper source=variables.go:462 msg="Variables override of 'StageGate/SecretStoreSetup/Tokens/ReadyPort' by environment variable: STAGEGATE_SECRETSTORESETUP_TOKENS_READYPORT=54322"
level=INFO ts=2024-04-08T14:52:40.081920921Z app=security-bootstrapper source=variables.go:462 msg="Variables override of 'StageGate/Registry/Port' by environment variable: STAGEGATE_REGISTRY_PORT=8500"
level=INFO ts=2024-04-08T14:52:40.081926877Z app=security-bootstrapper source=config.go:251 msg="Private configuration loaded from file with 13 overrides applied"
level=INFO ts=2024-04-08T14:52:40.082088204Z app=security-bootstrapper source=command.go:119 msg="Security bootstrapper running waitFor"
level=INFO ts=2024-04-08T14:52:40.082142486Z app=security-bootstrapper source=command.go:144 msg="Waiting for: [tcp://edgex-security-bootstrapper:54329] with timeout: [1m0s]"
level=INFO ts=2024-04-08T14:52:40.084120904Z app=security-bootstrapper source=command.go:214 msg="Connected to tcp://edgex-security-bootstrapper:54329"
Mon Apr  8 10:52:40 EDT 2024 Starting /device-modbus -cp=consul.http://edgex-core-consul:8500 --registry ...
level=INFO ts=2024-04-08T14:52:40.09118069Z app=device-modbus source=secret.go:69 msg="Creating SecretClient"
level=INFO ts=2024-04-08T14:52:40.091349396Z app=device-modbus source=variables.go:462 msg="Variables override of 'SecretStore/Host' by environment variable: SECRETSTORE_HOST=edgex-vault"
level=INFO ts=2024-04-08T14:52:40.09176703Z app=device-modbus source=secret.go:172 msg="SecretStore information created with 1 overrides applied"
level=INFO ts=2024-04-08T14:52:40.091789455Z app=device-modbus source=secret.go:79 msg="Reading secret store configuration and authentication token"
level=INFO ts=2024-04-08T14:52:40.091815447Z app=device-modbus source=secret.go:216 msg="load token from file"
level=INFO ts=2024-04-08T14:52:40.0918817Z app=device-modbus source=secret.go:101 msg="Attempting to create secret client"
level=WARN ts=2024-04-08T14:52:40.093027985Z app=device-modbus source=secret.go:132 msg="Retryable failure while creating SecretClient: HTTP response with status code 403, message: failed to lookup token"
level=INFO ts=2024-04-08T14:52:41.093228648Z app=device-modbus source=secret.go:79 msg="Reading secret store configuration and authentication token"
level=INFO ts=2024-04-08T14:52:41.093283236Z app=device-modbus source=secret.go:216 msg="load token from file"
level=INFO ts=2024-04-08T14:52:41.093359875Z app=device-modbus source=secret.go:101 msg="Attempting to create secret client"
level=WARN ts=2024-04-08T14:52:41.094754752Z app=device-modbus source=secret.go:132 msg="Retryable failure while creating SecretClient: HTTP response with status code 403, message: failed to lookup token"
level=INFO ts=2024-04-08T14:52:42.094861604Z app=device-modbus source=secret.go:79 msg="Reading secret store configuration and authentication token"
level=INFO ts=2024-04-08T14:52:42.094927865Z app=device-modbus source=secret.go:216 msg="load token from file"
level=INFO ts=2024-04-08T14:52:42.0950129Z app=device-modbus source=secret.go:101 msg="Attempting to create secret client"
level=WARN ts=2024-04-08T14:52:42.096275804Z app=device-modbus source=secret.go:132 msg="Retryable failure while creating SecretClient: HTTP response with status code 403, message: failed to lookup token"
level=INFO ts=2024-04-08T14:52:43.096653098Z app=device-modbus source=secret.go:79 msg="Reading secret store configuration and authentication token"
level=INFO ts=2024-04-08T14:52:43.096769719Z app=device-modbus source=secret.go:216 msg="load token from file"
level=INFO ts=2024-04-08T14:52:43.096921259Z app=device-modbus source=secret.go:101 msg="Attempting to create secret client"

...

level=INFO ts=2024-04-08T14:53:39.254430923Z app=device-modbus source=secret.go:101 msg="Attempting to create secret client"
level=WARN ts=2024-04-08T14:53:39.255664552Z app=device-modbus source=secret.go:132 msg="Retryable failure while creating SecretClient: HTTP response with status code 403, message: failed to lookup token"
level=ERROR ts=2024-04-08T14:53:40.256126896Z app=device-modbus source=bootstrap.go:48 msg="failed to create SecretProvider: unable to create SecretClient: HTTP response with status code 403, message: failed to lookup token"

Is there a way I can successfully start device-modbus without having to restart the entire deployment?

[cloudxxx8]

can you resolve this by restarting secretstore-setup

[jrtitus]

Hi @cloudxxx8 - yes, we have seen that it is resolved when secretstore-setup is restarted, but the goal would be to not have to manually restart this service.

[cloudxxx8]

Another workaround is to extend the token TTL
You can add an environment variable here:
https://github.com/edgexfoundry/edgex-compose/blob/c25035d319c2721f419fa1864a28196a409b7fe8/docker-compose.yml#L1005

TOKENFILEPROVIDER_DEFAULTTOKENTTL: 720h
default is 1h
it depends on your security policy

[cloudxxx8]

Refer to: https://github.com/edgexfoundry/edgex-go/blob/971ded0da61705452274f4b577f848bc3eecf2cb/cmd/security-secretstore-setup/res-file-token-provider/configuration.yaml#L14

[jrtitus]

Thank you, @cloudxxx8. So, this particular TTL is associated with the Vault token that is used to renew the service-to-service JWT, while the DefaultJWTTTL is the amount of time that the service-to-service token produced by this renewal is good for. In that case if any of the service containers are down for longer than DefaultTokenTTL, there's no other option other than restarting the secretstore-setup container to generate a new Vault identity provider token and JWTs for all services.

Did I understand that correctly?

Does each service use its generated client_token to request a token refresh during its lifetime? So, if a service misses the DefaultTokenTTL window, or the Default token has already been refreshed (and thus the two tokens no longer have any relation), this would explain why there's nothing else that can be done other than regenerating the value in the secrets-token.json.

[cloudxxx8]

You can also refer to another approach
https://docs.edgexfoundry.org/3.1/security/Ch-DelayedStartServices/
https://docs.edgexfoundry.org/3.1/design/adr/security/0020-spiffe/