Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

unexpected respawn with user set #1651

Closed
tgross opened this issue Oct 3, 2022 · 2 comments · Fixed by #1652
Closed

unexpected respawn with user set #1651

tgross opened this issue Oct 3, 2022 · 2 comments · Fixed by #1652
Labels
bug vault Related to the Vault integration

Comments

@tgross
Copy link
Member

tgross commented Oct 3, 2022 •
edited
Loading

While debugging hashicorp/nomad#14768 for a Nomad user, I discovered the new user/group fields cause CT to re-render unexpectedly without a content update.

My full reproduction with Nomad is over in hashicorp/nomad#14768 (comment) but tl;dr after I did some "printf debugging" I found we were getting the re-rendered event from CT, and I was able to reproduce with CT standalone without Nomad as well.

Consul Template version

$ consul-template -v
consul-template v0.29.4 (bf05ae5)

Configuration

log_level = "trace"

vault {
  address = "http://127.0.0.1:8200"
  token = "REDACTED"
  renew_token = false
}

template {
  contents = "{{ with secret \"secret/data/example\" }}{{ .Data.data.content }}{{ end }}"
  destination = "/srv/index.html"
  user = "996"
}

exec {
  command = ["busybox", "httpd", "-v", "-f", "-p", "8001", "-h", "/srv"]
}

Debug output

