Bug 1735511 - Rsyslog couldn't parse json log which has prefix space before the json string when set MERGE_JSON_LOG=true
Summary: Rsyslog couldn't parse json log which has prefix space before the json string...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: OpenShift Container Platform
Classification: Red Hat
Component: Logging
Version: 4.2.0
Hardware: Unspecified
OS: Unspecified
unspecified
medium
Target Milestone: ---
: 4.2.0
Assignee: Rich Megginson
QA Contact: Qiaoling Tang
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-08-01 03:03 UTC by Qiaoling Tang
Modified: 2019-10-16 06:34 UTC (History)
2 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-10-16 06:34:11 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github openshift cluster-logging-operator pull 223 0 None closed Bug 1735511: Rsyslog couldn't parse json log which has prefix space before the json string when set MERGE_JSON_LOG=true 2020-08-27 09:46:26 UTC
Red Hat Product Errata RHBA-2019:2922 0 None None None 2019-10-16 06:34:23 UTC

Description Qiaoling Tang 2019-08-01 03:03:37 UTC
Description of problem:
Set MERGE_JSON_LOG=true in daemonset rsyslog, then generate some json logs, some json logs couldn't be parsed. I checked the `original_raw_message` field, and found there has a space before the first `{`:
{
  "_index": "project.json2.045b2f01-b404-11e9-a38e-0aaf66d2161c.2019.08.01",
  "_type": "com.redhat.viaq.common",
  "_id": "81EE15D0E3C5488F9F52BC253F511CF7",
  "_version": 1,
  "_score": null,
  "_source": {
    "kubernetes": {
      "namespace_id": "045b2f01-b404-11e9-a38e-0aaf66d2161c",
      "creation_timestamp": "2019-08-01T02:28:15Z",
      "pod_id": "0b3fb375-b404-11e9-a589-022d83138dda",
      "labels": {
        "run": "centos-logtest",
        "test": "centos-logtest"
      },
      "host": "ip-10-0-173-53.eu-west-2.compute.internal",
      "pod_name": "centos-logtest-xncpv",
      "namespace_name": "json2",
      "container_name": "centos-logtest",
      "master_url": "https://kubernetes.default.svc.cluster.local:443"
    },
    "@timestamp": "2019-08-01T02:31:11.745173881+00:00",
    "file": "/var/log/containers/centos-logtest-xncpv_json2_centos-logtest-e43f4e5c683a601a4c75857ff8ac209c870229d47f1f69872df65475d3ec364f.log",
    "hostname": "ip-10-0-173-53.eu-west-2.compute.internal",
    "docker": {
      "container_id": "e43f4e5c683a601a4c75857ff8ac209c870229d47f1f69872df65475d3ec364f"
    },
    "pipeline_metadata": {
      "collector": {
        "original_raw_message": " {\"message\":\"MERGE_JSON_LOG=true\",\"level\":\"debug\",\"Layer1\":\"layer1 0\",\"layer2\":{\"name\":\"Layer2 1\",\"tips\":\"decide by PRESERVE_JSON_LOG\"},\"StringNumber\":\"10\",\"Number\":10,\"foo.bar\":\"dotstring\",\"{foobar}\":\"bracestring\",\"[foobar]\":\"bracket string\",\"foo:bar\":\"colonstring\",\"empty1\":\"\",\"empty2\":{}}",
        "name": "rsyslog",
        "inputname": "imfile",
        "received_at": "2019-08-01T02:31:11.745239+00:00",
        "ipaddr4": "10.0.173.53",
        "ipaddr6": "::ffff:10.0.173.53",
        "version": "8.37.0-9.el7 "
      }
    },
    "level": "unknown",
    "offset": "51561",
    "message": " {\"message\":\"MERGE_JSON_LOG=true\",\"level\":\"debug\",\"Layer1\":\"layer1 0\",\"layer2\":{\"name\":\"Layer2 1\",\"tips\":\"decide by PRESERVE_JSON_LOG\"},\"StringNumber\":\"10\",\"Number\":10,\"foo.bar\":\"dotstring\",\"{foobar}\":\"bracestring\",\"[foobar]\":\"bracket string\",\"foo:bar\":\"colonstring\",\"empty1\":\"\",\"empty2\":{}}"
  },
}

In comparison, I create an app to generate json logs than don't have a space before `{`, then the logs could be parsed:
{
  "_index": "project.json1.dc52fa5e-b403-11e9-9a4f-065c1cf38cec.2019.08.01",
  "_type": "com.redhat.viaq.common",
  "_id": "1F4D580B4C224AD4B55D701321AE8C52",
  "_version": 1,
  "_score": null,
  "_source": {
    " Layer1": "layer1 0",
    "@timestamp": "2019-08-01T02:31:11.367404721+00:00",
    "Number": 10,
    "StringNumber": "10",
    "[foobar]": "bracket string",
    "docker": {
      "container_id": "6fd22ca35f084f9030bb8f2a4808b8329b498ff3beee9c69bf71ce495c94dece"
    },
    "file": "/var/log/containers/log4j2-795974998c-7jb79_json1_log4j2-6fd22ca35f084f9030bb8f2a4808b8329b498ff3beee9c69bf71ce495c94dece.log",
    "foo.bar": "dotstring",
    "foo:bar": "colonstring",
    "hostname": "ip-10-0-173-53.eu-west-2.compute.internal",
    "kubernetes": {
      "container_name": "log4j2",
      "creation_timestamp": "2019-08-01T02:27:08Z",
      "host": "ip-10-0-173-53.eu-west-2.compute.internal",
      "labels": {
        "name": "log4j2",
        "pod-template-hash": "795974998c"
      },
      "master_url": "https://kubernetes.default.svc.cluster.local:443",
      "namespace_id": "dc52fa5e-b403-11e9-9a4f-065c1cf38cec",
      "namespace_name": "json1",
      "pod_id": "e784ba99-b403-11e9-a589-022d83138dda",
      "pod_name": "log4j2-795974998c-7jb79"
    },
    "layer2": {
      "name": "Layer2 1",
      "tips": "decide by PRESERVE_JSON_LOG"
    },
    "level": "debug",
    "message": "MERGE_JSON_LOG=true",
    "offset": "37100",
    "pipeline_metadata": {
      "collector": {
        "inputname": "imfile",
        "ipaddr4": "10.0.173.53",
        "ipaddr6": "::ffff:10.0.173.53",
        "name": "rsyslog",
        "original_raw_message": "{\"message\": \"MERGE_JSON_LOG=true\", \"level\": \"debug\",\" Layer1\": \"layer1 0\", \"layer2\": {\"name\":\"Layer2 1\", \"tips\":\"decide by PRESERVE_JSON_LOG\"}, \"StringNumber\":\"10\", \"Number\": 10,\"foo.bar\":\"dotstring\",\"{foobar}\":\"bracestring\",\"[foobar]\":\"bracket string\", \"foo:bar\":\"colonstring\", \"empty1\":\"\", \"empty2\":{}}",
        "received_at": "2019-08-01T02:31:11.367482+00:00",
        "version": "8.37.0-9.el7 "
      }
    },
    "{foobar}": "bracestring"
  },
}

Version-Release number of selected component (if applicable):
ose-logging-rsyslog-v4.2.0-201907311819
ose-cluster-logging-operator-v4.2.0-201907311819


How reproducible:
Always

Steps to Reproduce:
1. Deploy logging using rsyslog as log collector
2. oc set env ds/rsyslog MERGE_JSON_LOG=true
3. generate json logs using template: https://raw.githubusercontent.com/QiaolingTang/scripts-and-files/master/container_json_log_template.json
4. check logs in Kibana

Actual results:


Expected results:
The json logs could be parsed

Additional info:
Tested with fluentd,  this kind of json logs could be parsed.
{
  "_index": "project.json2.045b2f01-b404-11e9-a38e-0aaf66d2161c.2019.08.01",
  "_type": "com.redhat.viaq.common",
  "_id": "ZDI1Y2Y5ZTktMTZkYi00ZDMxLWIxOWYtOTVlMzhiNTZiYjE0",
  "_version": 1,
  "_score": null,
  "_source": {
    "message": "MERGE_JSON_LOG=true",
    "level": "debug",
    "Layer1": "layer1 0",
    "layer2": {
      "name": "Layer2 1",
      "tips": "decide by PRESERVE_JSON_LOG"
    },
    "StringNumber": "10",
    "Number": 10,
    "foo.bar": "dotstring",
    "{foobar}": "bracestring",
    "[foobar]": "bracket string",
    "foo:bar": "colonstring",
    "docker": {
      "container_id": "e43f4e5c683a601a4c75857ff8ac209c870229d47f1f69872df65475d3ec364f"
    },
    "kubernetes": {
      "container_name": "centos-logtest",
      "namespace_name": "json2",
      "pod_name": "centos-logtest-xncpv",
      "container_image": "docker.io/mffiedler/ocp-logtest:latest",
      "container_image_id": "docker.io/mffiedler/ocp-logtest@sha256:8ba8fa7000efcde126803a48b0f6678b200735c71da1ba0d8074941926f430d0",
      "pod_id": "0b3fb375-b404-11e9-a589-022d83138dda",
      "host": "ip-10-0-173-53.eu-west-2.compute.internal",
      "labels": {
        "run": "centos-logtest",
        "test": "centos-logtest"
      },
      "master_url": "https://kubernetes.default.svc",
      "namespace_id": "045b2f01-b404-11e9-a38e-0aaf66d2161c"
    },
    "hostname": "ip-10-0-173-53.eu-west-2.compute.internal",
    "pipeline_metadata": {
      "collector": {
        "ipaddr4": "10.131.0.27",
        "ipaddr6": "fe80::60b2:2eff:feb6:5cbf",
        "inputname": "fluent-plugin-systemd",
        "name": "fluentd",
        "received_at": "2019-08-01T02:54:41.565564+00:00",
        "version": "1.6.2 1.6.0"
      }
    },
    "@timestamp": "2019-08-01T02:54:41.265691+00:00",
    "viaq_msg_id": "ZDI1Y2Y5ZTktMTZkYi00ZDMxLWIxOWYtOTVlMzhiNTZiYjE0"
  },
}

Comment 2 Qiaoling Tang 2019-08-06 06:04:37 UTC
Bug verification blocked by https://bugzilla.redhat.com/show_bug.cgi?id=1737286

Comment 3 Qiaoling Tang 2019-08-07 01:23:45 UTC
Verified with ose-cluster-logging-operator-v4.2.0-201908061819

Comment 4 errata-xmlrpc 2019-10-16 06:34:11 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2019:2922


Note You need to log in before you can comment on or make changes to this bug.