Nested JSON elements in new log format

[osw...@gmail.com]

Hi there,

I'm discovering lnav and I have to say it's an amazing tool. I'm trying now to create some log formats to recognize the heterogeneous file format I'm getting from a Fluent Bit -> Fluentd inside K8s setup we're dealing with.

The log is in JSON format and one of the outputs looks like this:

```json
{"msg":"Received 2 platform services, 2 system services and 2 node services","rawmsg":"Received 2 platform services, 2 system services and 2 node services","timereported":"2018-11-02T17:47:45.067055+00:00","hostname":"node-1","syslogtag":"journal:","inputname":"imjournal","fromhost":"node-1","fromhost-ip":"127.0.0.1","pri":"14","syslogfacility":"1","syslogseverity":"6","timegenerated":"2018-11-02T17:47:45.067055+00:0
0","programname":"journal","protocol-version":"0","structured-data":"-","app-name":"journal","procid":"-","msgid":"-","uuid":null,"$!":{"PRIORITY":"6","_UID":"0","_GID":"0","_SYSTEMD_SLICE":"system.slice","_MACHINE_ID":"b2118a24bf3545ccac1f1e104cddbc8d","_TRANSPORT":"journal","_CAP_EFFECTIVE":"1fffffffff","_COMM":
"dockerd-current","_EXE":"\\/usr\\/bin\\/dockerd-current","_SYSTEMD_CGROUP":"\\/system.slice\\/docker.service","_SYSTEMD_UNIT":"docker.service","_BOOT_ID":"da3b4383430c4fc785f9eb8414c7408e","_HOSTNAME":"vm-0-co
ntroller-0","_CMDLINE":"\\/usr\\/bin\\/dockerd-current --add-runtime docker-runc=\\/usr\\/libexec\\/docker\\/docker-runc-current --default-runtime=docker-runc --authorization-plugin=rhel-push-plugin --exec-opt native.cgroupdriver=systemd --userland-proxy-path=\\/usr\\/libexec\\/docker\\/docker-proxy-current --init
-path=\\/usr\\/libexec\\/docker\\/docker-init-current --seccomp-profile=\\/etc\\/docker\\/seccomp.json --selinux-enabled --log-driver=journald --signature-verification=false --storage-driver overlay2 --bip=10.16.63.1\\/24 --ip-masq=true --mtu=1426 --add-registry registry.access.redhat.com","_PID":"5389","_SELINUX_CONTEXT":"system_u:system_r:container_runtime_t:s0","CONTAINER_ID_FULL":"4346e9e5a4306d500977d6adef748803
904639126454a75098fa82be4573e631","CONTAINER_NAME":"k8s_ncs_ncs-291-78f6dd4f5c-xh6s4_default_f721ee79-de9e-11e8-a5f9-024201000101_0","CONTAINER_TAG":"4346e9e5a430","CONTAINER_ID":"4346e9e5a430","MESSAGE":"Received 2 platform services, 2 system services and 2 node services","_SOURCE_REALTIME_TIMESTAMP":"1541180865066543"}}
```

This corresponds to a journald message routed to rsyslog by using the imjournal plugin. The question is, I already have created a format that recognizes the journald format but when we receive this one above, I'd like to extract some fields form the "$!" element like _SYSTEMD_UNIT and CONTAINER_NAME. For a clearer look of what I'm talkign about, I've posted a pretty version of the same message at the end of the message [1].

Is that possible?

By the way, I was wondering if lnav supports more than one format per file. I mean, having two or more different log formats in the same file. Even if I know this sounds weird, that's exactly the output we're having from this setup.

Thanks.

[1]
{
"msg": "Received 2 platform services, 2 system services and 2 node services",
"rawmsg": "Received 2 platform services, 2 system services and 2 node services",
"timereported": "2018-11-02T17:47:45.067055+00:00",
"hostname": "node-1",
"syslogtag": "journal:",
"inputname": "imjournal",
"fromhost": "node-1",
"fromhost-ip": "127.0.0.1",
"pri": "14",
"syslogfacility": "1",
"syslogseverity": "6",
"timegenerated": "2018-11-02T17:47:45.067055+00:00",
"programname": "journal",
"protocol-version": "0",
"structured-data": "-",
"app-name": "journal",
"procid": "-",
"msgid": "-",
"uuid": null,
"$!": {
"PRIORITY": "6",
"_UID": "0",
"_GID": "0",
"_SYSTEMD_SLICE": "system.slice",
"_MACHINE_ID": "b2118a24bf3545ccac1f1e104cddbc8d",
"_TRANSPORT": "journal",
"_CAP_EFFECTIVE": "1fffffffff",
"_COMM": "dockerd-current",
"_EXE": "\\/usr\\/bin\\/dockerd-current",
"_SYSTEMD_CGROUP": "\\/system.slice\\/docker.service",
"_SYSTEMD_UNIT": "docker.service",
"_BOOT_ID": "da3b4383430c4fc785f9eb8414c7408e",
"_HOSTNAME": "vm-0-controller-0",
"_CMDLINE": "\\/usr\\/bin\\/dockerd-current --add-runtime docker-runc=\\/usr\\/libexec\\/docker\\/docker-runc-current --default-runtime=docker-runc --authorization-plugin=rhel-push-plugin --exec-opt native.cgroupdriver=systemd --userland-proxy-path=\\/usr\\/libexec\\/docker\\/docker-proxy-current --init-path=\\/usr\\/libexec\\/docker\\/docker-init-current --seccomp-profile=\\/etc\\/docker\\/seccomp.json --selinux-enabled --log-driver=journald --signature-verification=false --storage-driver overlay2 --bip=10.16.63.1\\/24 --ip-masq=true --mtu=1426 --add-registry registry.access.redhat.com",
"_PID": "5389",
"_SELINUX_CONTEXT": "system_u:system_r:container_runtime_t:s0",
"CONTAINER_ID_FULL": "4346e9e5a4306d500977d6adef748803904639126454a75098fa82be4573e631",
"CONTAINER_NAME": "k8s_ncs_ncs-291-78f6dd4f5c-xh6s4_default_f721ee79-de9e-11e8-a5f9-024201000101_0",
"CONTAINER_TAG": "4346e9e5a430",
"CONTAINER_ID": "4346e9e5a430",
"MESSAGE": "Received 2 platform services, 2 system services and 2 node services",
"_SOURCE_REALTIME_TIMESTAMP": "1541180865066543"
}
}

