hashicorp / hashicorp/consul-template
Secrets not updating
- Dominant language
- Go
- Stars
- 4.8k
- Forks
- 801
- Avg merge
- 4h 5m
- Merged PRs (30d)
- 6
Description
### Consul Template version
consul-template v0.25.1 (b11fa800)
### Configuration
```hcl
consul {
address = "192.168.122.1:8500"
token = "abcd1234"
}
vault {
address = "http://192.168.122.1:8200"
token = "abcd1234"
}
template {
source = "/tmp/test.ctmpl"
destination = "/tmp/test.out"
}
```
```liquid
{{ key "mykey" }}
{{ secret "secret/mysecret" }}
```
Consul `mykey`:
```liquid
123
```
Vault `mysecret`:
```liquid
{"foo":"bar1"}
```
### Command
```shell
consul-template -config test.hcl -dry -log-level=trace
```
### Debug output
```
2020/11/04 04:06:06.747863 [INFO] consul-template v0.25.1 (b11fa800)
2020/11/04 04:06:06.747897 [INFO] (runner) creating new runner (dry: true, once: false)
2020/11/04 04:06:06.748100 [DEBUG] (runner) final config: {"Consul":{"Address":"192.168.122.1:8500","Namespace":"","Auth":{"Enabled":false,"Username":"","Password":""},"Retry":{"Attempts":12,"Backoff":250000000,"MaxBackoff":60000000000,"Enabled":true},"SSL":{"CaCert":"","CaPath":"","Cert":"","Enabled":false,"Key":"","ServerName":"","Verify":true},"Token":"","Transport":{"DialKeepAlive":30000000000,"DialTimeout":30000000000,"DisableKeepAlives":false,"IdleConnTimeout":90000000000,"MaxIdleConns":100,"MaxIdleConnsPerHost":4,"TLSHandshakeTimeout":10000000000}},"Dedup":{"Enabled":false,"MaxStale":2000000000,"Prefix":"consul-template/dedup/","TTL":15000000000,"BlockQueryWaitTime":60000000000},"DefaultDelims":{"Left":null,"Right":null},"Exec":{"Command":"","Enabled":false,"Env":{"Denylist":[],"Custom":[],"Pristine":false,"Allowlist":[]},"KillSignal":2,"KillTimeout":30000000000,"ReloadSignal":null,"Splay":0,"Timeout":0},"KillSignal":2,"LogLevel":"trace","MaxStale":2000000000,"PidFile":"","ReloadSignal":1,"Syslog":{"Enabled":false,"Facility":"LOCAL0","Name":"consul-template"},"Templates":[{"Backup":false,"Command":"","CommandTimeout":30000000000,"Contents":"","CreateDestDirs":true,"Destination":"/tmp/test.out","ErrMissingKey":false,"Exec":{"Command":"","Enabled":false,"Env":{"Denylist":[],"Custom":[],"Pristine":false,"Allowlist":[]},"KillSignal":2,"KillTimeout":30000000000,"ReloadSignal":null,"Splay":0,"Timeout":30000000000},"Perms":0,"Source":"/tmp/test.ctmpl","Wait":{"Enabled":false,"Min":0,"Max":0},"LeftDelim":"","RightDelim":"","FunctionDenylist":[],"SandboxPath":""}],"Vault":{"Address":"http://192.168.122.1:8200","Enabled":true,"Namespace":"","RenewToken":true,"Retry":{"Attempts":12,"Backoff":250000000,"MaxBackoff":60000000000,"Enabled":true},"SSL":{"CaCert":"","CaPath":"","Cert":"","Enabled":true,"Key":"","ServerName":"","Verify":true},"Transport":{"DialKeepAlive":30000000000,"DialTimeout":30000000000,"DisableKeepAlives":false,"IdleConnTimeout":90000000000,"MaxIdleConns":100,"MaxIdleConnsPerHost":4,"TLSHandshakeTimeout":10000000000},"UnwrapToken":false},"Wait":{"Enabled":false,"Min":0,"Max":0},"Once":false,"BlockQueryWaitTime":60000000000}
2020/11/04 04:06:06.748150 [INFO] (runner) creating watcher
2020/11/04 04:06:06.748164 [DEBUG] (watcher) adding vault.token
2020/11/04 04:06:06.748170 [TRACE] (watcher) vault.token starting
2020/11/04 04:06:06.748271 [TRACE] (view) vault.token starting fetch
2020/11/04 04:06:06.748298 [TRACE] vault.token: starting renewer
2020/11/04 04:06:06.748410 [INFO] (runner) starting
2020/11/04 04:06:06.748420 [DEBUG] (runner) running initial templates
2020/11/04 04:06:06.748459 [DEBUG] (runner) initiating run
2020/11/04 04:06:06.748773 [DEBUG] (runner) checking template bcaf102ae0995d5b6c74b5a06d739b62
2020/11/04 04:06:06.749426 [DEBUG] (runner) missing data for 2 dependencies
2020/11/04 04:06:06.749562 [DEBUG] (runner) missing dependency: kv.block(mykey)
2020/11/04 04:06:06.749656 [DEBUG] (runner) missing dependency: vault.read(secret/mysecret)
2020/11/04 04:06:06.749733 [DEBUG] (runner) add used dependency kv.block(mykey) to missing since isLeader but do not have a watcher
2020/11/04 04:06:06.749810 [DEBUG] (runner) add used dependency vault.read(secret/mysecret) to missing since isLeader but do not have a watcher
2020/11/04 04:06:06.749897 [DEBUG] (runner) was not watching 2 dependencies
2020/11/04 04:06:06.749975 [DEBUG] (watcher) adding kv.block(mykey)
2020/11/04 04:06:06.750124 [TRACE] (watcher) kv.block(mykey) starting
2020/11/04 04:06:06.750238 [DEBUG] (watcher) adding vault.read(secret/mysecret)
2020/11/04 04:06:06.750432 [TRACE] (watcher) vault.read(secret/mysecret) starting
2020/11/04 04:06:06.750539 [DEBUG] (runner) diffing and updating dependencies
2020/11/04 04:06:06.750711 [DEBUG] (runner) watching 3 dependencies
2020/11/04 04:06:06.750368 [TRACE] (view) kv.block(mykey) starting fetch
2020/11/04 04:06:06.751002 [TRACE] kv.block(mykey): GET /v1/kv/mykey?stale=true&wait=1m0s
2020/11/04 04:06:06.751151 [TRACE] vault.token: successfully renewed
2020/11/04 04:06:06.751167 [WARN] vault.token: TTL of "765h9m" exceeded the effective max_ttl of "765h8m44s"; TTL value is capped accordingly
2020/11/04 04:06:06.750633 [TRACE] (view) vault.read(secret/mysecret) starting fetch
2020/11/04 04:06:06.752394 [TRACE] kv.block(mykey): returned "123"
2020/11/04 04:06:06.752542 [TRACE] (view) kv.block(mykey) marking successful data response
2020/11/04 04:06:06.752660 [TRACE] (view) kv.block(mykey) successful contact, resetting retries
2020/11/04 04:06:06.753292 [TRACE] vault.read(secret/mysecret): GET /v1/secret/data/mysecret
2020/11/04 04:06:06.754572 [TRACE] vault.read(secret/mysecret): non-renewable secret, set sleep for 4m41.002254161s
2020/11/04 04:06:06.754675 [TRACE] (view) vault.read(secret/mysecret) marking successful data response
2020/11/04 04:06:06.754803 [TRACE] (view) vault.read(secret/mysecret) successful contact, resetting retries
2020/11/04 04:06:06.851697 [TRACE] (view) kv.block(mykey) received data
2020/11/04 04:06:06.851794 [TRACE] (view) kv.block(mykey) starting fetch
2020/11/04 04:06:06.851835 [TRACE] kv.block(mykey): GET /v1/kv/mykey?index=247529&stale=true&wait=1m0s
2020/11/04 04:06:06.852029 [DEBUG] (runner) receiving dependency kv.block(mykey)
2020/11/04 04:06:06.852038 [DEBUG] (runner) initiating run
2020/11/04 04:06:06.852042 [DEBUG] (runner) checking template bcaf102ae0995d5b6c74b5a06d739b62
2020/11/04 04:06:06.852382 [DEBUG] (runner) missing data for 1 dependencies
2020/11/04 04:06:06.852393 [DEBUG] (runner) missing dependency: vault.read(secret/mysecret)
2020/11/04 04:06:06.852402 [DEBUG] (runner) missing data for 1 dependencies
2020/11/04 04:06:06.852405 [DEBUG] (runner) diffing and updating dependencies
2020/11/04 04:06:06.852410 [DEBUG] (runner) kv.block(mykey) is still needed
2020/11/04 04:06:06.852413 [DEBUG] (runner) vault.read(secret/mysecret) is still needed
2020/11/04 04:06:06.852418 [DEBUG] (runner) watching 3 dependencies
2020/11/04 04:06:06.870780 [TRACE] (view) vault.read(secret/mysecret) received data
2020/11/04 04:06:06.870920 [DEBUG] (runner) receiving dependency vault.read(secret/mysecret)
2020/11/04 04:06:06.870946 [DEBUG] (runner) initiating run
2020/11/04 04:06:06.870957 [DEBUG] (runner) checking template bcaf102ae0995d5b6c74b5a06d739b62
2020/11/04 04:06:06.871052 [TRACE] (view) vault.read(secret/mysecret) starting fetch
2020/11/04 04:06:06.871529 [DEBUG] (runner) rendering "/tmp/test.ctmpl" => "/tmp/test.out"
> /tmp/test.out
123
{d95a71b9-c6ab-fed5-cc1a-44c2bf2080b4 0 false map[data:map[foo:bar1] metadata:map[created_time:2020-11-04T04:06:00.22861827Z deletion_time: destroyed:false version:5]] [] }
2020/11/04 04:06:06.871618 [INFO] (runner) rendered "/tmp/test.ctmpl" => "/tmp/test.out"
2020/11/04 04:06:06.871627 [DEBUG] (runner) diffing and updating dependencies
2020/11/04 04:06:06.871638 [DEBUG] (runner) kv.block(mykey) is still needed
2020/11/04 04:06:06.871647 [DEBUG] (runner) vault.read(secret/mysecret) is still needed
2020/11/04 04:06:06.871657 [DEBUG] (runner) watching 3 dependencies
2020/11/04 04:06:06.871665 [DEBUG] (runner) all templates rendered
2020/11/04 04:06:19.843032 [TRACE] kv.block(mykey): returned "1234"
2020/11/04 04:06:19.843063 [TRACE] (view) kv.block(mykey) marking successful data response
2020/11/04 04:06:19.843078 [TRACE] (view) kv.block(mykey) successful contact, resetting retries
2020/11/04 04:06:19.843243 [TRACE] (view) kv.block(mykey) received data
2020/11/04 04:06:19.843486 [DEBUG] (runner) receiving dependency kv.block(mykey)
2020/11/04 04:06:19.843515 [DEBUG] (runner) initiating run
2020/11/04 04:06:19.843522 [DEBUG] (runner) checking template bcaf102ae0995d5b6c74b5a06d739b62
2020/11/04 04:06:19.843772 [TRACE] (view) kv.block(mykey) starting fetch
2020/11/04 04:06:19.843916 [DEBUG] (runner) rendering "/tmp/test.ctmpl" => "/tmp/test.out"
> /tmp/test.out
1234
{d95a71b9-c6ab-fed5-cc1a-44c2bf2080b4 0 false map[data:map[foo:bar1] metadata:map[created_time:2020-11-04T04:06:00.22861827Z deletion_time: destroyed:false version:5]] [] }
2020/11/04 04:06:19.843984 [INFO] (runner) rendered "/tmp/test.ctmpl" => "/tmp/test.out"
2020/11/04 04:06:19.843993 [DEBUG] (runner) diffing and updating dependencies
2020/11/04 04:06:19.844002 [DEBUG] (runner) kv.block(mykey) is still needed
2020/11/04 04:06:19.844012 [DEBUG] (runner) vault.read(secret/mysecret) is still needed
2020/11/04 04:06:19.844022 [DEBUG] (runner) watching 3 dependencies
2020/11/04 04:06:19.844030 [DEBUG] (runner) all templates rendered
2020/11/04 04:06:19.844225 [TRACE] kv.block(mykey): GET /v1/kv/mykey?index=247530&stale=true&wait=1m0s
```
### Expected behavior
Secret value should have updated
### Actual behavior
Secret value remained unchanged
### Steps to reproduce
1. Create new Vault secret version for `mysecret` and set to `{"foo":"bar2"}`.
2. Change value of Consul key `mykey` to `1234`.
### Additional info
I'm assuming there's some caching going on here. While the documentation does state:
> Consul Template will not immediately reload in the event a secret is changed as it does with Consul's key-value store.
...it does not make it clear that the secret will not reload even if something else in the template triggers a render. If this is deliberate behavior, can we please get a mechanism for busting the cache.
Contributor guide
Research direction
Start by reproducing the configuration with consul-template v0.25.1, the Consul key, and the Vault secret, using the shown dry-run command and trace output. Compare the secret watcher behavior when the Vault version changes and when the Consul key triggers a render. Done means the intended secret refresh behavior is implemented or clearly documented, with coverage for the reported sequence.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- go
- Domain
- tooling
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100