Consul-template: With `wait` consul-template never starts the program

Created on 13 Nov 2017  路  8Comments  路  Source: hashicorp/consul-template

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

needs-investigation

Most helpful comment

I ran this down with git bisect and found the faulty commit is 993739e494005416ed5e506d6358060c2d29f02e 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.

All 8 comments

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

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!

I ran this down with git bisect and found the faulty commit is 993739e494005416ed5e506d6358060c2d29f02e 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.

We are bitten by this bug.

@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?

Any update on this?

@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.

I believe I have a fix in https://github.com/hashicorp/consul-template/pull/1174. It is the best I could do with my understanding of the system, but does resolve this behavior and calls exec as expected.

Was this page helpful?
0 / 5 - 0 ratings