Loading...

Type: Bug
Resolution: Done
Priority: Normal
Fix Version/s: Logging 5.9.16
Affects Version/s: Logging 5.9.12, Logging 5.8.19, Logging 6.0.z, Logging 6.1.z, Logging 6.2.z
Component/s: Log Collection
Labels:
- cee.next
- devel_ack+

Activity Type:
Future Sustainability
Blocked:
False
Blocked Reason:

Hide

None

Show
None
Ready:
False
Docs QE Status:
NEW
QE Status:
NEW
Release Note Text:
Before this update, Vector could duplicate a log message when forwarding logs to syslog, leading to redundant data in the output. With this update, the log event is handled correctly and preventing data duplication in output
Release Note Type:
Bug Fix
Intelligence Requested:
Market:

Sprint:
Log Collection - Sprint 269, Log Collection - Sprint 270, Log Collection - Sprint 271, Log Collection - Sprint 272, Log Collection - Sprint 273, Logging - Sprint 274, Logging - Sprint 275, Logging - Sprint 276
Severity:
Important

SFDC Cases Links:
SFDC Cases Open:
SFDC Cases Counter:

Description of problem:

It's observed that Vector after reading a message and configured to log forwarding to syslog, the same and unique message is sent twice to syslog.

Original log as produced by application:

{"log_type":"openshift_audit","event type":"Sign on Success","userName":"XXXXX","event":"LEEF:1.0|redhat|openshift|4.12|authenticate devTime=2025-04-03T07:46:30.621410481-05:00[America/Chicago] devTimeFormat=yyyy-MM-dd HH:mm:ssZ requestClientApplication=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/134.0.0.0 Safari/537.36 requestMethod=GET sourceServiceName=xxx.xxx.xx.xxx src=xxx.xxx.xx.xxx srcPort=8080 dst=xxx.xxx.xx.xxx dstPort=35302 proto=HTTP/1.1 apiUrl=https://server.example.com/resource-server/actuator/health"}

The same message duplicated and received in syslog:

