Nomad json log format includes non json line entries

[idrennanvmware]

Nomad version

Nomad v1.1.5 (117a23d)

Operating system and Environment details

Issue

When using json logging we noticed that the file contains a mix of json and non json entries. This creates some challenges for the log ingestion since we're now mixing formats.

{"@level":"info","@message":"opening fifo","@module":"logmon","@timestamp":"2021-10-20T17:50:49.443423Z","alloc_id":"1b16584d-c5d2-05ba-5e57-075efa073fc8","path":"/opt/nomad/alloc/1b16584d-c5d2-05ba-5e57-075efa073fc8/alloc/logs/.filebeat-task.stderr.fifo","task":"filebeat-task","timestamp":"2021-10-20T17:50:49.443Z"}
2021/10/20 17:50:49.455116 [INFO] (runner) creating new runner (dry: false, once: false)
2021/10/20 17:50:49.455466 [INFO] (runner) creating watcher
2021/10/20 17:50:49.455802 [INFO] (runner) starting
2021/10/20 17:50:49.457910 [INFO] (runner) rendered "(dynamic)" => "/opt/nomad/alloc/1b16584d-c5d2-05ba-5e57-075efa073fc8/journalbeat-task/local/journalbeat.yml"
2021/10/20 17:50:49.459903 [INFO] (runner) rendered "(dynamic)" => "/opt/nomad/alloc/1b16584d-c5d2-05ba-5e57-075efa073fc8/journalbeat-task/local/CA.crt"
2021/10/20 17:50:49.461596 [INFO] (runner) creating new runner (dry: false, once: false)
2021/10/20 17:50:49.461712 [INFO] (runner) creating watcher
2021/10/20 17:50:49.461803 [INFO] (runner) starting
2021/10/20 17:50:49.464847 [INFO] (runner) rendered "(dynamic)" => "/opt/nomad/alloc/1b16584d-c5d2-05ba-5e57-075efa073fc8/filebeat-task/local/filebeat.yml"
{"@level":"info","@message":"created container","@module":"client.driver_mgr.docker","@timestamp":"2021-10-20T17:50:49.560348Z","container_id":"399a73c1c8c485e2936afbc14c3d3b68124176a49c933914f8c2d6604365648f","driver":"docker"}
{"@level":"info","@message":"created container","@module":"client.driver_mgr.docker","@timestamp":"2021-10-20T17:50:49.562312Z","container_id":"bd665c9102941559f8acbd68342e8898dbcb7ec81f0cceb5ce42356459297c00","driver":"docker"}
{"@level":"info","@message":"started container","@module":"client.driver_mgr.docker","@timestamp":"2021-10-20T17:50:50.495645Z","container_id":"bd665c9102941559f8acbd68342e8898dbcb7ec81f0cceb5ce42356459297c00","driver":"docker"}
{"@level":"info","@message":"started container","@module":"client.driver_mgr.docker","@timestamp":"2021-10-20T17:50:50.800054Z","container_id":"399a73c1c8c485e2936afbc14c3d3b68124176a49c933914f8c2d6604365648f","driver":"docker"}
{"@level":"info","@message":"stopped container","@module":"client.driver_mgr.docker","@timestamp":"2021-10-20T17:52:11.979458Z","container_id":"479ba4e9fb5b5b359e81e98cc8da79ab9fc8590039cd640993a33c2f121e5e13","driver":"docker"}
{"@level":"info","@message":"marking allocation for GC","@module":"client.gc","@timestamp":"2021-10-20T17:52:11.993958Z","alloc_id":"923de21c-2c72-b1e7-7f8f-d7fea5494985"}
2021/10/20 17:52:11.995561 [INFO] (runner) stopping
2021/10/20 17:52:11.995897 [INFO] (runner) received finish

Config snippet from agent

log_file   = "/opt/nomad/logs/nomad.json"
log_rotate_max_files       =  5
log_rotate_bytes           =  10000000
log_json = true

log_level = "INFO"

[lgfa29]

Hi @idrennanvmware 👋

Thanks for the report. This has been fixed in #11291 and was previously reported in #11232. That PR was shipped with our latest v1.2.0-beta1 release so you can try it out and see if fixes the problem for you.

[idrennanvmware]

Great - ty! Will try that :)

[github-actions]

I'm going to lock this issue because it has been closed for 120 days ⏳. This helps our maintainers find and focus on the active issues.
If you have found a problem that seems similar to this, please open a new issue and complete the issue template so we can capture all the details necessary to investigate further.