Search code examples
javastack-tracedatadoggrok

Datadog grok custom java stack parsing and ordered list fields

I have the following log sample in a grok pipeline in datadog:

2022-05-10 11:26:58 [SEVERE]: Log from eu.myapp
  dev added message - eu.myapp.Controller.<init>
java.lang.NullPointerException
    at eu.myapp.Controller.<init>(Controller.java:48)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:423)

and the following simple parsing rule

log %{_date}%{space}\[%{_status}\]\:%{space}%{data:logger}(\n%{space}%{data:msg}%{space}-%{space}%{data:in})?(\n%{space}%{data:error.msg})?(\n%{space}%{data:error.stack})?

and the attempt to make it nicer by repeating error.stack so each line is added to array

log %{_date}%{space}\[%{_status}\]\:%{space}%{data:logger}(\n%{space}%{data:msg}%{space}-%{space}%{data:in})?(\n%{space}%{data:error.msg})?(\n%{space}%{data:error.stack})?(\n%{space}%{data:error.stack})?(\n%{space}%{data:error.stack})?(\n%{space}%{data:error.stack})?(\n%{space}%{data:error.stack})?(\n%{space}%{data:error.stack})?(\n%{space}%{data:error.stack})?(\n%{space}%{data:error.stack})?(\n%{space}%{data:error.stack})?(\n%{space}%{data:error.stack})

output simple:

{  
  "level": "SEVERE",
  "timestamp": 1652182018000,
  "error": {
    "msg": "java.lang.NullPointerException",
    "stack": "at eu.myapp.Controller.<init>(Controller.java:48)\n        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)\n        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)\n        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)\n        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)"
  },
  "in": "eu.myapp.Controller.<init>",
  "msg": "dev added message",
  "logger": "Log from eu.myapp"
 }

output nicer:

{
  "level": "SEVERE",
  "timestamp": 1652182018000,
  "error": {
    "msg": "java.lang.NullPointerException",
    "stack": [
      "at java.lang.reflect.Constructor.newInstance(Constructor.java:423)",
      "at eu.myapp.Controller.<init>(Controller.java:48)",
      "at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)",
      "at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)",
      "at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)"
    ]
  },
  "in": "eu.myapp.Controller.<init>",
  "msg": "dev added message",
  "logger": "Log from eu.myapp"
}

As you can see the nicer output is more readable but the list is now unordered. Any way to make the error.stack ordered? Or any other tip or trick to parse this scenario better than im doing now.

I must note I have no control over the log file generation or formatting.

Solution

  • The entire stack trace should be inside the error.msg attribute.

    grok parser preview

    So you can update your grok parser to this (You can put back in your status and date helper rules).

    log %{date("yyyy-MM-dd HH:mm:ss"):timestamp}%{space}\[%{word:status}\]\:%{space}%{data:logger}(\n%{space}%{data:msg}%{space}-%{space}%{data:in})?(\n%{data:error.msg})?

    Also I recommend renaming msg to message and error.msg to error.stack. You can see they are listed as a reserved attribute in the docs. This will make it so that the stack trace gets its own pretty UI that's a lot cleaner looking.

    prettified log in explorer

    Also remember to create the message, status, and date remappers in your pipeline so the default values of your log all get updated appropriately.