consul-template logs have inconsistent formatting
- Dominant language
- Go
- Stars
- 17k
- Forks
- 2.1k
- Avg merge
- 1d 9h
- Merged PRs (30d)
- 105
Description
A truly tiny papercut: the template runner we have produces logs that are coming up from consul-template itself, but these don't have the same date format as the logs for the rest of Nomad. So we end up with logs like the following:
```
2020-12-02T16:22:30.246Z [INFO] client.alloc_runner.task_runner.task_hook.logmon.nomad: opening fifo: alloc_id=2f8932c2-f563-5053-5059-49dcaf3fd53b task=sidecar @module=logmon path=/var/nomad/alloc/2f8932c2-f563-5053-5059-49dcaf3fd53b/alloc/logs/.sidecar.stderr.fifo timestamp=2020-12-02T16:22:30.245Z
2020-12-02T16:22:30.248Z [DEBUG] client.alloc_runner.task_runner.task_hook.stats_hook: failed to start stats collection for task with unrecoverable error: alloc_id=2f8932c2-f563-5053-5059-49dcaf3fd53b task=redis error="container stopped"
2020/12/02 16:22:30.249053 [INFO] (runner) creating new runner (dry: false, once: false)
2020/12/02 16:22:30.249243 [DEBUG] (runner) final config: {"Consul":{"Address":"127.0.0.1:8500","Namespace":"","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,"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":"WARN","MaxStale":2000000000,"PidFile":"","ReloadSignal":1,"Syslog":{"Enabled":false,"Facility":"LOCAL0","Name":""},"Templates":[{"Backup":false,"Command":"","CommandTimeout":30000000000,"Contents":"#!/bin/bash\ntrap do_trap SIGTERM SIGINT\n\ndo_trap() {\n echo \"received signal\"\n sleep 20\n}\n\necho \"hello\"\nsleep 600\n","CreateDestDirs":true,"Destination":"/var/nomad/alloc/2f8932c2-f563-5053-5059-49dcaf3fd53b/sidecar/local/script.sh","ErrMissingKey":false,"Exec":{"Command":"","Enabled":false,"Env":{"Denylist":[],"Custom":[],"Pristine":false,"Allowlist":[]},"KillSignal":2,"KillTimeout":30000000000,"ReloadSignal":null,"Splay":0,"Timeout":30000000000},"Perms":420,"Source":"","Wait":{"Enabled":false,"Min":0,"Max":0},"LeftDelim":"{{","RightDelim":"}}","FunctionDenylist":["plugin"],"SandboxPath":"/var/nomad/alloc/2f8932c2-f563-5053-5059-49dcaf3fd53b/sidecar"}],"Vault":{"Address":"","Enabled":false,"Namespace":"","RenewToken":false,"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":false,"Min":0,"Max":0},"Once":false,"BlockQueryWaitTime":60000000000}
2020/12/02 16:22:30.249304 [INFO] (runner) creating watcher
2020/12/02 16:22:30.249359 [INFO] (runner) starting
2020/12/02 16:22:30.249364 [DEBUG] (runner) running initial templates
2020/12/02 16:22:30.249367 [DEBUG] (runner) initiating run
2020/12/02 16:22:30.249370 [DEBUG] (runner) checking template 958a38b8b3fee8cd51690838272740cf
2020/12/02 16:22:30.249497 [DEBUG] (runner) rendering "(dynamic)" => "/var/nomad/alloc/2f8932c2-f563-5053-5059-49dcaf3fd53b/sidecar/local/script.sh"
2020/12/02 16:22:30.249518 [DEBUG] (runner) diffing and updating dependencies
2020/12/02 16:22:30.249523 [DEBUG] (runner) watching 0 dependencies
2020/12/02 16:22:30.249526 [DEBUG] (runner) all templates rendered
2020-12-02T16:22:30.252Z [DEBUG] client.alloc_runner.task_runner.task_hook.stats_hook: failed to start stats collection for task with unrecoverable error: alloc_id=2f8932c2-f563-5053-5059-49dcaf3fd53b task=sidecar error="container stopped"
2020-12-02T16:22:30.258Z [WARN] client.driver_mgr.docker: RemoveImage on non-referenced counted image id: driver=docker image_id=sha256:87856cc39862cec77541d68382e4867d7ccb29a85a17221446c857ddaebca916
2020-12-02T16:22:30.258Z [INFO] client.alloc_runner.task_runner: restarting task: alloc_id=2f8932c2-f563-5053-5059-49dcaf3fd53b task=redis reason="Restart within policy" delay=16.511388318s
```
Contributor guide
No contributing guide indexed for this repository
Research direction
Start by reproducing the shown template-runner logs and compare their timestamps with the surrounding Nomad logs. Trace where consul-template output enters the template runner integration; done means those messages use the same date format as the rest of Nomad logs.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- go
- Domain
- observability-sre
- Issue type
- Bug
- Difficulty
- 3/5
- Estimated time
- 1-2 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100