Concat problem on kubernetes with message with \n
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"

btw, the message is not always the same, but it has in common the \n
<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.