trace logs 
$ sudo consul-template -config ./tmp/ctconf.hcl
2022-10-03T17:18:21.478Z [INFO] consul-template v0.29.4 (bf05ae5)
2022-10-03T17:18:21.478Z [INFO] (runner) creating new runner (dry: false, once: false)
2022-10-03T17:18:21.479Z [DEBUG] (runner) final config: {"Consul":{"Address":"","Namespace":"","Auth":{"Enabled":false,"Username":""},"Retry":{"Attempts":12,"Backoff":250000000,"MaxBackoff":60000000000,"Enabled":true},"SSL":{"CaCert":"","CaPath":"","Cert":"","Enabled":false,"Key":"","ServerName":"","Verify":true},"Token":"","TokenFile":"","Transport":{"CustomDialer":null,"DialKeepAlive":30000000000,"DialTimeout":30000000000,"DisableKeepAlives":false,"IdleConnTimeout":90000000000,"MaxIdleConns":100,"MaxIdleConnsPerHost":2,"TLSHandshakeTimeout":10000000000}},"Dedup":{"Enabled":false,"MaxStale":2000000000,"Prefix":"consul-template/dedup/","TTL":15000000000,"BlockQueryWaitTime":60000000000},"DefaultDelims":{"Left":null,"Right":null},"Exec":{"Command":["busybox","httpd","-v","-f","-p","8001","-h","/srv"],"Enabled":true,"Env":{"Denylist":[],"Custom":[],"Pristine":false,"Allowlist":[]},"KillSignal":2,"KillTimeout":30000000000,"ReloadSignal":null,"Splay":0,"Timeout":0},"KillSignal":2,"LogLevel":"trace","FileLog":{"LogFilePath":"","LogRotateBytes":0,"LogRotateDuration":86400000000000,"LogRotateMaxFiles":0},"MaxStale":2000000000,"PidFile":"","ReloadSignal":1,"Syslog":{"Enabled":false,"Facility":"LOCAL0","Name":"consul-template"},"Templates":[{"Backup":false,"Command":[],"CommandTimeout":30000000000,"Contents":"{{ with secret \"secret/data/example\" }}{{ .Data.data.content }}{{ end }}","CreateDestDirs":true,"Destination":"/srv/index.html","ErrMissingKey":false,"ErrFatal":true,"Exec":{"Command":[],"Enabled":false,"Env":{"Denylist":[],"Custom":[],"Pristine":false,"Allowlist":[]},"KillSignal":2,"KillTimeout":30000000000,"ReloadSignal":null,"Splay":0,"Timeout":30000000000},"Perms":0,"User":"996","Uid":null,"Group":null,"Gid":null,"Source":"","Wait":{"Enabled":false,"Min":0,"Max":0},"LeftDelim":"","RightDelim":"","FunctionDenylist":[],"SandboxPath":""}],"TemplateErrFatal":null,"Vault":{"Address":"http://127.0.0.1:8200","Enabled":true,"Namespace":"","RenewToken":false,"Retry":{"Attempts":12,"Backoff":250000000,"MaxBackoff":60000000000,"Enabled":true},"SSL":{"CaCert":"","CaPath":"","Cert":"","Enabled":true,"Key":"","ServerName":"","Verify":true},"Transport":{"CustomDialer":null,"DialKeepAlive":30000000000,"DialTimeout":30000000000,"DisableKeepAlives":false,"IdleConnTimeout":90000000000,"MaxIdleConns":100,"MaxIdleConnsPerHost":2,"TLSHandshakeTimeout":10000000000},"UnwrapToken":false,"DefaultLeaseDuration":300000000000,"LeaseRenewalThreshold":0.9,"K8SAuthRoleName":"","K8SServiceAccountTokenPath":"/run/secrets/kubernetes.io/serviceaccount/token","K8SServiceAccountToken":"","K8SServiceMountPath":"kubernetes"},"Nomad":{"Address":"","Enabled":false,"Namespace":"","SSL":{"CaCert":"","CaPath":"","Cert":"","Enabled":false,"Key":"","ServerName":"","Verify":true},"AuthUsername":"","AuthPassword":"","Transport":{"CustomDialer":null,"DialKeepAlive":30000000000,"DialTimeout":30000000000,"DisableKeepAlives":false,"IdleConnTimeout":90000000000,"MaxIdleConns":100,"MaxIdleConnsPerHost":2,"TLSHandshakeTimeout":10000000000},"Retry":{"Attempts":12,"Backoff":250000000,"MaxBackoff":60000000000,"Enabled":true}},"Wait":{"Enabled":false,"Min":0,"Max":0},"Once":false,"ParseOnly":false,"BlockQueryWaitTime":60000000000}
2022-10-03T17:18:21.479Z [INFO] (runner) creating watcher
2022-10-03T17:18:21.480Z [INFO] (runner) starting
2022-10-03T17:18:21.480Z [DEBUG] (runner) running initial templates
2022-10-03T17:18:21.480Z [DEBUG] (runner) initiating run
2022-10-03T17:18:21.480Z [DEBUG] (runner) checking template 2e569aea44e206afcaa3a2acdee26619
2022-10-03T17:18:21.481Z [DEBUG] (runner) missing data for 1 dependencies
2022-10-03T17:18:21.481Z [DEBUG] (runner) missing dependency: vault.read(secret/data/example)
2022-10-03T17:18:21.481Z [DEBUG] (runner) add used dependency vault.read(secret/data/example) to missing since isLeader but do not have a watcher
2022-10-03T17:18:21.481Z [DEBUG] (runner) was not watching 1 dependencies
2022-10-03T17:18:21.482Z [DEBUG] (watcher) adding vault.read(secret/data/example)
2022-10-03T17:18:21.482Z [TRACE] (watcher) vault.read(secret/data/example) starting
2022-10-03T17:18:21.482Z [DEBUG] (runner) diffing and updating dependencies
2022-10-03T17:18:21.482Z [DEBUG] (runner) watching 1 dependencies
2022-10-03T17:18:21.482Z [TRACE] (view) vault.read(secret/data/example) starting fetch
2022-10-03T17:18:21.485Z [TRACE] vault.read(secret/data/example): GET /v1/secret/data/example
2022-10-03T17:18:21.486Z [TRACE] vault.read(secret/data/example): non-renewable secret, set sleep for 4m18.302725316s
2022-10-03T17:18:21.486Z [TRACE] (view) vault.read(secret/data/example) marking successful data response
2022-10-03T17:18:21.486Z [TRACE] (view) vault.read(secret/data/example) successful contact, resetting retries
2022-10-03T17:18:21.486Z [TRACE] (view) vault.read(secret/data/example) received data
2022-10-03T17:18:21.486Z [TRACE] (view) vault.read(secret/data/example) starting fetch
2022-10-03T17:18:21.487Z [DEBUG] (runner) receiving dependency vault.read(secret/data/example)
2022-10-03T17:18:21.487Z [DEBUG] (runner) initiating run
2022-10-03T17:18:21.487Z [DEBUG] (runner) checking template 2e569aea44e206afcaa3a2acdee26619
2022-10-03T17:18:21.488Z [DEBUG] (runner) rendering "(dynamic)" => "/srv/index.html"
2022-10-03T17:18:21.488Z [INFO] (runner) rendered "(dynamic)" => "/srv/index.html"
2022-10-03T17:18:21.488Z [DEBUG] (runner) diffing and updating dependencies
2022-10-03T17:18:21.489Z [DEBUG] (runner) vault.read(secret/data/example) is still needed
2022-10-03T17:18:21.489Z [DEBUG] (runner) watching 1 dependencies
2022-10-03T17:18:21.489Z [DEBUG] (runner) all templates rendered
2022-10-03T17:18:21.489Z [TRACE] (runner) acquired child lock for command, spawning
2022-10-03T17:18:21.489Z [INFO] (child) spawning: busybox httpd -v -f -p 8001 -h /srv
[::ffff:127.0.0.1]:58996: response:200

