hashicorp / hashicorp/consul-template

Secrets not updating

Open
#1,423 7 comments 3 reactions 0 assignees View on GitHub
enhancement
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

Open the contributing 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

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.