-
Bug
-
Resolution: Done-Errata
-
Normal
-
Logging 5.9.z
-
False
-
None
-
False
-
NEW
-
VERIFIED
-
-
Bug Fix
-
Moderate
Description of problem:
CLF's syslog.addLogSource is the option to add namespace_name=, pod_name= and container_name= info when forwaring logs.
Since those info are related only to container, they should be added only to container logs.
But vector attempts to add those info even to journal and audit logs.
Fluentd adds those info only to container logs. Vector should take the same approach.
There are the examples logs forwarded by fluentd and vector.
Log forwarded by fluentd
$ cat infra-node.worker0.example.com.log | jq .
{
"timegenerated": "May 17 17:26:02",
"timereported": "May 17 08:26:53",
"hostname": "worker0.example.com",
"syslogfacility-text": "local0",
"syslogpriority-text": "info",
"syslogtag": "kubenswrapper[2654]:",
"programname": "kubenswrapper",
"app-name": "kubenswrapper",
"procid": "2654",
"msgid": "-",
"msg": " {\"_RUNTIME_SCOPE\":\"system\",\"_STREAM_ID\":\"ee49d19a2891488a933a9aedc524287e\",\"_SYSTEMD_INVOCATION_ID\":\"43a74a9e367d4e6b8da4c7760791654f\",\"systemd\":{\"t\":{\"BOOT_ID\":\"4e946541c2644e4ab92d5bd982acba20\",\"CAP_EFFECTIVE\":\"1ffffffffff\",\"CMDLINE\":\"/usr/bin/kubelet --config=/etc/kubernetes/kubelet.conf --bootstrap-kubeconfig=/etc/kubernetes/kubeconfig --kubeconfig=/var/lib/kubelet/kubeconfig --container-runtime-endpoint=/var/run/crio/crio.sock --runtime-cgroups=/system.slice/crio.service --node-labels=node-role.kubernetes.io/worker,node.openshift.io/os_id=rhcos, --node-ip=172.19.90.27 --address=172.19.90.27 --minimum-container-ttl-duration=6m0s --volume-plugin-dir=/etc/kubernetes/kubelet-plugins/volume/exec --cloud-provider=external --hostname-override= --pod-infra-container-image=quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:ac97982e845413b2b7377171d1b4c85d2b2cfda174e8251e3049d4843cea40e1 --system-reserved=cpu=500m,memory=1Gi,ephemeral-storage=1Gi --v=2\",\"COMM\":\"kubelet\",\"EXE\":\"/usr/bin/kubelet\",\"GID\":\"0\",\"MACHINE_ID\":\"1e159a9fd97c4dd0a3e3575827f34055\",\"PID\":\"2654\",\"SELINUX_CONTEXT\":\"system_u:system_r:kubelet_t:s0-s0:c0.c1023\",\"STREAM_ID\":\"ee49d19a2891488a933a9aedc524287e\",\"SYSTEMD_CGROUP\":\"/system.slice/kubelet.service\",\"SYSTEMD_INVOCATION_ID\":\"43a74a9e367d4e6b8da4c7760791654f\",\"SYSTEMD_SLICE\":\"system.slice\",\"SYSTEMD_UNIT\":\"kubelet.service\",\"TRANSPORT\":\"stdout\",\"UID\":\"0\"},\"u\":{\"SYSLOG_FACILITY\":\"3\",\"SYSLOG_IDENTIFIER\":\"kubenswrapper[2654]\"}},\"level\":\"info\",\"message\":\"E0517 08:26:51.719853 2654 pod_workers.go:1300] \\\"Error syncing pod, skipping\\\" err=\\\"failed to \\\\\\\"StartContainer\\\\\\\" for \\\\\\\"install-cni\\\\\\\" with ImagePullBackOff: \\\\\\\"Back-off pulling image \\\\\\\\\\\\\\\"docker.io/istio/install-cni:1.20.3\\\\\\\\\\\\\\\"\\\\\\\"\\\" pod=\\\"openshift-operators/istio-cni-node-j5qjb\\\" podUID=\\\"f225f98a-be9c-42f8-8275-5195259528c0\\\"\",\"hostname\":\"worker0.example.com\",\"pipeline_metadata\":{\"collector\":{\"ipaddr4\":\"172.19.90.27\",\"inputname\":\"fluent-plugin-systemd\",\"name\":\"fluentd\",\"received_at\":\"2024-05-17T08:26:52.839308+00:00\",\"version\":\"1.16.2 1.6.0\"}},\"openshift\":{\"sequence\":34168,\"cluster_id\":\"c334d326-bd51-4623-8d20-4fa831bd305d\"},\"@timestamp\":\"2024-05-17T08:26:51.719888+00:00\",\"viaq_msg_id\":\"NzY5NTRiMmItMjZmZi00MWQ2LWE4NzItMGE0ZDU1Y2I2MTBj\",\"log_type\":\"infrastructure\"}"
}
Log forwarded by vector
$ cat infra-node.example.com.log | grep RUNTIME_SCOPE | tail -n 1 | jq .
{
"timegenerated": "Jun 3 11:38:05",
"timereported": "Jun 3 02:38:05",
"hostname": "example.com",
"syslogfacility-text": "local0",
"syslogpriority-text": "info",
"syslogtag": ":",
"programname": "",
"app-name": "",
"procid": "-",
"msgid": "-",
"msg": " namespace_name=, container_name=, pod_name=, message={\"@timestamp\":\"2024-06-03T02:38:05.239625Z\",\"_RUNTIME_SCOPE\":\"system\",\"_STREAM_ID\":\"9ae0be9563304d2b8db22344d8dc5976\",\"_SYSTEMD_INVOCATION_ID\":\"0fcd7d78a86c4e1696673458c2fa5917\",\"hostname\":\"example.com\",\"level\":\"info\",\"log_type\":\"infrastructure\",\"message\":\"I0603 02:38:05.239124 1726 kubelet_getters.go:187] \\\"Pod status updated\\\" pod=\\\"openshift-machine-config-operator/kube-rbac-proxy-crio-example.com\\\" status=\\\"Running\\\"\",\"openshift\":{\"cluster_id\":\"d43a0d58-47dc-4e61-a5d3-e7f93c1b1689\",\"sequence\":1717382285707930398},\"systemd\":{\"t\":{\"BOOT_ID\":\"bee5be8bf3d1448c81694c8223a86182\",\"CAP_EFFECTIVE\":\"1ffffffffff\",\"CMDLINE\":\"/usr/bin/kubelet --config=/etc/kubernetes/kubelet.conf --bootstrap-kubeconfig=/etc/kubernetes/kubeconfig --kubeconfig=/var/lib/kubelet/kubeconfig --container-runtime-endpoint=/var/run/crio/crio.sock --runtime-cgroups=/system.slice/crio.service --node-labels=node-role.kubernetes.io/control-plane,node-role.kubernetes.io/master,node.openshift.io/os_id=rhcos --node-ip=192.168.200.10 --minimum-container-ttl-duration=6m0s --cloud-provider= --volume-plugin-dir=/etc/kubernetes/kubelet-plugins/volume/exec --hostname-override= --provider-id= --register-with-taints=node-role.kubernetes.io/master=:NoSchedule --pod-infra-container-image=quay.io/openshift-release-dev/ocp-v4.0-art-dev@sha256:882de158fbea366429b4d3abab016de5cf60b1e7efad7d04f6882ec61b404b3a --system-reserved=cpu=500m,memory=1Gi,ephemeral-storage=1Gi --v=2\",\"COMM\":\"kubelet\",\"EXE\":\"/usr/bin/kubelet\",\"GID\":\"0\",\"MACHINE_ID\":\"a64cdf964fc64493958f9ddb9ae1846f\",\"PID\":\"1726\",\"SELINUX_CONTEXT\":\"system_u:system_r:kubelet_t:s0-s0:c0.c1023\",\"STREAM_ID\":\"9ae0be9563304d2b8db22344d8dc5976\",\"SYSTEMD_CGROUP\":\"/system.slice/kubelet.service\",\"SYSTEMD_INVOCATION_ID\":\"0fcd7d78a86c4e1696673458c2fa5917\",\"SYSTEMD_SLICE\":\"system.slice\",\"SYSTEMD_UNIT\":\"kubelet.service\",\"TRANSPORT\":\"stdout\",\"UID\":\"0\"},\"u\":{\"SYSLOG_FACILITY\":\"3\",\"SYSLOG_IDENTIFIER\":\"kubenswrapper\"}},\"tag\":\".journal.system\",\"time\":\"2024-06-03T02:38:05+00:00\"}"
}
Version-Release number of selected component (if applicable):
cluster-logging.v5.9.0
How reproducible:
Always
Steps to Reproduce:
Step1. Prepre rsyslog server outside of the cluster.
We use the following conf in rsyslog server to handle logs forwarded from vector.
$ cat /etc/rsyslog.d/remotelog.conf
template(name="OpenShiftLogging_InfraNodeLogFile" type="list") {
constant(value="/var/log/remote/infra-node.")
property(name="hostname")
constant(value=".log")
}
template(name="OpenShiftLogging_InfraContainerLogFile" type="list") {
constant(value="/var/log/remote/infra-container.")
property(name="hostname")
constant(value=".log")
}
template(name="OpenShiftLogging_AppLogFile" type="list") {
constant(value="/var/log/remote/app.")
property(name="hostname")
constant(value=".log")
}
template(name="OpenShiftLogging_AuditLogFile" type="list") {
constant(value="/var/log/remote/audit.")
property(name="hostname")
constant(value=".log")
}
template(name="DebugJsonFormat" type="list") {
constant(value="{")
property(name="timegenerated" format="jsonf")
constant(value=",")
property(name="timereported" format="jsonf")
constant(value=",")
property(name="hostname" format="jsonf")
constant(value=",")
property(name="syslogfacility-text" format="jsonf")
constant(value=",")
property(name="syslogpriority-text" format="jsonf")
constant(value=",")
property(name="syslogtag" format="jsonf")
constant(value=",")
property(name="programname" format="jsonf")
constant(value=",")
property(name="app-name" format="jsonf")
constant(value=",")
property(name="procid" format="jsonf")
constant(value=",")
property(name="msgid" format="jsonf")
constant(value=",")
property(name="msg" format="jsonf")
constant(value="}\n")
}
# Adding this ruleset to process remote messages
ruleset(name="OpenShiftLogging_Ruleset") {
if ($syslogfacility-text == "local0") then {
if ($syslogtag startswith "openshift-logging-infra") then {
*.* action(type="omfile" DynaFile="OpenShiftLogging_InfraContainerLogFile" Template="DebugJsonFormat")
} else {
*.* action(type="omfile" DynaFile="OpenShiftLogging_InfraNodeLogFile" Template="DebugJsonFormat")
}
} else if ($syslogfacility-text == "local1") then {
*.* action(type="omfile" DynaFile="OpenShiftLogging_AppLogFile" Template="DebugJsonFormat")
} else if ($syslogfacility-text == "local2") then {
*.* action(type="omfile" DynaFile="OpenShiftLogging_AuditLogFile" Template="DebugJsonFormat")
}
}
# Load the imptcp module to provide the ability to receive messages over plain TCP
module(load="imtcp")
input(type="imtcp" port="514" ruleset="OpenShiftLogging_Ruleset")
Step2. Deploy vector from Cluster Logging Operator. [1]
(You don't need to deploy Loki. You just need to deploy vector)
Step3. Apply the following yaml to forward infrastructure logs(which include journal logs) to rsyslog server.
kind: ClusterLogForwarder
apiVersion: "logging.openshift.io/v1"
metadata:
name: instance
namespace: openshift-logging
spec:
outputs:
- name: external-rsyslog-infra
type: syslog
url: 'tcp://<your rsyslog server>:514'
syslog:
addLogSource: true
rfc: RFC3164
facility: local0
severity: informational
pipelines:
- name: syslog-infra
inputRefs:
- infrastructure
outputRefs:
- external-rsyslog-infra
Step4. Log in to rsyslog server then check logs(/var/log/remote/infra-node.*.log) forwarded from vector.
Actual results:
Unnecessary LogSource template strings (namespace_name=, container_name=, pod_name=) are included in the msg.
Expected results:
Unnecessary LogSource template strings should not be included in the msg.
Additional information:
Just like when sending journal logs, unnecessary LogSource template strings are included in msg when sending audit logs.
Log forwarded by fluentd
$ tail -n 1 audit.master0.example.com.log | jq .
{
"timegenerated": "May 17 17:26:09",
"timereported": "May 17 08:27:00",
"hostname": "master0.example.com",
"syslogfacility-text": "local2",
"syslogpriority-text": "info",
"syslogtag": "openshift-logging-audit:",
"programname": "openshift-logging-audit",
"app-name": "openshift-logging-audit",
"procid": "-",
"msgid": "-",
"msg": " {\"kind\":\"Event\",\"apiVersion\":\"audit.k8s.io/v1\",\"level\":\"Metadata\",\"auditID\":\"9b613cf5-92c5-4978-959e-aa5a7c8518a2\",\"stage\":\"ResponseStarted\",\"requestURI\":\"/apis/config.openshift.io/v1/featuregates?allowWatchBookmarks=true&resourceVersion=33513865&timeout=9m45s&timeoutSeconds=585&watch=true\",\"verb\":\"watch\",\"user\":{\"username\":\"system:serviceaccount:openshift-insights:operator\",\"uid\":\"af95deb6-d5f5-462a-9cdc-24e51df04915\",\"groups\":[\"system:serviceaccounts\",\"system:serviceaccounts:openshift-insights\",\"system:authenticated\"],\"extra\":{\"authentication.kubernetes.io/pod-name\":[\"insights-operator-856fcc58bc-rb5nz\"],\"authentication.kubernetes.io/pod-uid\":[\"2d71715d-0855-4739-80da-e1df22cf812a\"]}},\"sourceIPs\":[\"10.128.0.37\"],\"userAgent\":\"insights-operator/v0.0.0 (linux/amd64) kubernetes/$Format\",\"objectRef\":{\"resource\":\"featuregates\",\"apiGroup\":\"config.openshift.io\",\"apiVersion\":\"v1\"},\"responseStatus\":{\"metadata\":{},\"code\":200},\"requestReceivedTimestamp\":\"2024-05-17T08:26:59.941784Z\",\"stageTimestamp\":\"2024-05-17T08:26:59.953558Z\",\"annotations\":{\"authorization.k8s.io/decision\":\"allow\",\"authorization.k8s.io/reason\":\"RBAC: allowed by ClusterRoleBinding \\\"insights-operator\\\" of ClusterRole \\\"insights-operator\\\" to ServiceAccount \\\"operator/openshift-insights\\\"\"},\"@timestamp\":\"2024-05-17T08:26:59.941784Z\",\"k8s_audit_level\":\"Metadata\",\"message\":null,\"hostname\":\"master0.example.com\",\"pipeline_metadata\":{\"collector\":{\"ipaddr4\":\"172.19.90.21\",\"inputname\":\"fluent-plugin-systemd\",\"name\":\"fluentd\",\"received_at\":\"2024-05-17T08:26:59.954071+00:00\",\"version\":\"1.16.2 1.6.0\"}},\"openshift\":{\"sequence\":68952,\"cluster_id\":\"c334d326-bd51-4623-8d20-4fa831bd305d\"},\"viaq_msg_id\":\"ZjFhMTEzNWQtODllMy00ODViLTk0YmYtMDZjNmM2MzU2NThh\",\"log_type\":\"audit\"}"
}
Log forwarded by vector
$ sudo tail -n 1 audit.example.com.log | jq .
{
"timegenerated": "May 17 17:26:10",
"timereported": "May 17 08:26:10",
"hostname": "example.com",
"syslogfacility-text": "local2",
"syslogpriority-text": "info",
"syslogtag": "openshift-logging-audit:",
"programname": "openshift-logging-audit",
"app-name": "openshift-logging-audit",
"procid": "-",
"msgid": "-",
"msg": " namespace_name=, container_name=, pod_name=, message={\"@timestamp\":\"2024-05-17T08:26:10.542079967Z\",\"annotations\":{\"authorization.k8s.io/decision\":\"allow\",\"authorization.k8s.io/reason\":\"\"},\"apiVersion\":\"audit.k8s.io/v1\",\"auditID\":\"c10460bf-d97e-4dfe-b9e9-634288692b6f\",\"file\":\"/var/log/kube-apiserver/audit.log\",\"hostname\":\"example.com\",\"k8s_audit_level\":\"Metadata\",\"kind\":\"Event\",\"level\":\"Metadata\",\"log_type\":\"audit\",\"objectRef\":{\"apiVersion\":\"v1\",\"name\":\"collector-t4n7m\",\"namespace\":\"openshift-logging\",\"resource\":\"pods\"},\"openshift\":{\"cluster_id\":\"d43a0d58-47dc-4e61-a5d3-e7f93c1b1689\",\"sequence\":1715934370547559292},\"requestReceivedTimestamp\":\"2024-05-17T08:26:10.491595Z\",\"requestURI\":\"/api/v1/namespaces/openshift-logging/pods/collector-t4n7m\",\"responseStatus\":{\"code\":200,\"metadata\":{}},\"sourceIPs\":[\"192.168.200.1\"],\"source_type\":\"file\",\"stage\":\"ResponseComplete\",\"stageTimestamp\":\"2024-05-17T08:26:10.537957Z\",\"tag\":\".k8s-audit.log\",\"user\":{\"groups\":[\"system:nodes\",\"system:authenticated\"],\"username\":\"system:node:worker3.example.com\"},\"userAgent\":\"kubelet/v1.28.9+2f7b992 (linux/amd64) kubernetes/922efb2\",\"verb\":\"get\"}"
}
- links to
-
RHBA-2025:144863
Logging for Red Hat OpenShift - 5.9.11