Wait 4m18 for the sleep to expire...

2022-10-03T17:22:39.874Z [TRACE] vault.read(secret/data/example): GET /v1/secret/data/example
2022-10-03T17:22:39.876Z [TRACE] vault.read(secret/data/example): non-renewable secret, set sleep for 4m37.473787744s
2022-10-03T17:22:39.876Z [TRACE] (view) vault.read(secret/data/example) marking successful data response
2022-10-03T17:22:39.876Z [TRACE] (view) vault.read(secret/data/example) successful contact, resetting retries
2022-10-03T17:22:39.876Z [TRACE] (view) vault.read(secret/data/example) received data
2022-10-03T17:22:39.876Z [TRACE] (view) vault.read(secret/data/example) starting fetch
2022-10-03T17:22:39.876Z [DEBUG] (runner) receiving dependency vault.read(secret/data/example)
2022-10-03T17:22:39.877Z [DEBUG] (runner) initiating run
2022-10-03T17:22:39.877Z [DEBUG] (runner) checking template 2e569aea44e206afcaa3a2acdee26619
2022-10-03T17:22:39.878Z [DEBUG] (runner) rendering "(dynamic)" => "/srv/index.html"
2022-10-03T17:22:39.879Z [INFO] (runner) rendered "(dynamic)" => "/srv/index.html"
2022-10-03T17:22:39.879Z [DEBUG] (runner) diffing and updating dependencies
2022-10-03T17:22:39.879Z [DEBUG] (runner) vault.read(secret/data/example) is still needed
2022-10-03T17:22:39.880Z [INFO] (child) restarting process
2022-10-03T17:22:39.881Z [DEBUG] (runner) watching 1 dependencies
2022-10-03T17:22:39.881Z [DEBUG] (runner) all templates rendered
2022-10-03T17:22:39.881Z [TRACE] (runner) acquired child lock for command, spawning

Expected behavior

The template should not re-rendered and the exec'd process should not have respawned.

Actual behavior

The template timestamp was touched and the exec'd process was respawned.

Steps to reproduce

My setup was to run Vault in dev mode. Configure the CLI with VAULT_TOKEN and VAULT_ADDR and write a secret:

$ vault kv put -mount=secret example content='<html>hello, world</html>'
=== Secret Path ===
secret/data/example
...

Using the CT configuration above, if I run that and check the exec'd process, I get the following:

$ curl localhost:8001
<html>hello, world</html>

$ pgrep busybox
24106

$ ls -lah /srv/index.html
-rw-rw-r-- 1 nomad vagrant 25 Oct  3 17:18 /srv/index.html

And then after the sleep expires, the process is respawned and the template is touched:

$ pgrep busybox
24118

$ ls -lah /srv/index.html
-rw-rw-r-- 1 nomad vagrant 25 Oct  3 17:22 /srv/index.html

References
@tgross tgross added the bug label Oct 3, 2022
@tgross tgross mentioned this issue Oct 3, 2022
Closed
@tgross tgross added the vault Related to the Vault integration label Oct 3, 2022
@eikenb
Copy link
Contributor

eikenb commented Oct 3, 2022 •
edited
Loading

Workaround : You should be able to work around this by setting both.

Hey @tgross, thanks for reporting!

After a quick scan of the code it looks like it is triggering the update based on the group. When either user or group are set, it compares both. In the problematic snippet below it compares both (AND) against the guard value but on return it compares either (OR) against the current value of the file.

consul-template/renderer/file_ownership.go

Lines 31 to 41 in bf05ae5

func isChownNeeded(path string, uid, gid int) (bool, error) {
if uid == -1 && gid == -1 {
return false, nil
}
currUid, currGid, err := getFileOwnership(path)
if err != nil {
return false, err
}
return uid != currUid || gid != currGid, nil
}

@eikenb eikenb mentioned this issue Oct 3, 2022
Merged
@eikenb
Copy link
Contributor

eikenb commented Oct 3, 2022

PR up.. #1652

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug vault Related to the Vault integration
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

isChownNeeded bad when only user/group (!both) set hashicorp/consul-template
2 participants
@eikenb @tgross