Apr  7 14:45:24 server.example.com vector {"@timestamp":"2025-04-07T14:45:24.699132308Z","event":"LEEF:1.0|redhat|openshift|4.12|Apr  7 15:05:06 server.example.com vector {"@timestamp":"2025-04-07T15:05:06.245293157Z","event":"LEEF:1.0|redhat|openshift|4.12|authenticate devTime=2025-04-03T07:46:30.621410481-05:00[America/Chicago] devTimeFormat=yyyy-MM-dd HH:mm:ssZ requestClientApplication=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/134.0.0.0 Safari/537.36 requestMethod=GET sourceServiceName=xxx.xxx.xx.xxx src=xxx.xxx.xx.xxx srcPort=8080 dst=xxx.xxx.xx.xxx dstPort=35302 proto=HTTP/1.1 apiUrl=https://server.example.com/resource-server/actuator/health","event type":"Sign on Success","file":"/var/log/pods/syslogtest_hello-node-8dd54cb99-5hsbs_7076289c-ca8b-4e99-a7fc-fffe9f1e295e/agnhost/0.log","hostname":"server.example.com","kubernetes":{"annotations":{"k8s.ovn.org/pod-networks":"{\"default\":{\"ip_addresses\":[\"10.128.2.92/23\"],\"mac_address\":\"0a:58:0a:80:02:5c\",\"gateway_ips\":[\"10.128.2.1\"],\"routes\":[{\"dest\":\"10.128.0.0/14\",\"nextHop\":\"10.128.2.1\"},{\"dest\":\"172.30.0.0/16\",\"nextHop\":\"10.128.2.1\"},{\"dest\":\"169.254.169.5/32\",\"nextHop\":\"10.128.2.1\"},{\"dest\":\"100.64.0.0/16\",\"nextHop\":\"10.128.2.1\"}],\"ip_address\":\"10.128.2.92/23\",\"gateway_ip\":\"10.128.2.1\"}}","k8s.v1.cni.cncf.io/network-status":"[{\n    \"name\": \"ovn-kubernetes\",\n    \"interface\": \"eth0\",\n    \"ips\": [\n        \"10.128.2.92\"\n    ],\n    \"mac\": \"0a:58:0a:80:02:5c\",\n    \"default\": true,\n    \"dns\": {}\n}]","openshift.io/scc":"restricted-v2","seccomp.security.alpha.kubernetes.io/pod":"runtime/default"},"container_id":"cri-o://6cfd642e5d466988ba6952844f539cd35ec1305908389fc1258b1550bae8ccb6","container_image":"registry.k8s.io/e2e-test-images/agnhost:2.43","container_name":"agnhost","labels":{"app":"hello-node","pod-template-hash":"8dd54cb99"},"namespace_id":"5b84ab56-c441-4942-b241-5e7a75799774","namespace_labels":{"kubernetes_io_metadata_name":"syslogtest","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"},"namespace_name":"syslogtest","pod_id":"7076289c-ca8b-4e99-a7fc-fffe9f1e295e","pod_ip":"10.128.2.92","pod_name":"hello-node-8dd54cb99-5hsbs","pod_owner":"ReplicaSet/hello-node-8dd54cb99"},"level":"default","log_type":"openshift_audit","message":"{\"log_type\":\"openshift_audit\",\"event type\":\"Sign on Success\",\"userName\":\"XXXXXXX\",\"event\":\"LEEF:1.0|redhat|openshift|4.12|authenticate devTime=2025-04-03T07:46:30.621410481-05:00[America/Chicago] devTimeFormat=yyyy-MM-dd HH:mm:ssZ requestClientApplication=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/134.0.0.0 Safari/537.36 requestMethod=GET sourceServiceName=xxx.xxx.xx.xxx src=xxx.xxx.xx.xxx srcPort=8080 dst=xxx.xxx.xx.xxx dstPort=35302 proto=HTTP/1.1 apiUrl=https://server.example.com/resource-server/actuator/health\"}","openshift":{"cluster_id":"ec905b28-0bd2-4ab7-bcdc-201125e35249","sequence":3273},"userName":"XXXXXXX"}
Apr  7 15:05:06 server.example.com vector {"@timestamp":"2025-04-07T15:05:06.245293157Z","event":"LEEF:1.0|redhat|openshift|4.12|authenticate devTime=2025-04-03T07:46:30.621410481-05:00[America/Chicago] devTimeFormat=yyyy-MM-dd HH:mm:ssZ requestClientApplication=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/134.0.0.0 Safari/537.36 requestMethod=GET sourceServiceName=xxx.xxx.xx.xxx src=xxx.xxx.xx.xxx srcPort=8080 dst=xxx.xxx.xx.xxx dstPort=35302 proto=HTTP/1.1 apiUrl=https://server.example.com/resource-server/actuator/health","event type":"Sign on Success","file":"/var/log/pods/syslogtest_hello-node-8dd54cb99-5hsbs_7076289c-ca8b-4e99-a7fc-fffe9f1e295e/agnhost/0.log","hostname":"server.example.com","kubernetes":{"annotations":{"k8s.ovn.org/pod-networks":"{\"default\":{\"ip_addresses\":[\"10.128.2.92/23\"],\"mac_address\":\"0a:58:0a:80:02:5c\",\"gateway_ips\":[\"10.128.2.1\"],\"routes\":[{\"dest\":\"10.128.0.0/14\",\"nextHop\":\"10.128.2.1\"},{\"dest\":\"172.30.0.0/16\",\"nextHop\":\"10.128.2.1\"},{\"dest\":\"169.254.169.5/32\",\"nextHop\":\"10.128.2.1\"},{\"dest\":\"100.64.0.0/16\",\"nextHop\":\"10.128.2.1\"}],\"ip_address\":\"10.128.2.92/23\",\"gateway_ip\":\"10.128.2.1\"}}","k8s.v1.cni.cncf.io/network-status":"[{\n    \"name\": \"ovn-kubernetes\",\n    \"interface\": \"eth0\",\n    \"ips\": [\n        \"10.128.2.92\"\n    ],\n    \"mac\": \"0a:58:0a:80:02:5c\",\n    \"default\": true,\n    \"dns\": {}\n}]","openshift.io/scc":"restricted-v2","seccomp.security.alpha.kubernetes.io/pod":"runtime/default"},"container_id":"cri-o://6cfd642e5d466988ba6952844f539cd35ec1305908389fc1258b1550bae8ccb6","container_image":"registry.k8s.io/e2e-test-images/agnhost:2.43","container_name":"agnhost","labels":{"app":"hello-node","pod-template-hash":"8dd54cb99"},"namespace_id":"5b84ab56-c441-4942-b241-5e7a75799774","namespace_labels":{"kubernetes_io_metadata_name":"syslogtest","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"},"namespace_name":"syslogtest","pod_id":"7076289c-ca8b-4e99-a7fc-fffe9f1e295e","pod_ip":"10.128.2.92","pod_name":"hello-node-8dd54cb99-5hsbs","pod_owner":"ReplicaSet/hello-node-8dd54cb99"},"level":"default","log_type":"openshift_audit","message":"{\"log_type\":\"openshift_audit\",\"event type\":\"Sign on Success\",\"userName\":\"XXXXXXX\",\"event\":\"LEEF:1.0|redhat|openshift|4.12|authenticate devTime=2025-04-03T07:46:30.621410481-05:00[America/Chicago] devTimeFormat=yyyy-MM-dd HH:mm:ssZ requestClientApplication=Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/134.0.0.0 Safari/537.36 requestMethod=GET sourceServiceName=xxx.xxx.xx.xxx src=xxx.xxx.xx.xxx srcPort=8080 dst=xxx.xxx.xx.xxx dstPort=35302 proto=HTTP/1.1 apiUrl=https://server.example.com/resource-server/actuator/health\"}","openshift":{"cluster_id":"ec905b28-0bd2-4ab7-bcdc-201125e35249","sequence":3273},"userName":"XXXXXXX"}

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

Logging 5.8.19 and Logging 5.9.12, not tested in Logging v6.
Vector

How reproducible:

Always

Steps to Reproduce:

Deploy a syslog server
Deploy the Cluster Logging Operator

Configure clusterLogForwarder for log forwarding to a syslog server with the next configuration:

apiVersion: logging.openshift.io/v1
kind: ClusterLogForwarder
metadata:
  name: instance
  namespace: openshift-logging
spec:
  outputs:
  - name: logs
    type: syslog
    url: tcp://rsyslog-server.rsyslog-pj.svc:6514
  pipelines:
  - inputRefs:
    - application
    - audit
    name: syslog-pl
    outputRefs:
    - logs

Actual results:

A single message by the application is sent twice by Vector to the syslog server

Expected results:

A single application log is read once and sent only 1 to the same destination

Additional info:

This impacts in the network usage and also in the cpu/memory/storage usage needed on the server receiving the logs

depends on

LOG-7009 Vector overwrites the log_type when writing a message to syslog that includes its own log_type field

Closed

LOG-7183 [release-6.0] Syslog: merging data from 'message' to the root of log makes log event inconsistent with ViaQ data model

Closed

LOG-7184 [release-6.1] Syslog: merging data from 'message' to the root of log make log event inconsistent with ViaQ data model

Closed

LOG-7185 [release-6.2] Syslog: merging data from 'message' to the root of log make log event inconsistent with ViaQ data model

Closed

LOG-7189 Syslog: merging data from 'message' to the root of log make log event inconsistent with ViaQ data model

Closed

links to

[KCS] Vector sends twice the same log when log forwarding to syslog in RHOL

openshift/cluster-logging-operator#3033: LOG-7009: remove parse and merge data from message to the log event

openshift/cluster-logging-operator#3034: [master]LOG-7189:avoid merge data from message to the log event

openshift/cluster-logging-operator#3035: [release-5.9]LOG-7009: avoid merge data from .message field to the log event root

(4 links to)

Details

Description

Description of problem:

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

How reproducible:

Steps to Reproduce:

Actual results:

Expected results:

Additional info:

Attachments

Issue Links

Easy Agile Planning Poker

Activity

People

Dates