Consul Template WriteToFile changes trace Output

trace.log

consul-template -config ./consul-template.conf
2023-11-28T11:15:24.289Z [INFO] consul-template v0.35.0 (2d2654ff)
2023-11-28T11:15:24.289Z [INFO] (runner) creating new runner (dry: false, once: false)
2023-11-28T11:15:24.290Z [DEBUG] (runner) final config: {"Consul":{"Address":"host.docker.internal:8500","Namespace":"","Auth":{"Enabled":false,"Username":""},"Retry":{"Attempts":0,"Backoff":250000000,"MaxBackoff":60000000000,"Enabled":true},"SSL":{"CaCert":"","CaCertBytes":"","CaPath":"","Cert":"","Enabled":false,"Key":"","ServerName":"","Verify":true},"Token":"","TokenFile":"","Transport":{"CustomDialer":null,"DialKeepAlive":30000000000,"DialTimeout":30000000000,"DisableKeepAlives":false,"IdleConnTimeout":5000000000,"MaxIdleConns":0,"MaxIdleConnsPerHost":100,"TLSHandshakeTimeout":10000000000}},"Dedup":{"Enabled":false,"MaxStale":2000000000,"Prefix":"consul-template/dedup/","TTL":15000000000,"BlockQueryWaitTime":60000000000},"DefaultDelims":{"Left":null,"Right":null},"Exec":{"Command":["exec ./debug.sh"],"Enabled":true,"Env":{"Denylist":[],"Custom":[],"Pristine":false,"Allowlist":[]},"KillSignal":2,"KillTimeout":30000000000,"ReloadSignal":1,"Splay":0,"Timeout":0},"KillSignal":2,"LogLevel":"trace","FileLog":{"LogFilePath":"","LogRotateBytes":0,"LogRotateDuration":86400000000000,"LogRotateMaxFiles":0},"MaxStale":600000000000,"PidFile":"","ReloadSignal":1,"Syslog":{"Enabled":false,"Facility":"LOCAL0","Name":"consul-template"},"Templates":[{"Backup":false,"Command":[],"CommandTimeout":30000000000,"Contents":"","CreateDestDirs":true,"Destination":"out.conf","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":null,"Uid":null,"Group":null,"Gid":null,"Source":"template.tmpl","Wait":{"Enabled":false,"Min":0,"Max":0},"LeftDelim":"","RightDelim":"","FunctionDenylist":[],"SandboxPath":"","MapToEnvironmentVariable":""}],"TemplateErrFatal":null,"Vault":{"Address":"","Enabled":false,"Namespace":"","RenewToken":false,"Retry":{"Attempts":12,"Backoff":250000000,"MaxBackoff":60000000000,"Enabled":true},"SSL":{"CaCert":"","CaCertBytes":"","CaPath":"","Cert":"","Enabled":true,"Key":"","ServerName":"","Verify":true},"Transport":{"CustomDialer":null,"DialKeepAlive":30000000000,"DialTimeout":30000000000,"DisableKeepAlives":false,"IdleConnTimeout":5000000000,"MaxIdleConns":0,"MaxIdleConnsPerHost":100,"TLSHandshakeTimeout":10000000000},"UnwrapToken":false,"ClientUserAgent":null,"DefaultLeaseDuration":300000000000,"LeaseRenewalThreshold":0.9,"K8SAuthRoleName":"","K8SServiceAccountTokenPath":"/run/secrets/kubernetes.io/serviceaccount/token","K8SServiceAccountToken":"","K8SServiceMountPath":"kubernetes"},"Nomad":{"Address":"","Enabled":false,"Namespace":"","SSL":{"CaCert":"","CaCertBytes":"","CaPath":"","Cert":"","Enabled":false,"Key":"","ServerName":"","Verify":true},"AuthUsername":"","AuthPassword":"","Transport":{"CustomDialer":null,"DialKeepAlive":30000000000,"DialTimeout":30000000000,"DisableKeepAlives":false,"IdleConnTimeout":5000000000,"MaxIdleConns":0,"MaxIdleConnsPerHost":100,"TLSHandshakeTimeout":10000000000},"Retry":{"Attempts":12,"Backoff":250000000,"MaxBackoff":60000000000,"Enabled":true}},"Wait":{"Enabled":false,"Min":0,"Max":0},"Once":false,"ParseOnly":false,"BlockQueryWaitTime":60000000000,"ErrOnFailedLookup":false}
2023-11-28T11:15:24.290Z [INFO] (runner) creating watcher
2023-11-28T11:15:24.290Z [INFO] (runner) starting
2023-11-28T11:15:24.290Z [DEBUG] (runner) running initial templates
2023-11-28T11:15:24.290Z [DEBUG] (runner) initiating run
2023-11-28T11:15:24.290Z [DEBUG] (runner) checking template e15dc0f1bb8cb4cd502b46b9f215d538
2023-11-28T11:15:24.290Z [DEBUG] (runner) missing data for 1 dependencies
2023-11-28T11:15:24.290Z [DEBUG] (runner) missing dependency: kv.get(testKeys)
2023-11-28T11:15:24.290Z [DEBUG] (runner) add used dependency kv.get(testKeys) to missing since isLeader but do not have a watcher
2023-11-28T11:15:24.290Z [DEBUG] (runner) was not watching 1 dependencies
2023-11-28T11:15:24.290Z [DEBUG] (watcher) adding kv.get(testKeys)
2023-11-28T11:15:24.290Z [TRACE] (watcher) kv.get(testKeys) starting
2023-11-28T11:15:24.290Z [DEBUG] (runner) diffing and updating dependencies
2023-11-28T11:15:24.290Z [DEBUG] (runner) watching 1 dependencies
2023-11-28T11:15:24.290Z [TRACE] (view) kv.get(testKeys) starting fetch
2023-11-28T11:15:24.290Z [TRACE] kv.get(testKeys): GET /v1/kv/testKeys?stale=true&wait=1m0s
2023-11-28T11:15:24.298Z [TRACE] kv.get(testKeys): returned "{\n    \"testSet\": [\n        {\n            \"staticValue\": \"test1\",\n            \"dynamicValue\": \"value1\"\n        },\n        {\n            \"staticValue\": \"test2\",\n            \"dynamicValue\": \"value2\"\n        }\n    ]\n}"
2023-11-28T11:15:24.298Z [TRACE] (view) kv.get(testKeys) marking successful data response
2023-11-28T11:15:24.298Z [TRACE] (view) kv.get(testKeys) successful contact, resetting retries
2023-11-28T11:15:24.298Z [TRACE] (view) kv.get(testKeys) received data
2023-11-28T11:15:24.298Z [TRACE] (view) kv.get(testKeys) starting fetch
2023-11-28T11:15:24.298Z [TRACE] kv.get(testKeys): GET /v1/kv/testKeys?index=26115&stale=true&wait=1m0s
2023-11-28T11:15:24.298Z [DEBUG] (runner) receiving dependency kv.get(testKeys)
2023-11-28T11:15:24.298Z [DEBUG] (runner) initiating run
2023-11-28T11:15:24.298Z [DEBUG] (runner) checking template e15dc0f1bb8cb4cd502b46b9f215d538
2023-11-28T11:15:24.298Z [DEBUG] (runner) rendering "template.tmpl" => "out.conf"
2023-11-28T11:15:24.299Z [DEBUG] (runner) diffing and updating dependencies
2023-11-28T11:15:24.299Z [DEBUG] (runner) kv.get(testKeys) is still needed
2023-11-28T11:15:24.299Z [DEBUG] (runner) watching 1 dependencies
2023-11-28T11:15:24.299Z [DEBUG] (runner) all templates rendered
2023-11-28T11:15:24.299Z [TRACE] (runner) acquired child lock for command, spawning
2023-11-28T11:15:24.299Z [INFO] (child) spawning: sh -c exec ./debug.sh

