Concat problem on kubernetes with message with \n

[jarduini]

Problem

I'm trying to concatenate a json log that has \n in the message,
this is the original message:
June 22nd 2020, 17:50:13.396 | {"message":"I am a test pod \n second line","uniqueid":"","loops":24040,"ii":1}

but I get 2 lines on Kibana:
June 22nd 2020, 17:50:13.396 | {"message":"I am a test pod
June 22nd 2020, 17:50:13.396 | second line","uniqueid":"","loops":24040,"ii":1}

Steps to replicate

This is the config file:

    <source>
      @type tail
      @id docker-input
      path "/var/log/containers/*.log"
      pos_file "/var/log/es-containers.log.pos"
      refresh_interval 5
      rotate_wait 5
      exclude_path []
      time_format %Y-%m-%dT%H:%M:%S.%N%Z
      tag kubernetes.*
      format json
      keep_time_key true
      read_from_head "true"
      @label @CONCAT
    </source>
    <label @CONCAT>
      <filter kubernetes.**>
        @type concat
        key log
        separator ""
        multiline_end_regexp /\n$/
      </filter>
      <match kubernetes.**>
        @type relabel
        @label @INGRESS
      </match>
    </label>

This is the container to do the test:
cat templat.yml

apiVersion: v1
kind: Template
metadata:
  name: test-template
  annotations:
    description: "For creating test pods"
objects:
- apiVersion: v1
  kind: Pod
  metadata:
    name: ${TEST_POD_NAME}
    namespace: ${TEST_NAMESPACE_NAME}
  spec:
    terminationGracePeriodSeconds: 0
    containers:
    - name: test
      image: centos:7
      command:
      - bash
      - -c
      - |-
        loops=0
        while true; do
          loops=$( expr $loops + 1 )
          for ii in $( seq 1 ${TEST_ITERATIONS} ) ; do
            if [ "${FORMAT}" = json ] ; then
              echo "{\"message\":\"${TEST_POD_MESSAGE}\",\"uniqueid\":\"${UNIQUEID}\",\"loops\":$loops,\"ii\":$ii}"
            else
              echo "${TEST_POD_MESSAGE} $loops $ii"
            fi
          done
          sleep ${TEST_POD_SLEEP_TIME}
        done
parameters:
- description: Namespace name to create pod in
  value: test-template
  name: TEST_NAMESPACE_NAME
- description: name of test pod to create
  value: test
  name: TEST_POD_NAME
- description: message to print
  value: "I am a test pod \n second line"
  name: TEST_POD_MESSAGE
- description: time to sleep between each message in seconds
  value: "1"
  name: TEST_POD_SLEEP_TIME
- description: number of times to print message before sleeping
  value: "1"
  name: TEST_ITERATIONS
- description: format - text or json
  value: "json"
  name: FORMAT
- description: unique id for searching
  value: ""
  name: UNIQUEID
labels:
  test: "true"

Expected Behavior

June 22nd 2020, 17:50:13.396 | {"message":"I am a test pod second line","uniqueid":"","loops":24040,"ii":1}

Your environment

Openshift 3.11
rhel 7.8
fluentd 0.12.43

• plugin version
  fluentd boot log:
  2020-06-22 10:19:56 +0200 [info]: reading config file path="/etc/fluent/fluent.conf"
  2020-06-22 10:19:56 +0200 [info]: starting fluentd-0.12.43 without supervision
  2020-06-22 10:19:57 +0200 [info]: gem 'fluent-mixin-config-placeholders' version '0.4.0'
  2020-06-22 10:19:57 +0200 [info]: gem 'fluent-plugin-docker_metadata_filter' version '0.1.1'
  2020-06-22 10:19:57 +0200 [info]: gem 'fluent-plugin-elasticsearch' version '1.17.2'
  2020-06-22 10:19:57 +0200 [info]: gem 'fluent-plugin-flatten-hash' version '0.4.0'
  2020-06-22 10:19:57 +0200 [info]: gem 'fluent-plugin-kubernetes_metadata_filter' version '1.2.1'
  2020-06-22 10:19:57 +0200 [info]: gem 'fluent-plugin-prometheus' version '0.4.0'
  2020-06-22 10:19:57 +0200 [info]: gem 'fluent-plugin-record-modifier' version '0.6.2'
  2020-06-22 10:19:57 +0200 [info]: gem 'fluent-plugin-remote-syslog' version '1.1'
  2020-06-22 10:19:57 +0200 [info]: gem 'fluent-plugin-rewrite-tag-filter' version '1.5.6'
  2020-06-22 10:19:57 +0200 [info]: gem 'fluent-plugin-secure-forward' version '0.4.5'
  2020-06-22 10:19:57 +0200 [info]: gem 'fluent-plugin-systemd' version '0.0.11'
  2020-06-22 10:19:57 +0200 [info]: gem 'fluent-plugin-viaq_data_model' version '0.0.18'
  2020-06-22 10:19:57 +0200 [info]: gem 'fluentd' version '0.12.43'
  2020-06-22 10:19:57 +0200 [info]: adding filter in @concat pattern="kubernetes." type="concat"
  2020-06-22 10:19:57 +0200 [info]: adding match in @concat pattern="kubernetes." type="relabel"
  2020-06-22 10:19:57 +0200 [info]: adding match in @ingress pattern="journal" type="rewrite_tag_filter"
  2020-06-22 10:19:57 +0200 [info]: adding rewrite_tag_filter rule: rewriterule1 ["CONTAINER_NAME", /^k8s_kibana./, "", "kubernetes.journal.container.kibana"]
  2020-06-22 10:19:57 +0200 [info]: adding rewrite_tag_filter rule: rewriterule2 ["CONTAINER_NAME", /^k8s_[^_]+logging-eventrouter-[^_]+/, "", "kubernetes.journal.container.default.kubernetes-event"]
  2020-06-22 10:19:57 +0200 [info]: adding rewrite_tag_filter rule: rewriterule3 ["CONTAINER_NAME", /^k8s_[^_]+[^_]+default/, "", "kubernetes.journal.container.default"]
  2020-06-22 10:19:57 +0200 [info]: adding rewrite_tag_filter rule: rewriterule4 ["CONTAINER_NAME", /^k8s[^_]+[^_]+kube-(.+)/, "", "kubernetes.journal.container.kube-$1"]
  2020-06-22 10:19:57 +0200 [info]: adding rewrite_tag_filter rule: rewriterule5 ["CONTAINER_NAME", /^k8s[^_]+[^_]+openshift-(.+)/, "", "kubernetes.journal.container.openshift-$1"]
  2020-06-22 10:19:57 +0200 [info]: adding rewrite_tag_filter rule: rewriterule6 ["CONTAINER_NAME", /^k8s[^_]+[^_]+openshift/, "", "kubernetes.journal.container.openshift"]
  2020-06-22 10:19:57 +0200 [info]: adding rewrite_tag_filter rule: rewriterule7 ["CONTAINER_NAME", /^k8s.*fluentd/, "", "kubernetes.journal.container.fluentd"]
  2020-06-22 10:19:57 +0200 [info]: adding rewrite_tag_filter rule: rewriterule8 ["CONTAINER_NAME", /^k8s_/, "", "kubernetes.journal.container"]
  2020-06-22 10:19:57 +0200 [info]: adding rewrite_tag_filter rule: rewriterule9 ["_TRANSPORT", /.+/, "", "journal.system"]
  2020-06-22 10:19:57 +0200 [info]: adding filter in @ingress pattern="kubernetes." type="kubernetes_metadata"
  2020-06-22 10:19:58 +0200 [info]: adding filter in @ingress pattern="kubernetes.journal." type="parse_json_field"
  2020-06-22 10:19:58 +0200 [info]: adding filter in @ingress pattern="kubernetes.var.log.containers." type="parse_json_field"
  2020-06-22 10:19:58 +0200 [info]: adding filter in @ingress pattern="kibana" type="record_transformer"
  2020-06-22 10:19:58 +0200 [info]: adding filter in @ingress pattern="" type="viaq_data_model"
  2020-06-22 10:19:58 +0200 [info]: adding filter in @ingress pattern="" type="record_modifier"
  2020-06-22 10:19:58 +0200 [info]: adding filter in @ingress pattern="" type="elasticsearch_genid_ext"
  2020-06-22 10:19:58 +0200 [info]: adding match in @ingress pattern="mux.** .fluentd" type="relabel"
  2020-06-22 10:19:58 +0200 [info]: adding match in @ingress pattern="" type="rewrite_tag_filter"
  2020-06-22 10:19:58 +0200 [info]: adding rewrite_tag_filter rule: rewriterule1 ["message", /.+/, "", "output_tag"]
  2020-06-22 10:19:58 +0200 [info]: adding rewrite_tag_filter rule: rewriterule2 ["message", /.+/, "!", "output_tag"]
  2020-06-22 10:19:58 +0200 [info]: adding match in @output pattern="retry_es" type="copy"
  2020-06-22 10:19:58 +0200 [debug]: adding store type="elasticsearch"
  2020-06-22 10:19:58 +0200 [warn]: 'block' action stops input process until the buffer full is resolved. Check your pipeline this action is fit or not
  2020-06-22 10:19:58 +0200 [info]: adding match in @output pattern="**" type="copy"
  2020-06-22 10:19:58 +0200 [debug]: adding store type="elasticsearch"
  2020-06-22 10:19:58 +0200 [warn]: 'block' action stops input process until the buffer full is resolved. Check your pipeline this action is fit or not
  2020-06-22 10:19:58 +0200 [info]: adding source type="prometheus"
  2020-06-22 10:19:58 +0200 [info]: adding source type="prometheus_monitor"
  2020-06-22 10:19:58 +0200 [info]: adding source type="prometheus_output_monitor"
  2020-06-22 10:19:58 +0200 [info]: adding source type="systemd"
  2020-06-22 10:19:58 +0200 [info]: adding source type="tail"

[jarduini]

[jarduini]

btw, the message is not always the same, but it has in common the \n

[kenhys]

<filter kubernetes.**>
        @type concat
        key log
        separator ""
        multiline_end_regexp /\n$/
      </filter>

For example, I am a test pod and second line\n will be concatenated to I am a test pod second line as you mention "expected".
I'm not sure intention about templat.yml, but it seems that there is something weird after @label @INGRESS processing.