Uploaded image for project: 'OpenShift Logging'
  1. OpenShift Logging
  2. LOG-3433

message log field disappears after enabling json

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Not a Bug
    • Icon: Undefined Undefined
    • None
    • Logging 5.5.3, Logging 5.5.4, Logging 5.5.5
    • Log Collection
    • False
    • None
    • False
    • Logging
    • NEW
    • Troubleshoot
    • NEW
    • Hide

      1) Create a cluster with RHOL 5.5 version

      $ oc get csv
      NAME                           DISPLAY                            VERSION   REPLACES   PHASE
      cluster-logging.5.5.5          Red Hat OpenShift Logging          5.5.5                Succeeded
      elasticsearch-operator.5.5.5   OpenShift Elasticsearch Operator   5.5.5                Succeeded

       2) Deploy an application that continuously sends logs in JSON like the following:

      '{"level":"info","name":"fred","home":"bedrock"}'  

      3) Deploy CLF instance with parse: json field

       

      apiVersion: "logging.openshift.io/v1"
      kind: ClusterLogForwarder
      metadata:
        name: instance
        namespace: openshift-logging
      spec:
        outputDefaults:
          elasticsearch:
            structuredTypeKey: kubernetes.labels.logFormat
            structuredTypeName: json
        outputs:
        - name: forwarder-test
          type: fluentdForward
          url: tcp://localhost:24224
        pipelines:
          - inputRefs:
              - application
            outputRefs:
              - forwarder-test
            parse: json
       
      

       

      4) Check the bufferfiles in the collector pods (we can see the structured field but the message field is not there):

      @timestamp?#2022-12-15T12:07:06.919327572+00:00?docker??container_id?@9af532840872f3aec6ad0a68551f466782737167979b606e1015609e16ef7140?kubernetes??container_name?rails-postgresql-example?namespace_name?test?pod_name? rails-postgresql-example-1-b2wcg?container_imageٖimage-registry.openshift-image-registry.svc:5000/test/rails-postgresql-example@sha256:56561a1e75f4417973eaab7d67085767e4742274bb6602ed2ae82acf0f11fe88?container_image_idٖimage-registry.openshift-image-registry.svc:5000/test/rails-postgresql-example@sha256:56561a1e75f4417973eaab7d67085767e4742274bb6602ed2ae82acf0f11fe88?pod_id?$416f9119-13e3-43c2-9909-dd266efa90bd?pod_ip?10.129.2.20?host?0worker-2.adricluster.lab.upshift.rdu2.redhat.com?labels??deployment?rails-postgresql-example-1?deploymentconfig?rails-postgresql-example?name?rails-postgresql-example?master_url?https://kubernetes.default.svc?namespace_id?$af6c62a0-93fa-4978-b02b-02e15a6266f3?namespace_labels??kubernetes.io/metadata.name?test? pod-security.kubernetes.io/audit?restricted?(pod-security.kubernetes.io/audit-version?v1.24?pod-security.kubernetes.io/warn?restricted?'pod-security.kubernetes.io/warn-version?v1.24?flat_labels??%deployment=rails-postgresql-example-1?)deploymentconfig=rails-postgresql-example?name=rails-postgresql-example?level?info?hostname?0worker-2.adricluster.lab.upshift.rdu2.redhat.com?pipeline_metadata??collector??ipaddr4?10.0.93.247?inputname?fluent-plugin-systemd?name?fluentd?received_at? 2022-12-15T12:07:06.920019+00:00?version?1.14.6 1.6.0?openshift??sequencȩ?viaq_msg_id?0Yzk5NjVmYWUtNmUwOC00MWE5LWI0YTAtMGU4OTA1MTczZjc4?log_type?application?structured??level?info??i???fred?home?bedrock??c?

       

      Additionally, I did two tests for the internal ES (maybe it would be easier to do the troubleshooting)

      1)  Deploy a CLF without enabling json: parse:

      apiVersion: "logging.openshift.io/v1"
      kind: ClusterLogForwarder
      metadata:
        name: instance
        namespace: openshift-logging
      spec:
        outputDefaults:
          elasticsearch:
            structuredTypeKey: kubernetes.labels.logFormat
            structuredTypeName: json
        outputs:
        - name: forwarder-test
          type: fluentdForward
          url: tcp://localhost:24224
        pipelines:
          - inputRefs:
              - application
            outputRefs:
              - default

      In Kibana we can see that it works as expected (with the message field):

      {
        "_index": "app-000001",
        "_type": "_doc",
        "_id": "N2RiN2YwZjItYjJjMi00NjU1LWJkZjgtM2NmMzY2MzQ1Y2Q3",
        "_version": 1,
        "_score": null,
        "_source": {
          "kubernetes": {
            "container_image_id": "image-registry.openshift-image-registry.svc:5000/test/rails-postgresql-example@sha256:56561a1e75f4417973eaab7d67085767e4742274bb6602ed2ae82acf0f11fe88",
            "container_name": "rails-postgresql-example",
            "namespace_id": "af6c62a0-93fa-4978-b02b-02e15a6266f3",
            "flat_labels": [
              "deployment=rails-postgresql-example-1",
              "deploymentconfig=rails-postgresql-example",
              "name=rails-postgresql-example"
            ],
            "pod_ip": "10.129.2.20",
            "host": "worker-2.adricluster.lab.upshift.rdu2.redhat.com",
            "master_url": "https://kubernetes.default.svc",
            "pod_id": "416f9119-13e3-43c2-9909-dd266efa90bd",
            "namespace_labels": {
              "pod-security.kubernetes.io/warn-version": "v1.24",
              "pod-security.kubernetes.io/audit-version": "v1.24",
              "pod-security.kubernetes.io/audit": "restricted",
              "pod-security.kubernetes.io/warn": "restricted",
              "kubernetes.io/metadata.name": "test"
            },
            "container_image": "image-registry.openshift-image-registry.svc:5000/test/rails-postgresql-example@sha256:56561a1e75f4417973eaab7d67085767e4742274bb6602ed2ae82acf0f11fe88",
            "namespace_name": "test",
            "pod_name": "rails-postgresql-example-1-b2wcg"
          },
          "viaq_msg_id": "N2RiN2YwZjItYjJjMi00NjU1LWJkZjgtM2NmMzY2MzQ1Y2Q3",
          "level": "info",
          "openshift": {
            "sequence": 585
          },
          "message": "{\"level\":\"info\",\"name\":\"fred\",\"home\":\"bedrock\"}",
          "docker": {
            "container_id": "9af532840872f3aec6ad0a68551f466782737167979b606e1015609e16ef7140"
          },
          "hostname": "worker-2.adricluster.lab.upshift.rdu2.redhat.com",
          "log_type": "application",
          "@timestamp": "2022-12-15T12:19:04.434737716+00:00",
          "pipeline_metadata": {
            "collector": {
              "received_at": "2022-12-15T12:19:04.468066+00:00",
              "name": "fluentd",
              "inputname": "fluent-plugin-systemd",
              "version": "1.14.6 1.6.0",
              "ipaddr4": "10.0.93.247"
            }
          }
        },
        "fields": {
          "@timestamp": [
            "2022-12-15T12:19:04.434Z"
          ],
          "pipeline_metadata.collector.received_at": [
            "2022-12-15T12:19:04.468Z"
          ]
        },
        "sort": [
          1671106744434
        ]
      }

       

      2) After that,  I added json: parse field and we see again that message field is not in the log:

      {
        "_index": "app-json-000001",
        "_type": "_doc",
        "_id": "Nzk5MWZhNjAtOTdkMS00YzBlLWI3NjUtNGMzZDE3ZWRhYWEy",
        "_version": 1,
        "_score": null,
        "_source": {
          "kubernetes": {
            "container_image_id": "image-registry.openshift-image-registry.svc:5000/test/rails-postgresql-example@sha256:56561a1e75f4417973eaab7d67085767e4742274bb6602ed2ae82acf0f11fe88",
            "container_name": "rails-postgresql-example",
            "namespace_id": "af6c62a0-93fa-4978-b02b-02e15a6266f3",
            "flat_labels": [
              "deployment=rails-postgresql-example-1",
              "deploymentconfig=rails-postgresql-example",
              "name=rails-postgresql-example"
            ],
            "pod_ip": "10.129.2.20",
            "host": "worker-2.adricluster.lab.upshift.rdu2.redhat.com",
            "master_url": "https://kubernetes.default.svc",
            "pod_id": "416f9119-13e3-43c2-9909-dd266efa90bd",
            "namespace_labels": {
              "pod-security.kubernetes.io/warn-version": "v1.24",
              "pod-security.kubernetes.io/audit-version": "v1.24",
              "pod-security.kubernetes.io/audit": "restricted",
              "pod-security.kubernetes.io/warn": "restricted",
              "kubernetes.io/metadata.name": "test"
            },
            "container_image": "image-registry.openshift-image-registry.svc:5000/test/rails-postgresql-example@sha256:56561a1e75f4417973eaab7d67085767e4742274bb6602ed2ae82acf0f11fe88",
            "namespace_name": "test",
            "pod_name": "rails-postgresql-example-1-b2wcg"
          },
          "viaq_msg_id": "Nzk5MWZhNjAtOTdkMS00YzBlLWI3NjUtNGMzZDE3ZWRhYWEy",
          "level": "info",
          "openshift": {
            "sequence": 115
          },
          "docker": {
            "container_id": "9af532840872f3aec6ad0a68551f466782737167979b606e1015609e16ef7140"
          },
          "hostname": "worker-2.adricluster.lab.upshift.rdu2.redhat.com",
          "log_type": "application",
          "@timestamp": "2022-12-15T12:25:30.224537710+00:00",
          "pipeline_metadata": {
            "collector": {
              "received_at": "2022-12-15T12:25:30.225114+00:00",
              "name": "fluentd",
              "inputname": "fluent-plugin-systemd",
              "version": "1.14.6 1.6.0",
              "ipaddr4": "10.0.93.247"
            }
          },
          "structured": {
            "level": "info",
            "name": "fred",
            "home": "bedrock"
          }
        },
        "fields": {
          "@timestamp": [
            "2022-12-15T12:25:30.224Z"
          ],
          "pipeline_metadata.collector.received_at": [
            "2022-12-15T12:25:30.225Z"
          ]
        },
        "sort": [
          1671107130224
        ]
      }

       

       

       

       

       

       

       

       

       

       

       

       

       

       

       

       

      Show
      1) Create a cluster with RHOL 5.5 version $ oc get csv NAME                           DISPLAY                            VERSION   REPLACES   PHASE cluster-logging.5.5.5          Red Hat OpenShift Logging          5.5.5                Succeeded elasticsearch- operator .5.5.5   OpenShift Elasticsearch Operator   5.5.5                Succeeded  2) Deploy an application that continuously sends logs in JSON like the following: '{ "level" : "info" , "name" : "fred" , "home" : "bedrock" }'   3) Deploy CLF instance with parse: json field   apiVersion: "logging.openshift.io/v1" kind: ClusterLogForwarder metadata:   name: instance   namespace: openshift-logging spec:   outputDefaults:     elasticsearch:       structuredTypeKey: kubernetes.labels.logFormat       structuredTypeName: json   outputs:   - name: forwarder-test     type: fluentdForward     url: tcp: //localhost:24224   pipelines:     - inputRefs:         - application       outputRefs:         - forwarder-test       parse: json     4) Check the bufferfiles in the collector pods (we can see the structured field but the message field is not there): @timestamp?#2022-12-15T12:07:06.919327572+00:00?docker??container_id?@9af532840872f3aec6ad0a68551f466782737167979b606e1015609e16ef7140?kubernetes??container_name?rails-postgresql-example?namespace_name?test?pod_name? rails-postgresql-example-1-b2wcg?container_imageٖimage-registry.openshift-image-registry.svc:5000/test/rails-postgresql-example@sha256:56561a1e75f4417973eaab7d67085767e4742274bb6602ed2ae82acf0f11fe88?container_image_idٖimage-registry.openshift-image-registry.svc:5000/test/rails-postgresql-example@sha256:56561a1e75f4417973eaab7d67085767e4742274bb6602ed2ae82acf0f11fe88?pod_id?$416f9119-13e3-43c2-9909-dd266efa90bd?pod_ip?10.129.2.20?host?0worker-2.adricluster.lab.upshift.rdu2.redhat.com?labels??deployment?rails-postgresql-example-1?deploymentconfig?rails-postgresql-example?name?rails-postgresql-example?master_url?https: //kubernetes. default .svc?namespace_id?$af6c62a0-93fa-4978-b02b-02e15a6266f3?namespace_labels??kubernetes.io/metadata.name?test? pod-security.kubernetes.io/audit?restricted?(pod-security.kubernetes.io/audit-version?v1.24?pod-security.kubernetes.io/warn?restricted?'pod-security.kubernetes.io/warn-version?v1.24?flat_labels??%deployment=rails-postgresql-example-1?)deploymentconfig=rails-postgresql-example?name=rails-postgresql-example?level?info?hostname?0worker-2.adricluster.lab.upshift.rdu2.redhat.com?pipeline_metadata??collector??ipaddr4?10.0.93.247?inputname?fluent-plugin-systemd?name?fluentd?received_at? 2022-12-15T12:07:06.920019+00:00?version?1.14.6 1.6.0?openshift??sequencȩ?viaq_msg_id?0Yzk5NjVmYWUtNmUwOC00MWE5LWI0YTAtMGU4OTA1MTczZjc4?log_type?application?structured??level?info??i???fred?home?bedrock??c?   Additionally, I did two tests for the internal ES (maybe it would be easier to do the troubleshooting) 1)  Deploy a CLF without enabling json: parse: apiVersion: "logging.openshift.io/v1" kind: ClusterLogForwarder metadata:   name: instance   namespace: openshift-logging spec:   outputDefaults:     elasticsearch:       structuredTypeKey: kubernetes.labels.logFormat       structuredTypeName: json   outputs:   - name: forwarder-test     type: fluentdForward     url: tcp: //localhost:24224   pipelines:     - inputRefs:         - application       outputRefs:         - default In Kibana we can see that it works as expected (with the message field): {   "_index" : "app-000001" ,   "_type" : "_doc" ,   "_id" : "N2RiN2YwZjItYjJjMi00NjU1LWJkZjgtM2NmMzY2MzQ1Y2Q3" ,   "_version" : 1,   "_score" : null ,   "_source" : {     "kubernetes" : {       "container_image_id" : "image-registry.openshift-image-registry.svc:5000/test/rails-postgresql-example@sha256:56561a1e75f4417973eaab7d67085767e4742274bb6602ed2ae82acf0f11fe88" ,       "container_name" : "rails-postgresql-example" ,       "namespace_id" : "af6c62a0-93fa-4978-b02b-02e15a6266f3" ,       "flat_labels" : [         "deployment=rails-postgresql-example-1" ,         "deploymentconfig=rails-postgresql-example" ,         "name=rails-postgresql-example"       ],       "pod_ip" : "10.129.2.20" ,       "host" : "worker-2.adricluster.lab.upshift.rdu2.redhat.com" ,       "master_url" : "https: //kubernetes. default .svc" ,       "pod_id" : "416f9119-13e3-43c2-9909-dd266efa90bd" ,       "namespace_labels" : {         "pod-security.kubernetes.io/warn-version" : "v1.24" ,         "pod-security.kubernetes.io/audit-version" : "v1.24" ,         "pod-security.kubernetes.io/audit" : "restricted" ,         "pod-security.kubernetes.io/warn" : "restricted" ,         "kubernetes.io/metadata.name" : "test"       },       "container_image" : "image-registry.openshift-image-registry.svc:5000/test/rails-postgresql-example@sha256:56561a1e75f4417973eaab7d67085767e4742274bb6602ed2ae82acf0f11fe88" ,       "namespace_name" : "test" ,       "pod_name" : "rails-postgresql-example-1-b2wcg"     },     "viaq_msg_id" : "N2RiN2YwZjItYjJjMi00NjU1LWJkZjgtM2NmMzY2MzQ1Y2Q3" ,     "level" : "info" ,     "openshift" : {       "sequence" : 585     },     "message" : "{\" level\ ":\" info\ ",\" name\ ":\" fred\ ",\" home\ ":\" bedrock\ "}" ,     "docker" : {       "container_id" : "9af532840872f3aec6ad0a68551f466782737167979b606e1015609e16ef7140"     },     "hostname" : "worker-2.adricluster.lab.upshift.rdu2.redhat.com" ,     "log_type" : "application" ,     "@timestamp" : "2022-12-15T12:19:04.434737716+00:00" ,     "pipeline_metadata" : {       "collector" : {         "received_at" : "2022-12-15T12:19:04.468066+00:00" ,         "name" : "fluentd" ,         "inputname" : "fluent-plugin-systemd" ,         "version" : "1.14.6 1.6.0" ,         "ipaddr4" : "10.0.93.247"       }     }   },   "fields" : {     "@timestamp" : [       "2022-12-15T12:19:04.434Z"     ],     "pipeline_metadata.collector.received_at" : [       "2022-12-15T12:19:04.468Z"     ]   },   "sort" : [     1671106744434   ] }   2) After that,  I added json: parse field and we see again that message field is not in the log: {   "_index" : "app-json-000001" ,   "_type" : "_doc" ,   "_id" : "Nzk5MWZhNjAtOTdkMS00YzBlLWI3NjUtNGMzZDE3ZWRhYWEy" ,   "_version" : 1,   "_score" : null ,   "_source" : {     "kubernetes" : {       "container_image_id" : "image-registry.openshift-image-registry.svc:5000/test/rails-postgresql-example@sha256:56561a1e75f4417973eaab7d67085767e4742274bb6602ed2ae82acf0f11fe88" ,       "container_name" : "rails-postgresql-example" ,       "namespace_id" : "af6c62a0-93fa-4978-b02b-02e15a6266f3" ,       "flat_labels" : [         "deployment=rails-postgresql-example-1" ,         "deploymentconfig=rails-postgresql-example" ,         "name=rails-postgresql-example"       ],       "pod_ip" : "10.129.2.20" ,       "host" : "worker-2.adricluster.lab.upshift.rdu2.redhat.com" ,       "master_url" : "https: //kubernetes. default .svc" ,       "pod_id" : "416f9119-13e3-43c2-9909-dd266efa90bd" ,       "namespace_labels" : {         "pod-security.kubernetes.io/warn-version" : "v1.24" ,         "pod-security.kubernetes.io/audit-version" : "v1.24" ,         "pod-security.kubernetes.io/audit" : "restricted" ,         "pod-security.kubernetes.io/warn" : "restricted" ,         "kubernetes.io/metadata.name" : "test"       },       "container_image" : "image-registry.openshift-image-registry.svc:5000/test/rails-postgresql-example@sha256:56561a1e75f4417973eaab7d67085767e4742274bb6602ed2ae82acf0f11fe88" ,       "namespace_name" : "test" ,       "pod_name" : "rails-postgresql-example-1-b2wcg"     },     "viaq_msg_id" : "Nzk5MWZhNjAtOTdkMS00YzBlLWI3NjUtNGMzZDE3ZWRhYWEy" ,     "level" : "info" ,     "openshift" : {       "sequence" : 115     },     "docker" : {       "container_id" : "9af532840872f3aec6ad0a68551f466782737167979b606e1015609e16ef7140"     },     "hostname" : "worker-2.adricluster.lab.upshift.rdu2.redhat.com" ,     "log_type" : "application" ,     "@timestamp" : "2022-12-15T12:25:30.224537710+00:00" ,     "pipeline_metadata" : {       "collector" : {         "received_at" : "2022-12-15T12:25:30.225114+00:00" ,         "name" : "fluentd" ,         "inputname" : "fluent-plugin-systemd" ,         "version" : "1.14.6 1.6.0" ,         "ipaddr4" : "10.0.93.247"       }     },     "structured" : {       "level" : "info" ,       "name" : "fred" ,       "home" : "bedrock"     }   },   "fields" : {     "@timestamp" : [       "2022-12-15T12:25:30.224Z"     ],     "pipeline_metadata.collector.received_at" : [       "2022-12-15T12:25:30.225Z"     ]   },   "sort" : [     1671107130224   ] }                                

      OCP 4.11.17

      RHOL 5.5.3 5.5.4 5.5.5

      After enabling JSON (parse: json) the message field inside the logs disappears.

      We can observe structured field but message field doesn´t exist.

       

       

       

      Version-Release number of selected component (if applicable): RHOL 5.5.3, 5.5.4 and 5.5.5

      How reproducible: Always

      Actual results: message field in the logs disappears

      Expected results: have in the logs the fields "message" and "structured"

      Additional info:

       

       

       

            Unassigned Unassigned
            acandelp Adrian Candel
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

              Created:
              Updated:
              Resolved: