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.

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

With wait consul-template never starts the program #1043

Closed
iksaif opened this issue Nov 13, 2017 · 8 comments
Closed

With wait consul-template never starts the program #1043

iksaif opened this issue Nov 13, 2017 · 8 comments
Assignees
Milestone

Comments

@iksaif
Copy link

iksaif commented Nov 13, 2017

Consul Template version

0.19.4 (works with 0.19.0)

Configuration

log_level = "debug"

# Keep prometheus up even if consul cluster does not have a leader
max_stale = "24h"

syslog {
  enabled = true
  facility = "LOCAL5"
}

exec {
  reload_signal = "SIGHUP"
  kill_signal = "SIGKILL"
  kill_timeout = "30s"
  # Try to not resart all instances at the same time.
  splay = "60s"
}

# Add wait time before reloading config when multiple files are modified
# Do not put it too high as it could break marathon startup health check.
wait {
  min = "5s"
  max = "10s"
}

template {
  source = "alertmanager.yml.tmpl"
  destination = "alertmanager.yml"
}

template {
  source = "alertmanager.tmpl.tmpl"
  destination = "alertmanager.tmpl"
}
{{$environ := env "ENV"}}
{{$app_id := env "PROMETHEUS_APP_ID"}}
{{$perimeter := env "PROMETHEUS_PERIMETER"}}
{{with (printf "/prometheus/%s/%s/config_%s" $perimeter $app_id $environ)}}
{{if keyExists .}}
# =======================================================================
# Updated from consul KV (key = {{.}}) at {{timestamp}}
# =======================================================================
{{key .}}
{{else}}
# =======================================================================
# Updated from consul KV (key = {{.}}) at {{timestamp}}
# =======================================================================

{{key (printf "/prometheus/%s/%s/config" $perimeter $app_id)}}
{{end}}
{{end}}

Command

../consul-template \
    --config=alertmanager.hcl \
    --exec 'bash -c "echo start; sleep 10; echo stop"'

Debug output

0.19.4

