Bug 1794085

Summary:	[fluentd] 3.11 remote syslog message is incomplete/truncated
Product:	OpenShift Container Platform	Reporter:	Victor Hernando <vhernand>
Component:	Logging	Assignee:	Sergey Yedrikov <syedriko>
Status:	CLOSED ERRATA	QA Contact:	Anping Li <anli>
Severity:	medium	Docs Contact:
Priority:	unspecified
Version:	3.11.0	CC:	aos-bugs, bparees, jcantril, syedriko
Target Milestone:	---
Target Release:	3.11.z
Hardware:	x86_64
OS:	Linux
Whiteboard:
Fixed In Version:		Doc Type:	Enhancement
Doc Text:	Feature: Maximum size of syslog messages sent by Fluentd is now configurable, for both the syslog (UDP) and syslog_buffered (TCP) plugins. A new environment variable is now recognized: REMOTE_SYSLOG_MAX_SIZE, which specifies the maximum size of syslog messages, in bytes. Before this enhancement, the maximum message size was hardcoded to be 1024 bytes, which is now the default. Reason: The syslog and syslog_buffered plugins in Fluentd truncated log messages longer then 1024 bytes. Result: Maximum size of syslog messages sent by Fluentd is now configurable.	Story Points:	---
Clone Of:		Environment:
Last Closed:	2020-03-20 00:12:43 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description Victor Hernando 2020-01-22 15:41:57 UTC

Description of problem:
Using REMOTE_SYSLOG feature [1] messages received by syslog server are incomplete/truncated when exceeding 969 characters.
In kibana is shown the entire message.
In order to discard any issue with the rsyslog server config, tested the same long message with "logger" and the messages is received on the rsyslog server end correctly.

[1] https://docs.openshift.com/container-platform/3.11/install_config/aggregate_logging.html#sending-logs-to-external-rsyslog


Version-Release number of selected component (if applicable):
- OpenShift 3.11.157

How reproducible:
- Run any application on OpenShift logging large messages (more than 969 characters).

Steps to Reproduce:
What I did to reproduce:
1. Enable REMOTE_SYSLOG plugin as indicated in: https://docs.openshift.com/container-platform/3.11/install_config/aggregate_logging.html#sending-logs-to-external-rsyslog

2. Deploy a simple http application modifying the default LogFormat in httpd.conf as follows.
LogFormat "%h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" combined

3. Access to the url to print a new access record in the apache pod.
4. Check the entry in Kibana, the output is not truncated.
5. Check the log received by the rsyslog server, the line is truncated.

Actual results:
Message incomplete / truncated when some limit is reached.

Expected results:
Expand the limit or make it configurable.

Additional info:

Comment 6 Anping Li 2020-03-12 15:10:19 UTC

The record sent by fluentd was truncated.

Send by fluentd:
2020-03-12T10:53:15+00:00 ip-172-18-15-226.ec2.internal output_tag: namespace_name=anlitest, container_name=centos-logtest, pod_name=centos-logtest-vm9mq, message=10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0

Send by logger -n 172.30.89.11 -p 514  'xxxxx'

2020-03-12T11:07:02+00:00 ip-10-128-0-1.ec2.internal root: 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 - - [22/Jan/2020:08:57:57 +0000] "GET / HTTP/1.1" 304 - "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.86 Safari/537.36
2020-03-12T11:07:04+00:00 ip-10-128-0-1.ec2.internal root: 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 10.131.0.1 - - [22/Jan/2020:08:57:57 +0000] "GET / HTTP/1.1" 304 - "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.86 Safari/537.36

Comment 7 Sergey Yedrikov 2020-03-13 01:02:59 UTC

Hi Anping,

My apologies, I assumed my commit or PR comment made it to this BZ. I added it as the Doc Text field.

You gotta set REMOTE_SYSLOG_MAX_SIZE env var to the max size in bytes that you want, without it the behavior is as before:

"This fix makes maximum size of syslog messages sent by Fluentd configurable,
for both the syslog (UDP) and syslog_buffered (TCP) plugins.
Previously, the maximum message size was hardcoded to 1024 bytes. This fix
keeps that limit as the default.

