Windows Service - Log fails to write, due to output handle at /dev/stderr

[pbrooks]

When attempting to install consul-template as a windows service, with a relevant least privilege server user.
Whilst the log file will be created. The output from the log will fail to populate the specified log file.

To best describe this issue, refer to the following commit: ee40636

Investigating the issue, it would appear that the handle becomes /dev/stderr and thus unable to have output piped to.

To debug the issue, logging.go was modified to allow redirection of failed log messages.
I.e if a log message fails to appear, it'll be output to the file consul_template_fallback.log, within the given service user.

A sample scripts/Install-Service.ps1 is provided (run as admin), that will take care of setting up installation of a sample service.

Consul Template version

consul-template v0.35.0

Using latest source to replicate.

Configuration

See test/testdat/sample.conf
Any valid configuration will exhibit the behaviour.

Command

.\scripts\Install-Service.ps1

Debug output

output-log will be empty.

c:\Users\consul-template\consul_template_fallback.log will contain
Error writing to logfile write /dev/stderr: The handle is invalid. [INFO] consul-template v0.35.0 () Error writing to logfile write /dev/stderr: The handle is invalid. [INFO] (runner) creating new runner (dry: false, once: false) Error writing to logfile write /dev/stderr: The handle is invalid. [DEBUG] (runner) final config: {"Consul":{"Address":"","Namespace":"","Auth":{"Enabled":false,"Username":""},"Retry":{"Attempts":12,"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":[],"Enabled":false,"Env":{"Denylist":[],"Custom":[],"Pristine":false,"Allowlist":[]},"KillSignal":2,"KillTimeout":30000000000,"ReloadSignal":null,"Splay":0,"Timeout":0},"KillSignal":2,"LogLevel":"debug","FileLog":{"LogFilePath":"D:\\projects\\consul-template\\src\\tem\\scripts\\..\\logs\\output.log","LogRotateBytes":0,"LogRotateDuration":86400000000000,"LogRotateMaxFiles":0},"MaxStale":2000000000,"PidFile":"","ReloadSignal":1,"Syslog":{"Enabled":false,"Facility":"LOCAL0","Name":"consul-template"},"Templates":[],"TemplateErrFatal":null,"Vault":{"Address":"VAULT_ADDR","Enabled":true,"Namespace":"","RenewToken":true,"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} Error writing to logfile write /dev/stderr: The handle is invalid. [INFO] (runner) creating watcher Error writing to logfile write /dev/stderr: The handle is invalid. [INFO] (runner) starting Error writing to logfile write /dev/stderr: The handle is invalid. [DEBUG] (runner) running initial templates Error writing to logfile write /dev/stderr: The handle is invalid. [DEBUG] (runner) initiating run Error writing to logfile write /dev/stderr: The handle is invalid. [DEBUG] (runner) diffing and updating dependencies Error writing to logfile write /dev/stderr: The handle is invalid. [DEBUG] (runner) watching 0 dependencies Error writing to logfile write /dev/stderr: The handle is invalid. [DEBUG] (runner) all templates rendered

Expected behavior

All logging output should be within the specified log.

[jamesdoran]

I'm also experiencing this issue. If consul template is run from powershell, it writes to both the console and the log file, but we can't do this in a production environment.