Getting Data In

How to fix Docker container JSON logs from not being formatted correctly?

65pony
Explorer

We are using the latest ta for docker logs, ta-dockerlogs_fileinput. When we look at the data within Splunk, each line of the message is showing up as a different messages. I have attached the sample of the docker containers json.log as well as how they look in the various tools we are looking at; raw data, within Splunk and within the Docker UCP. These are all different visualizations of the same log messages. It looks like a props and transform issue that I hope you guys can help me with.

raw data from /var/lib/docker/containers/*json.log
{"log":"[02:13:03] \u001b[31merror\u001b[39m [core.server.api.services.invoke.proxy.handler] Error: Bad response from service [globalnavbar]\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435148335Z"}
{"log":"    at InvokeError.Error (native)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435153835Z"}
{"log":"    at new InvokeError (/gssp/app/node_modules/remix-common/lib/errors/InvokeError.js:22:89)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435158035Z"}
{"log":"    at /gssp/app/node_modules/remix-server/lib/api/services/invoke.proxy.js:46:31\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435161435Z"}
{"log":"    at process._tickCallback (internal/process/next_tick.js:103:7)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435165035Z"}
{"log":"From previous event:\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435168435Z"}
{"log":"    at /gssp/app/node_modules/remix-server/lib/api/services/invoke.proxy.js:25:75\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435171635Z"}
{"log":"    at tryOnImmediate (timers.js:534:15)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435174835Z"}
{"log":"    at processImmediate [as _immediateCallback] (timers.js:514:5)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435178235Z"}
{"log":"From previous event:\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435182135Z"}
{"log":"    at exports.default (/gssp/app/node_modules/remix-server/lib/api/services/invoke.proxy.js:18:8)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435193035Z"}
{"log":"From previous event:\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435197335Z"}
{"log":"    at exports.default (/gssp/app/node_modules/remix-server/lib/api/services/invoke.proxy.handler.js:46:8)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435200735Z"}
{"log":"    at Layer.handle [as handle_request] (/gssp/app/node_modules/express/lib/router/layer.js:95:5)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435207735Z"}
{"log":"    at next (/gssp/app/node_modules/express/lib/router/route.js:131:13)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435211835Z"}
{"log":"    at Route.dispatch (/gssp/app/node_modules/express/lib/router/route.js:112:3)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435220635Z"}
{"log":"    at Layer.handle [as handle_request] (/gssp/app/node_modules/express/lib/router/layer.js:95:5)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435224135Z"}
{"log":"    at /gssp/app/node_modules/express/lib/router/index.js:277:22\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435227535Z"}
{"log":"    at Function.process_params (/gssp/app/node_modules/express/lib/router/index.js:330:12)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435230635Z"}
{"log":"    at next (/gssp/app/node_modules/express/lib/router/index.js:271:10)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435234135Z"}
{"log":"    at Function.handle (/gssp/app/node_modules/express/lib/router/index.js:176:3)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435241635Z"}
{"log":"    at router (/gssp/app/node_modules/express/lib/router/index.js:46:12)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435245035Z"}
{"log":"    at Layer.handle [as handle_request] (/gssp/app/node_modules/express/lib/router/layer.js:95:5)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435248135Z"}
{"log":"    at trim_prefix (/gssp/app/node_modules/express/lib/router/index.js:312:13)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435251335Z"}
{"log":"    at /gssp/app/node_modules/express/lib/router/index.js:280:7\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435254535Z"}
{"log":"    at Function.process_params (/gssp/app/node_modules/express/lib/router/index.js:330:12)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435262535Z"}
{"log":"    at next (/gssp/app/node_modules/express/lib/router/index.js:271:10)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435266035Z"}
{"log":"    at /gssp/app/node_modules/express/lib/router/index.js:618:15\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435269335Z"}
{"log":"    at next (/gssp/app/node_modules/express/lib/router/index.js:256:14)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435272535Z"}
{"log":"    at Function.handle (/gssp/app/node_modules/express/lib/router/index.js:176:3)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435275835Z"}
{"log":"    at router (/gssp/app/node_modules/express/lib/router/index.js:46:12)\r\n","stream":"stdout","time":"2016-11-03T14:13:03.435279035Z"}

In Splunkalt text

As Seen in Docker UCP

[02:13:03] [31merror[39m [core.server.api.services.invoke.proxy.handler] Error: Bad response from service [globalnavbar]
    at InvokeError.Error (native)
    at new InvokeError (/gssp/app/node_modules/remix-common/lib/errors/InvokeError.js:22:89)
    at /gssp/app/node_modules/remix-server/lib/api/services/invoke.proxy.js:46:31
    at process._tickCallback (internal/process/next_tick.js:103:7)
From previous event:
    at /gssp/app/node_modules/remix-server/lib/api/services/invoke.proxy.js:25:75
    at tryOnImmediate (timers.js:534:15)
    at processImmediate [as _immediateCallback] (timers.js:514:5)
From previous event:
    at exports.default (/gssp/app/node_modules/remix-server/lib/api/services/invoke.proxy.js:18:8)
From previous event:
    at exports.default (/gssp/app/node_modules/remix-server/lib/api/services/invoke.proxy.handler.js:46:8)
    at Layer.handle [as handle_request] (/gssp/app/node_modules/express/lib/router/layer.js:95:5)
    at next (/gssp/app/node_modules/express/lib/router/route.js:131:13)
    at Route.dispatch (/gssp/app/node_modules/express/lib/router/route.js:112:3)
    at Layer.handle [as handle_request] (/gssp/app/node_modules/express/lib/router/layer.js:95:5)
    at /gssp/app/node_modules/express/lib/router/index.js:277:22
    at Function.process_params (/gssp/app/node_modules/express/lib/router/index.js:330:12)
    at next (/gssp/app/node_modules/express/lib/router/index.js:271:10)
    at Function.handle (/gssp/app/node_modules/express/lib/router/index.js:176:3)
    at router (/gssp/app/node_modules/express/lib/router/index.js:46:12)
    at Layer.handle [as handle_request] (/gssp/app/node_modules/express/lib/router/layer.js:95:5)
    at trim_prefix (/gssp/app/node_modules/express/lib/router/index.js:312:13)
    at /gssp/app/node_modules/express/lib/router/index.js:280:7
    at Function.process_params (/gssp/app/node_modules/express/lib/router/index.js:330:12)
    at next (/gssp/app/node_modules/express/lib/router/index.js:271:10)
    at /gssp/app/node_modules/express/lib/router/index.js:618:15
    at next (/gssp/app/node_modules/express/lib/router/index.js:256:14)
    at Function.handle (/gssp/app/node_modules/express/lib/router/index.js:176:3)
    at router (/gssp/app/node_modules/express/lib/router/index.js:46:12)

aaraneta_splunk
Splunk Employee
Splunk Employee

@65pony - Were you able to test out halr9000's solution? Did it work? If yes, please don't forget to resolve this post by clicking on "Accept". If you still need more help, please provide a comment with some feedback. Thanks!

0 Karma

halr9000
Motivator

if you haven't by now (I know this Q is old), be sure you are running Docker 1.13 so that you can take advantage of the latest JSON and RAW modes in our logging driver as detailed in this blog post. One of these modes (depending on whether you care about embedded JSON) should allow you to take better advantage of the processing pipeline and to be able to handle these events.

If you continue to have issues, let us know.

0 Karma
Get Updates on the Splunk Community!

Introducing the 2024 SplunkTrust!

Hello, Splunk Community! We are beyond thrilled to announce our newest group of SplunkTrust members!  The ...

Introducing the 2024 Splunk MVPs!

We are excited to announce the 2024 cohort of the Splunk MVP program. Splunk MVPs are passionate members of ...

Splunk Custom Visualizations App End of Life

The Splunk Custom Visualizations apps End of Life for SimpleXML will reach end of support on Dec 21, 2024, ...