A new environment variable is now recognized:

    REMOTE_SYSLOG_MAX_SIZE, which specifies the maximum size of syslog messages, in bytes.
"

Regards,
Sergey.

Comment 8 Anping Li 2020-03-13 10:53:01 UTC

Verified on 3.11.188. the logs weren't trucated when REMOTE_SYSLOG_MAX_SIZE=2048
2020-03-13T06:37:12+00:00 anli311node-2 atomic-openshift-node: I0313 06:37:09.295267   17826 kuberuntime_manager.go:441] Syncing Pod "nodejs-mongodb-example-1-dsk54_install-test(92337ea3-64de-11ea-93b7-fa163e4fb086)": &Pod{ObjectMeta:k8s_io_apimachinery_pkg_apis_meta_v1.ObjectMeta{Name:nodejs-mongodb-example-1-dsk54,GenerateName:nodejs-mongodb-example-1-,Namespace:install-test,SelfLink:/api/v1/namespaces/install-test/pods/nodejs-mongodb-example-1-dsk54,UID:92337ea3-64de-11ea-93b7-fa163e4fb086,ResourceVersion:5167,Generation:0,CreationTimestamp:2020-03-12 23:56:08 -0400 EDT,DeletionTimestamp:<nil>,DeletionGracePeriodSeconds:nil,Labels:map[string]string{deployment: nodejs-mongodb-example-1,deploymentconfig: nodejs-mongodb-example,name: nodejs-mongodb-example,},Annotations:map[string]string{kubernetes.io/config.seen: 2020-03-12T23:56:08.393231042-04:00,kubernetes.io/config.source: api,openshift.io/deployment-config.latest-version: 1,openshift.io/deployment-config.name: nodejs-mongodb-example,openshift.io/deployment.name: nodejs-mongodb-example-1,openshift.io/generated-by: OpenShiftNewApp,openshift.io/scc: restricted,},OwnerReferences:[{v1 ReplicationController nodejs-mongodb-example-1 8fff111d-64de-11ea-93b7-fa163e4fb086 0xc421f05d10 0xc421f05d11}],Finalizers:[],ClusterName:,Initializers:nil,},Spec:PodSpec{Volumes:[{default-token-kc8q7 {nil nil nil nil nil SecretVolumeSource{SecretName:default-token-kc8q7,Items:[],DefaultMode:*420,Optional:nil,} nil nil nil nil nil nil nil nil nil nil nil nil nil nil nil nil nil nil nil nil nil}}],Containers:[{nodejs-mongodb-example docker-registry.default.svc:5000/install-test/nodejs-mongodb-example@sha256:a574cb14989f00c73ddce18b5ce8e11b5ca5b6895a3eeaf74c3d4615994f8b46 [] []  [{ 0 8080 TCP }] [] [{DATABASE_SERVICE_NAME mongodb nil} {MONGODB_USER  EnvVarSource{FieldRef:nil,ResourceFieldRef:nil,ConfigMapKeyRef:nil,SecretKeyRef:&SecretKeySelector{LocalObjectReference:LocalObjectReference{Name:nodejs-mongodb-example,},Key:database-user,Optional:nil,},}} {MONGODB_PASSWORD  &EnvVarSource{Fiel

 10.130.0.1 10.130.0.1 - - [22/Jan/2020:08:57:57 +0000] "GET / HTTP/1.1" 304 - "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.86 Safari/537.36"
infra.log:2020-03-13T06:51:09+00:00 anli311node-2 output_tag: namespace_name=test, container_name=centos-logtest, pod_name=centos-logtest-8ssxx, message=66.131.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.131.66.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 10.130.0.1 - - [22/Jan/2020:08:57:57 +0000] "GET / HTTP/1.1" 304 - "-" "Mozilla/5.0 (X11; Fedora; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.86 Safari/537.36"

Comment 10 errata-xmlrpc 2020-03-20 00:12:43 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-2020:0793