[Hector Oswaldo Caballero]

OK, re-reading the documentation, I noticed that., in order to recognize one log format inside another one as it is the case here (journald inside syslog, both JSON),  'module-filed' could be used. So I came with this format:

{
  "test_syslog_journald" : {
    "title" : "syslog_journald Format",
    "description" : "Log format used to recognize K8s logs as gatherd by Fluent Bit/Fluentd.",
    "url" : "http://test.com",
    "json" : true,
    "hide-extra" : true,
    "line-format" : [
      { "field" : "_SOURCE_REALTIME_TIMESTAMP" },
      " ",
      { "field" : "_SYSTEMD_UNIT" },
      " ",
      { "field" : "SYSLOG_IDENTIFIER" },
      " ",
      { "field" : "hostname" },
      " ",
      "[",
      { "field" : "_PID" },
      "] ",
      { "field" : "__level__", "text-transform": "uppercase" },
      " ",
      { "field" : "msg" }
    ],
    "timestamp-field": "timegenerated",
    "timestamp-format": [
      "%6"
    ],
    "module-field" : "programname",
    "level-field" : "syslogseverity",
    "level" : {
      "fatal" : "0|1",
      "critical" : "2",
      "error" : "3",
      "warning" : "4",
      "stats" : "5",
      "info" : "6",
      "debug" : "7"
    },
    "body-field": "msg",
    "value": {
      "_SOURCE_REALTIME_TIMESTAMP" : { "kind": "integer" },
      "_SYSTEMD_UNIT" : { "kind": "string", "identifier" : true },
      "SYSLOG_IDENTIFIER" : { "kind": "string", "identifier" : true },
      "_PID" : { "kind": "integer", "identifier": true },
      "hostname": { "kind": "string", "identifier" : true, "foreign-key": true },
      "syslogseverity": { "kind": "string", "identifier" : true, "foreign-key": true },
      "msg": { "kind": "string" }
    }
  }
}

As seen, I'm using in the shown fields array a mixing of "external" and "internal" fields. I set 'module-field' to 'programname' that it's the field referring to journald as the kind of "sub-format.

Unfortunately, this is not working as the log format is not recognized. I suspect it has to be with the fact the "sub-format" is journald but in JSON form.

I'll continue fiddling with this but any idea/hint is very much welcomed.

Thanks

[Timothy Stack]

I'll take a look, don't worry about fiddling with it, I'm not sure the module

functionality is compatible with json logs right now.

thanks,

tim

--
You received this message because you are subscribed to the Google Groups "lnav" group.
To unsubscribe from this group and stop receiving emails from it, send an email to lnav+uns...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Timothy Stack]

Unfortunately, it looks like module formats are not wired up for JSON logs at

the moment.  I'm in the middle of some other changes, but I'll get to this once

that stuff is done.

sorry for the trouble,

tim

[Hector Oswaldo Caballero]

Thanks for looking at this. For the moment, is there any option to get an "internal" JSON element to show on the line format? 

I've tried with different options like $!.CONTAINER_NAME, $!['CONTAINER_NAME'] and different combinations of quotes and brackets but no luck so far.

Thanks again.

[Timothy Stack]

On Tue, Nov 6, 2018 at 9:39 AM Hector Oswaldo Caballero <osw...@gmail.com> wrote:

Thanks for looking at this. For the moment, is there any option to get an "internal" JSON element to show on the line format? 

I've tried with different options like $!.CONTAINER_NAME, $!['CONTAINER_NAME'] and different combinations of quotes and brackets but no luck so far.

Sorry, lnav uses json-pointer, so I think you'd write something like:

  $!/CONTAINER_NAME

The following test format uses nested JSON:

  https://github.com/tstack/lnav/blob/master/test/formats/nestedjson/format.json

The test logfile for this format is:

  https://github.com/tstack/lnav/blob/master/test/logfile_nested_json.json

tim

[Hector Oswaldo Caballero]

Indeed, that worked!

Thanks a lot and kudos for a great project