-- Manual Change to KV State, create change only in WriteToFileOutput --

2023-11-28T11:15:36.442Z [TRACE] kv.get(testKeys): returned "{\n    \"testSet\": [\n        {\n            \"staticValue\": \"test1\",\n            \"dynamicValue\": \"value11\"\n        },\n        {\n            \"staticValue\": \"test2\",\n            \"dynamicValue\": \"value2\"\n        }\n    ]\n}"
2023-11-28T11:15:36.442Z [TRACE] (view) kv.get(testKeys) marking successful data response
2023-11-28T11:15:36.442Z [TRACE] (view) kv.get(testKeys) successful contact, resetting retries
2023-11-28T11:15:36.442Z [TRACE] (view) kv.get(testKeys) received data
2023-11-28T11:15:36.442Z [TRACE] (view) kv.get(testKeys) starting fetch
2023-11-28T11:15:36.442Z [TRACE] kv.get(testKeys): GET /v1/kv/testKeys?index=26116&stale=true&wait=1m0s
2023-11-28T11:15:36.442Z [DEBUG] (runner) receiving dependency kv.get(testKeys)
2023-11-28T11:15:36.442Z [DEBUG] (runner) initiating run
2023-11-28T11:15:36.442Z [DEBUG] (runner) checking template e15dc0f1bb8cb4cd502b46b9f215d538
2023-11-28T11:15:36.443Z [DEBUG] (runner) rendering "template.tmpl" => "out.conf"
2023-11-28T11:15:36.444Z [DEBUG] (runner) diffing and updating dependencies
2023-11-28T11:15:36.444Z [DEBUG] (runner) kv.get(testKeys) is still needed
2023-11-28T11:15:36.444Z [DEBUG] (runner) watching 1 dependencies
2023-11-28T11:15:36.444Z [DEBUG] (runner) all templates rendered
2023-11-28T11:15:36.444Z [TRACE] (runner) acquired child lock for command, spawning
^C2023-11-28T11:15:41.111Z [DEBUG] (cli) receiving signal "interrupt"
Cleaning up...
2023-11-28T11:15:41.111Z [INFO] (runner) stopping
2023-11-28T11:15:41.111Z [DEBUG] (runner) stopping watcher
2023-11-28T11:15:41.111Z [DEBUG] (watcher) stopping all views
2023-11-28T11:15:41.111Z [TRACE] (watcher) stopping kv.get(testKeys)
2023-11-28T11:15:41.111Z [DEBUG] (runner) stopping child process immediately
2023-11-28T11:15:41.111Z [INFO] (child) stopping process
2023-11-28T11:15:41.111Z [DEBUG] (child) Kill() called but performing immediate shutdown; not waiting for splay.
2023-11-28T11:15:41.111Z [TRACE] (view) kv.get(testKeys) stopping poll (received on view stopCh)