2017/11/13 12:41:20 [DEBUG] (logging) enabling syslog on LOCAL5
2017/11/13 11:41:20.648079 [INFO] consul-template v0.19.4 (68b1da2)
2017/11/13 11:41:20.648114 [INFO] (runner) creating new runner (dry: false, once: false)
2017/11/13 11:41:20.648505 [DEBUG] (runner) final config: {"Consul":{"Address":"consul.query.consul:8500","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":9,"TLSHandshakeTimeout":10000000000}},"Dedup":{"Enabled":false,"MaxStale":2000000000,"Prefix":"consul-template/dedup/","TTL":15000000000},"Exec":{"Command":"bash -c \"echo start; sleep 10; echo stop\"","Enabled":true,"Env":{"Blacklist":[],"Custom":[],"Pristine":false,"Whitelist":[]},"KillSignal":9,"KillTimeout":30000000000,"ReloadSignal":1,"Splay":60000000000,"Timeout":0},"KillSignal":2,"LogLevel":"debug","MaxStale":86400000000000,"PidFile":"","ReloadSignal":1,"Syslog":{"Enabled":true,"Facility":"LOCAL5"},"Templates":[{"Backup":false,"Command":"","CommandTimeout":30000000000,"Contents":"","CreateDestDirs":true,"Destination":"alertmanager.yml","ErrMissingKey":false,"Exec":{"Command":"","Enabled":false,"Env":{"Blacklist":[],"Custom":[],"Pristine":false,"Whitelist":[]},"KillSignal":2,"KillTimeout":30000000000,"ReloadSignal":null,"Splay":0,"Timeout":30000000000},"Perms":0,"Source":"alertmanager.yml.tmpl","Wait":{"Enabled":false,"Min":0,"Max":0},"LeftDelim":"","RightDelim":""},{"Backup":false,"Command":"","CommandTimeout":30000000000,"Contents":"","CreateDestDirs":true,"Destination":"alertmanager.tmpl","ErrMissingKey":false,"Exec":{"Command":"","Enabled":false,"Env":{"Blacklist":[],"Custom":[],"Pristine":false,"Whitelist":[]},"KillSignal":2,"KillTimeout":30000000000,"ReloadSignal":null,"Splay":0,"Timeout":30000000000},"Perms":0,"Source":"alertmanager.tmpl.tmpl","Wait":{"Enabled":false,"Min":0,"Max":0},"LeftDelim":"","RightDelim":""}],"Vault":{"Address":"","Enabled":false,"Grace":15000000000,"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":9,"TLSHandshakeTimeout":10000000000},"UnwrapToken":false},"Wait":{"Enabled":true,"Min":5000000000,"Max":10000000000}}
2017/11/13 11:41:20.648611 [INFO] (runner) creating watcher
2017/11/13 11:41:20.648790 [INFO] (runner) starting
2017/11/13 11:41:20.648892 [DEBUG] (runner) running initial templates
2017/11/13 11:41:20.648917 [INFO] (runner) initiating run
2017/11/13 11:41:20.648953 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:41:20.649656 [DEBUG] (runner) was not watching 2 dependencies
2017/11/13 11:41:20.649703 [DEBUG] (watcher) adding kv.get(prometheus/meta/alertmanager/config_preprod)
2017/11/13 11:41:20.649728 [DEBUG] (watcher) adding kv.block(prometheus/meta/alertmanager/config)
2017/11/13 11:41:20.649753 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:41:20.650114 [DEBUG] (runner) was not watching 1 dependencies
2017/11/13 11:41:20.650157 [DEBUG] (watcher) adding kv.list(prometheus/meta/alertmanager/tmpls)
2017/11/13 11:41:20.650195 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:41:20.650223 [DEBUG] (runner) enabling global quiescence for "84a864c51892f0037def47250012371a"
2017/11/13 11:41:20.650245 [DEBUG] (runner) enabling global quiescence for "43378979410015e279c3f8446de00381"
2017/11/13 11:41:20.650262 [DEBUG] (runner) watching 3 dependencies
2017/11/13 11:41:20.660006 [DEBUG] (runner) receiving dependency kv.list(prometheus/meta/alertmanager/tmpls)
2017/11/13 11:41:20.660044 [INFO] (runner) initiating run
2017/11/13 11:41:20.660060 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:41:20.660312 [DEBUG] (runner) missing data for 2 dependencies
2017/11/13 11:41:20.660327 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:41:20.660469 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:41:20.660484 [DEBUG] (runner) kv.get(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:20.660496 [DEBUG] (runner) kv.block(prometheus/meta/alertmanager/config) is still needed
2017/11/13 11:41:20.660504 [DEBUG] (runner) kv.list(prometheus/meta/alertmanager/tmpls) is still needed
2017/11/13 11:41:20.660525 [DEBUG] (runner) watching 3 dependencies
2017/11/13 11:41:20.661076 [DEBUG] (runner) receiving dependency kv.get(prometheus/meta/alertmanager/config_preprod)
2017/11/13 11:41:20.661092 [INFO] (runner) initiating run
2017/11/13 11:41:20.661103 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:41:20.661311 [DEBUG] (runner) was not watching 1 dependencies
2017/11/13 11:41:20.661326 [DEBUG] (watcher) adding kv.block(prometheus/meta/alertmanager/config_preprod)
2017/11/13 11:41:20.661339 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:41:20.661468 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:41:20.661483 [DEBUG] (runner) kv.get(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:20.661492 [DEBUG] (runner) kv.block(prometheus/meta/alertmanager/config) is no longer needed
2017/11/13 11:41:20.661502 [DEBUG] (watcher) removing kv.block(prometheus/meta/alertmanager/config)
2017/11/13 11:41:20.661528 [DEBUG] (runner) kv.list(prometheus/meta/alertmanager/tmpls) is still needed
2017/11/13 11:41:20.661541 [DEBUG] (runner) watching 3 dependencies
2017/11/13 11:41:20.669626 [DEBUG] (runner) receiving dependency kv.block(prometheus/meta/alertmanager/config_preprod)
2017/11/13 11:41:20.669659 [INFO] (runner) initiating run
2017/11/13 11:41:20.669671 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:41:20.670006 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:41:20.670207 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:41:20.670228 [DEBUG] (runner) kv.get(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:20.670242 [DEBUG] (runner) kv.block(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:20.670254 [DEBUG] (runner) kv.list(prometheus/meta/alertmanager/tmpls) is still needed
2017/11/13 11:41:20.670268 [DEBUG] (runner) watching 3 dependencies
2017/11/13 11:41:25.670178 [DEBUG] (runner) received template "84a864c51892f0037def47250012371a" from quiescence
2017/11/13 11:41:25.670241 [INFO] (runner) initiating run
2017/11/13 11:41:25.670263 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:41:25.670709 [DEBUG] (runner) rendering "alertmanager.yml.tmpl" => "alertmanager.yml"
2017/11/13 11:41:25.673310 [INFO] (runner) rendered "alertmanager.yml.tmpl" => "alertmanager.yml"
2017/11/13 11:41:25.673346 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:41:25.673664 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:41:25.673703 [DEBUG] (runner) kv.get(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:25.673722 [DEBUG] (runner) kv.block(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:25.673742 [DEBUG] (runner) kv.list(prometheus/meta/alertmanager/tmpls) is still needed
2017/11/13 11:41:25.673761 [DEBUG] (runner) enabling global quiescence for "84a864c51892f0037def47250012371a"
2017/11/13 11:41:25.673779 [DEBUG] (runner) watching 3 dependencies
2017/11/13 11:41:25.673803 [DEBUG] (runner) received template "43378979410015e279c3f8446de00381" from quiescence
2017/11/13 11:41:25.673822 [INFO] (runner) initiating run
2017/11/13 11:41:25.673835 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:41:25.674212 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:41:25.675701 [DEBUG] (runner) rendering "alertmanager.tmpl.tmpl" => "alertmanager.tmpl"
2017/11/13 11:41:25.678367 [INFO] (runner) rendered "alertmanager.tmpl.tmpl" => "alertmanager.tmpl"
2017/11/13 11:41:25.678430 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:41:25.678465 [DEBUG] (runner) kv.get(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:25.678540 [DEBUG] (runner) kv.block(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:25.678573 [DEBUG] (runner) kv.list(prometheus/meta/alertmanager/tmpls) is still needed
2017/11/13 11:41:25.678596 [DEBUG] (runner) enabling global quiescence for "43378979410015e279c3f8446de00381"
2017/11/13 11:41:25.678614 [DEBUG] (runner) watching 3 dependencies
2017/11/13 11:41:30.674317 [DEBUG] (runner) received template "84a864c51892f0037def47250012371a" from quiescence
2017/11/13 11:41:30.674376 [INFO] (runner) initiating run
2017/11/13 11:41:30.674392 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:41:30.674839 [DEBUG] (runner) rendering "alertmanager.yml.tmpl" => "alertmanager.yml"
2017/11/13 11:41:30.677604 [INFO] (runner) rendered "alertmanager.yml.tmpl" => "alertmanager.yml"
2017/11/13 11:41:30.677668 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:41:30.678116 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:41:30.678158 [DEBUG] (runner) kv.get(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:30.678186 [DEBUG] (runner) kv.block(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:30.678212 [DEBUG] (runner) kv.list(prometheus/meta/alertmanager/tmpls) is still needed
2017/11/13 11:41:30.678249 [DEBUG] (runner) enabling global quiescence for "84a864c51892f0037def47250012371a"
2017/11/13 11:41:30.678272 [DEBUG] (runner) watching 3 dependencies
2017/11/13 11:41:35.678223 [DEBUG] (runner) received template "43378979410015e279c3f8446de00381" from quiescence
2017/11/13 11:41:35.678299 [INFO] (runner) initiating run
2017/11/13 11:41:35.678334 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:41:35.679304 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:41:35.679935 [DEBUG] (runner) rendering "alertmanager.tmpl.tmpl" => "alertmanager.tmpl"
2017/11/13 11:41:35.682764 [INFO] (runner) rendered "alertmanager.tmpl.tmpl" => "alertmanager.tmpl"
2017/11/13 11:41:35.682823 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:41:35.682859 [DEBUG] (runner) kv.get(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:35.682887 [DEBUG] (runner) kv.block(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:35.682916 [DEBUG] (runner) kv.list(prometheus/meta/alertmanager/tmpls) is still needed
2017/11/13 11:41:35.682947 [DEBUG] (runner) enabling global quiescence for "43378979410015e279c3f8446de00381"
2017/11/13 11:41:35.682983 [DEBUG] (runner) watching 3 dependencies
2017/11/13 11:41:40.679490 [DEBUG] (runner) received template "84a864c51892f0037def47250012371a" from quiescence
2017/11/13 11:41:40.679673 [INFO] (runner) initiating run
2017/11/13 11:41:40.679733 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:41:40.680493 [DEBUG] (runner) rendering "alertmanager.yml.tmpl" => "alertmanager.yml"
2017/11/13 11:41:40.683508 [INFO] (runner) rendered "alertmanager.yml.tmpl" => "alertmanager.yml"
2017/11/13 11:41:40.683605 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:41:40.684243 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:41:40.684311 [DEBUG] (runner) kv.get(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:40.684352 [DEBUG] (runner) kv.block(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:40.684381 [DEBUG] (runner) kv.list(prometheus/meta/alertmanager/tmpls) is still needed
2017/11/13 11:41:40.684412 [DEBUG] (runner) enabling global quiescence for "84a864c51892f0037def47250012371a"
2017/11/13 11:41:40.684447 [DEBUG] (runner) watching 3 dependencies
2017/11/13 11:41:45.684355 [DEBUG] (runner) received template "43378979410015e279c3f8446de00381" from quiescence
2017/11/13 11:41:45.684435 [INFO] (runner) initiating run
2017/11/13 11:41:45.684461 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:41:45.685085 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:41:45.685453 [DEBUG] (runner) rendering "alertmanager.tmpl.tmpl" => "alertmanager.tmpl"
2017/11/13 11:41:45.688873 [INFO] (runner) rendered "alertmanager.tmpl.tmpl" => "alertmanager.tmpl"
2017/11/13 11:41:45.688920 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:41:45.688949 [DEBUG] (runner) kv.get(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:45.688974 [DEBUG] (runner) kv.block(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:41:45.688994 [DEBUG] (runner) kv.list(prometheus/meta/alertmanager/tmpls) is still needed
2017/11/13 11:41:45.689011 [DEBUG] (runner) enabling global quiescence for "43378979410015e279c3f8446de00381"
2017/11/13 11:41:45.689029 [DEBUG] (runner) watching 3 dependencies

0.19.0

$ sh test.sh 
2017/11/13 12:40:43 [DEBUG] (logging) enabling syslog on LOCAL5
2017/11/13 11:40:43.381627 [INFO] consul-template v0.19.0 (33b34b3)
2017/11/13 11:40:43.381669 [INFO] (runner) creating new runner (dry: false, once: false)
2017/11/13 11:40:43.382001 [DEBUG] (runner) final config: {"Consul":{"Address":"consul.query.consul:8500","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":9,"TLSHandshakeTimeout":10000000000}},"Dedup":{"Enabled":false,"MaxStale":2000000000,"Prefix":"consul-template/dedup/","TTL":15000000000},"Exec":{"Command":"bash -c \"echo start; sleep 10; echo stop\"","Enabled":true,"Env":{"Blacklist":[],"Custom":[],"Pristine":false,"Whitelist":[]},"KillSignal":9,"KillTimeout":30000000000,"ReloadSignal":1,"Splay":60000000000,"Timeout":0},"KillSignal":2,"LogLevel":"debug","MaxStale":86400000000000,"PidFile":"","ReloadSignal":1,"Syslog":{"Enabled":true,"Facility":"LOCAL5"},"Templates":[{"Backup":false,"Command":"","CommandTimeout":30000000000,"Contents":"","Destination":"alertmanager.yml","Exec":{"Command":"","Enabled":false,"Env":{"Blacklist":[],"Custom":[],"Pristine":false,"Whitelist":[]},"KillSignal":2,"KillTimeout":30000000000,"ReloadSignal":null,"Splay":0,"Timeout":30000000000},"Perms":420,"Source":"alertmanager.yml.tmpl","Wait":{"Enabled":false,"Min":0,"Max":0},"LeftDelim":"","RightDelim":""},{"Backup":false,"Command":"","CommandTimeout":30000000000,"Contents":"","Destination":"alertmanager.tmpl","Exec":{"Command":"","Enabled":false,"Env":{"Blacklist":[],"Custom":[],"Pristine":false,"Whitelist":[]},"KillSignal":2,"KillTimeout":30000000000,"ReloadSignal":null,"Splay":0,"Timeout":30000000000},"Perms":420,"Source":"alertmanager.tmpl.tmpl","Wait":{"Enabled":false,"Min":0,"Max":0},"LeftDelim":"","RightDelim":""}],"Vault":{"Address":"","Enabled":false,"Grace":15000000000,"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":9,"TLSHandshakeTimeout":10000000000},"UnwrapToken":false},"Wait":{"Enabled":true,"Min":5000000000,"Max":10000000000}}
2017/11/13 11:40:43.382066 [INFO] (runner) creating watcher
2017/11/13 11:40:43.382209 [INFO] (runner) starting
2017/11/13 11:40:43.382294 [DEBUG] (runner) running initial templates
2017/11/13 11:40:43.382312 [INFO] (runner) initiating run
2017/11/13 11:40:43.382329 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:40:43.382936 [DEBUG] (runner) was not watching 2 dependencies
2017/11/13 11:40:43.382967 [DEBUG] (watcher) adding kv.get(prometheus/meta/alertmanager/config_preprod)
2017/11/13 11:40:43.382987 [DEBUG] (watcher) adding kv.block(prometheus/meta/alertmanager/config)
2017/11/13 11:40:43.383002 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:40:43.383251 [DEBUG] (runner) was not watching 1 dependencies
2017/11/13 11:40:43.383282 [DEBUG] (watcher) adding kv.list(prometheus/meta/alertmanager/tmpls)
2017/11/13 11:40:43.383305 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:40:43.383318 [DEBUG] (runner) enabling global quiescence for "84a864c51892f0037def47250012371a"
2017/11/13 11:40:43.383331 [DEBUG] (runner) enabling global quiescence for "43378979410015e279c3f8446de00381"
2017/11/13 11:40:43.383346 [DEBUG] (runner) watching 3 dependencies
2017/11/13 11:40:43.401609 [DEBUG] (runner) receiving dependency kv.list(prometheus/meta/alertmanager/tmpls)
2017/11/13 11:40:43.401689 [INFO] (runner) initiating run
2017/11/13 11:40:43.401717 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:40:43.402303 [DEBUG] (runner) missing data for 2 dependencies
2017/11/13 11:40:43.402340 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:40:43.402643 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:40:43.402669 [DEBUG] (runner) kv.get(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:40:43.402689 [DEBUG] (runner) kv.block(prometheus/meta/alertmanager/config) is still needed
2017/11/13 11:40:43.402703 [DEBUG] (runner) kv.list(prometheus/meta/alertmanager/tmpls) is still needed
2017/11/13 11:40:43.402720 [DEBUG] (runner) watching 3 dependencies
2017/11/13 11:40:43.407375 [DEBUG] (runner) receiving dependency kv.get(prometheus/meta/alertmanager/config_preprod)
2017/11/13 11:40:43.407395 [INFO] (runner) initiating run
2017/11/13 11:40:43.407407 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:40:43.407689 [DEBUG] (runner) was not watching 1 dependencies
2017/11/13 11:40:43.407714 [DEBUG] (watcher) adding kv.block(prometheus/meta/alertmanager/config_preprod)
2017/11/13 11:40:43.407738 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:40:43.407933 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:40:43.407949 [DEBUG] (runner) kv.get(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:40:43.407958 [DEBUG] (runner) kv.block(prometheus/meta/alertmanager/config) is no longer needed
2017/11/13 11:40:43.407974 [DEBUG] (watcher) removing kv.block(prometheus/meta/alertmanager/config)
2017/11/13 11:40:43.407991 [DEBUG] (runner) kv.list(prometheus/meta/alertmanager/tmpls) is still needed
2017/11/13 11:40:43.408001 [DEBUG] (runner) watching 3 dependencies
2017/11/13 11:40:43.435041 [DEBUG] (runner) receiving dependency kv.block(prometheus/meta/alertmanager/config_preprod)
2017/11/13 11:40:43.435083 [INFO] (runner) initiating run
2017/11/13 11:40:43.435101 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:40:43.435380 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:40:43.435580 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:40:43.435601 [DEBUG] (runner) kv.get(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:40:43.435616 [DEBUG] (runner) kv.block(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:40:43.435631 [DEBUG] (runner) kv.list(prometheus/meta/alertmanager/tmpls) is still needed
2017/11/13 11:40:43.435644 [DEBUG] (runner) watching 3 dependencies
2017/11/13 11:40:48.435474 [DEBUG] (runner) received template "84a864c51892f0037def47250012371a" from quiescence
2017/11/13 11:40:48.435506 [INFO] (runner) initiating run
2017/11/13 11:40:48.435520 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:40:48.435777 [DEBUG] (runner) rendering "alertmanager.yml.tmpl" => "alertmanager.yml"
2017/11/13 11:40:48.438129 [INFO] (runner) rendered "alertmanager.yml.tmpl" => "alertmanager.yml"
2017/11/13 11:40:48.438155 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:40:48.438324 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:40:48.438359 [DEBUG] (runner) kv.list(prometheus/meta/alertmanager/tmpls) is still needed
2017/11/13 11:40:48.438369 [DEBUG] (runner) kv.get(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:40:48.438376 [DEBUG] (runner) kv.block(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:40:48.438385 [DEBUG] (runner) enabling global quiescence for "84a864c51892f0037def47250012371a"
2017/11/13 11:40:48.438395 [DEBUG] (runner) watching 3 dependencies
2017/11/13 11:40:48.438406 [DEBUG] (runner) received template "43378979410015e279c3f8446de00381" from quiescence
2017/11/13 11:40:48.438413 [INFO] (runner) initiating run
2017/11/13 11:40:48.438418 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:40:48.438601 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:40:48.438723 [DEBUG] (runner) rendering "alertmanager.tmpl.tmpl" => "alertmanager.tmpl"
2017/11/13 11:40:48.441157 [INFO] (runner) rendered "alertmanager.tmpl.tmpl" => "alertmanager.tmpl"
2017/11/13 11:40:48.441173 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:40:48.441181 [DEBUG] (runner) kv.list(prometheus/meta/alertmanager/tmpls) is still needed
2017/11/13 11:40:48.441189 [DEBUG] (runner) kv.get(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:40:48.441195 [DEBUG] (runner) kv.block(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:40:48.441204 [DEBUG] (runner) enabling global quiescence for "43378979410015e279c3f8446de00381"
2017/11/13 11:40:48.441215 [DEBUG] (runner) watching 3 dependencies
2017/11/13 11:40:48.441280 [INFO] (child) spawning: bash -c echo start; sleep 10; echo stop
start
2017/11/13 11:40:53.438844 [DEBUG] (runner) received template "84a864c51892f0037def47250012371a" from quiescence
2017/11/13 11:40:53.438973 [INFO] (runner) initiating run
2017/11/13 11:40:53.439020 [DEBUG] (runner) checking template 84a864c51892f0037def47250012371a
2017/11/13 11:40:53.439951 [DEBUG] (runner) rendering "alertmanager.yml.tmpl" => "alertmanager.yml"
2017/11/13 11:40:53.442860 [INFO] (runner) rendered "alertmanager.yml.tmpl" => "alertmanager.yml"
2017/11/13 11:40:53.442942 [DEBUG] (runner) checking template 43378979410015e279c3f8446de00381
2017/11/13 11:40:53.443453 [DEBUG] (runner) diffing and updating dependencies
2017/11/13 11:40:53.443536 [DEBUG] (runner) kv.block(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:40:53.443595 [DEBUG] (runner) kv.list(prometheus/meta/alertmanager/tmpls) is still needed
2017/11/13 11:40:53.443638 [DEBUG] (runner) kv.get(prometheus/meta/alertmanager/config_preprod) is still needed
2017/11/13 11:40:53.443674 [INFO] (child) reloading process
2017/11/13 11:40:53.443723 [DEBUG] (child) waiting 13.55s for random splay
stop
2017/11/13 11:40:58.443405 [DEBUG] (cli) receiving signal "child exited"

Expected behavior

0.19.4 should behave like 0.19.0

Actual behavior

It never starts the command

@niko
Copy link

niko commented Sep 18, 2018

Having the same issue with multiple templates and wait configured via command line flags. It works with just one template, though.

@sodabrew
Copy link

sodabrew commented Nov 2, 2018

I am experiencing the same problem. I have some more information.

If there are multiple templates and the wait state applies to more than one then the program never starts.

The failure applies to consul-template in long-running mode. In -once mode, the program does start.

This works:

template {
  source = "foo"
  destination = "bar"
}

template {
  source = "baz"
  destination = "qux"
}

exec {
  command = "hello-world"
}

This works:

template {
  source = "foo"
  destination = "bar"
  wait = "5s:20s"
}

template {
  source = "baz"
  destination = "qux"
}

exec {
  command = "hello-world"
}

This FAILS:

template {
  source = "foo"
  destination = "bar"
  wait = "5s:20s"
}

template {
  source = "baz"
  destination = "qux"
  wait = "5s:20s"
}

exec {
  command = "hello-world"
}

This FAILS:

template {
  source = "foo"
  destination = "bar"
}

template {
  source = "baz"
  destination = "qux"
}

wait {
  min = "5s"
  max = "20s"
}

exec {
  command = "hello-world"
}

The common thread between those last two scenarios is that the wait states apply to more than one of the templates.

Hope this helps!

sodabrew added a commit to udacity/haproxy-consul that referenced this issue Nov 2, 2018
When consul-template -wait argument is given, the exec command is never
executed. See hashicorp/consul-template#1043
@sodabrew
Copy link

sodabrew commented Nov 2, 2018

I ran this down with git bisect and found the faulty commit is 993739e authored by @sethvargo and the commit message claims to be fixing #991 the PR is #995

I'll go out on a limb that @dadgar's refactor in #988 between 0.19.0 and 0.19.1 needs another set of eyes, as it resulted in bug #991 and fixing that caused this bug, and likely there's some deeper race condition.

Hope this is enough information to debug to a resolution, I'm tapped out for the day in my timezone.

@skyrocknroll
Copy link

We are bitten by this bug.

@sodabrew
Copy link

@pearkes I've debugged this to the point of providing a reproduction case and a suspect commit. Are you able to take it from here to a fix given this information?

@niko
Copy link

niko commented Jan 28, 2019

Any update on this?

@pearkes pearkes added this to the v0.20.0 milestone Feb 6, 2019
@pearkes pearkes self-assigned this Feb 6, 2019
@pearkes
Copy link
Contributor

pearkes commented Feb 7, 2019

@sodabrew appreciate your efforts! Been able to get a failing test written for this in #1174. The fix is quite elusive but working on it.

@pearkes
Copy link
Contributor

pearkes commented Feb 8, 2019

I believe I have a fix in #1174. It is the best I could do with my understanding of the system, but does resolve this behavior and calls exec as expected.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

5 participants