DEBUG log level is extremely verbose due to quiescence behaviour bug in consul-template

[lattwood]

Nomad version

Nomad v1.7.7
BuildDate 2024-04-16T19:26:43Z
Revision 0f34c85ee63f6472bd2db1e2487611f4b176c70c

Operating system and Environment details

N/A

Issue

A longstanding consul-template issue makes Nomad DEBUG logs extremely verbose as consul-template logs several orders of magnitude more than Nomad.

I wasn't sure if this issue should be filed here or consul-template, but as the bug in consul-template is impacting our use of Nomad, and the bug only becomes problematic with how Nomad is using consul-template, I went with Nomad.

Reproduction steps

• Turn Nomad log level to DEBUG
• Deploy some jobs that have multiple templates reading from consul or Vault
• journalctl --unit nomad.service --since '1 minute ago' | grep runner | grep debug | wc -l

Expected Result

> journalctl --unit nomad.service --since '1 minute ago' | grep runner | grep debug | wc -l
0
> journalctl --unit nomad.service --since '1 minute ago' | wc -l
0

Actual Result

> journalctl --unit nomad.service --since '1 minute ago' | grep runner | grep debug | wc -l
740
> journalctl --unit nomad.service --since '1 minute ago' | wc -l
740

A not small number is output, and the second command's number isn't larger (therefore we know the only thing being logged by Nomad is coming from consul-template).

Nomad Client logs (if appropriate)

Too big to put in the issue, sanitized gist is here: https://gist.github.com/lattwood/8c42d04e4caaf224a72d4a991d6a35b8

[tgross]

Hi @lattwood! Yeah, sorry about that... we use consul-template as a library which was never its original intended use, and that hits all kinds of weird quirks in the logging. I don't have an immediate workaround for you unfortunately, but I'll definitely mark this for roadmapping and see if I can get this particular papercut surfaced.

[lattwood]

So uh, in 4 days...

root@HOSTNAME:~# journalctl --unit nomad --since '4 days ago' > nomad_log
root@HOSTNAME:~# grep -v runner nomad_log > nomad_log_filtered
root@HOSTNAME:~# ls -latrh | grep nomad
-rw-r-----  1 root root 899M Jul  9 13:58 nomad_log
-rw-r-----  1 root root  12M Jul  9 13:59 nomad_log_filtered

pretty bad 😓