Merge pull request #1597 from jcantrill/log2923

LOG-2923: fix timestamp field for kube and openshift event audit logs
openshift · Sep 7, 2022 · ad9c860 · ad9c860
2 parents 9ca48d5 + bed7dad
commit ad9c860
Show file tree

Hide file tree

Showing 5 changed files with 90 additions and 16 deletions.
diff --git a/internal/generator/fluentd/conf_test.go b/internal/generator/fluentd/conf_test.go
@@ -334,7 +334,15 @@ var _ = Describe("Testing Complete Config Generation", func() {
       level ${record['message'].split('|')[3].downcase}
     </record>
   </filter>
-  
+
+  # Process Kube and OpenShift Audit logs
+  <filter k8s-audit.log openshift-audit.log>
+    @type record_modifier
+    <record>
+      @timestamp ${record['requestReceivedTimestamp']}
+    </record>
+  </filter>  
+
   # Retag Journal logs to specific tags
   <match journal>
     @type rewrite_tag_filter

diff --git a/internal/generator/fluentd/fluent_conf_test.go b/internal/generator/fluentd/fluent_conf_test.go
@@ -361,7 +361,15 @@ var _ = Describe("Generating fluentd config", func() {
       level ${record['message'].split('|')[3].downcase}
     </record>
   </filter>
-  
+
+  # Process Kube and OpenShift Audit logs
+  <filter k8s-audit.log openshift-audit.log>
+    @type record_modifier
+    <record>
+      @timestamp ${record['requestReceivedTimestamp']}
+    </record>
+  </filter>  
+
   # Retag Journal logs to specific tags
   <match journal>
     @type rewrite_tag_filter
@@ -1182,7 +1190,15 @@ var _ = Describe("Generating fluentd config", func() {
       level ${record['message'].split('|')[3].downcase}
     </record>
   </filter>
-  
+
+  # Process Kube and OpenShift Audit logs
+  <filter k8s-audit.log openshift-audit.log>
+    @type record_modifier
+    <record>
+      @timestamp ${record['requestReceivedTimestamp']}
+    </record>
+  </filter>
+
   # Retag Journal logs to specific tags
   <match journal>
     @type rewrite_tag_filter
@@ -1989,6 +2005,14 @@ var _ = Describe("Generating fluentd config", func() {
     </record>
   </filter>
   
+  # Process Kube and OpenShift Audit logs
+  <filter k8s-audit.log openshift-audit.log>
+    @type record_modifier
+    <record>
+      @timestamp ${record['requestReceivedTimestamp']}
+    </record>
+  </filter>  
+
   # Retag Journal logs to specific tags
   <match journal>
     @type rewrite_tag_filter
@@ -2739,7 +2763,15 @@ var _ = Describe("Generating fluentd config", func() {
       level ${record['message'].split('|')[3].downcase}
     </record>
   </filter>
-  
+
+  # Process Kube and OpenShift Audit logs
+  <filter k8s-audit.log openshift-audit.log>
+    @type record_modifier
+    <record>
+      @timestamp ${record['requestReceivedTimestamp']}
+    </record>
+  </filter>
+
   # Retag Journal logs to specific tags
   <match journal>
     @type rewrite_tag_filter
@@ -3287,7 +3319,15 @@ var _ = Describe("Generating fluentd config", func() {
       level ${record['message'].split('|')[3].downcase}
     </record>
   </filter>
-  
+
+  # Process Kube and OpenShift Audit logs
+  <filter k8s-audit.log openshift-audit.log>
+    @type record_modifier
+    <record>
+      @timestamp ${record['requestReceivedTimestamp']}
+    </record>
+  </filter>  
+
   # Retag Journal logs to specific tags
   <match journal>
     @type rewrite_tag_filter
@@ -4381,7 +4421,15 @@ inputs:
       level ${record['message'].split('|')[3].downcase}
     </record>
   </filter>
-  
+
+  # Process Kube and OpenShift Audit logs
+  <filter k8s-audit.log openshift-audit.log>
+    @type record_modifier
+    <record>
+      @timestamp ${record['requestReceivedTimestamp']}
+    </record>
+  </filter>  
+
   # Retag Journal logs to specific tags
   <match journal>
     @type rewrite_tag_filter

diff --git a/internal/generator/fluentd/ingress.go b/internal/generator/fluentd/ingress.go
@@ -45,6 +45,11 @@ func Ingress(spec *logging.ClusterLogForwarderSpec, o Options) []Element {
 					TemplateName: "processOVNLogs",
 					TemplateStr:  ProcessOVNLogs,
 				},
+				ConfLiteral{
+					Desc:         "Process Kube and OpenShift Audit logs",
+					TemplateName: "processKubeAuditEvents",
+					TemplateStr:  ProcessKubeAuditEvents,
+				},
 				ConfLiteral{
 					Desc:         "Retag Journal logs to specific tags",
 					OutLabel:     "INGRESS",
@@ -112,6 +117,17 @@ const ProcessOVNLogs string = `
 </filter>
 {{end}}
 `
+const ProcessKubeAuditEvents string = `
+{{define "processKubeAuditEvents" -}}
+# {{.Desc}}
+<filter k8s-audit.log openshift-audit.log>
+  @type record_modifier
+  <record>
+    @timestamp ${record['requestReceivedTimestamp']}
+  </record>
+</filter>
+{{end}}
+`
 
 const RetagJournalLogs string = `
 {{define "retagJournal" -}}

diff --git a/test/functional/normalization/audit_logs_format_test.go b/test/functional/normalization/audit_logs_format_test.go
@@ -37,24 +37,25 @@ var _ = Describe("[Functional][LogForwarding][Normalization] message format test
 
 			It("should parse k8s audit log format correctly", func() {
 				// Log message data
-				timestamp := "2013-03-28T14:36:03.243000+00:00"
+				timestamp := "2022-08-17T20:27:20.570375Z"
 				nanoTime, _ := time.Parse(time.RFC3339Nano, timestamp)
 
 				// Define a template for test format (used for input, and expected output)
 				var outputLogTemplate = types.K8sAuditLog{
 					AuditLogCommon: types.AuditLogCommon{
-						Kind:             "Event",
-						Hostname:         functional.FunctionalNodeName,
-						LogType:          "audit",
-						Level:            "debug",
-						Timestamp:        time.Time{},
-						ViaqMsgID:        "*",
-						PipelineMetadata: functional.TemplateForAnyPipelineMetadata,
+						Kind:                     "Event",
+						Hostname:                 functional.FunctionalNodeName,
+						LogType:                  "audit",
+						Level:                    "debug",
+						Timestamp:                nanoTime,
+						RequestReceivedTimestamp: nanoTime,
+						ViaqMsgID:                "*",
+						PipelineMetadata:         functional.TemplateForAnyPipelineMetadata,
 					},
 					K8SAuditLevel: "debug",
 				}
 				// Template expected as output Log
-				k8sAuditLogLine := fmt.Sprintf(`{"kind":"Event","requestReceivedTimestamp":"%s","level":"debug"}`, functional.CRIOTime(nanoTime))
+				k8sAuditLogLine := fmt.Sprintf(`{"kind":"Event","requestReceivedTimestamp":"%s","level":"debug"}`, timestamp)
 				Expect(framework.WriteMessagesTok8sAuditLog(k8sAuditLogLine, 10)).To(BeNil())
 				// Read line from Log Forward output
 				raw, err := framework.ReadAuditLogsFrom(logging.OutputTypeFluentdForward)

diff --git a/test/matchers/log_format.go b/test/matchers/log_format.go
@@ -137,7 +137,8 @@ func compareLogLogic(name string, templateValue interface{}, value interface{})
 		return true
 	}
 
-	if templateValueString == "0001-01-01 00:00:00 +0000 UTC" && valueString != "" { // Any time value not Nil is ok if template value is empty time
+	// Any time value not Nil is ok if template value is empty time and also does not equal the value for time.Time{}
+	if templateValueString == "0001-01-01 00:00:00 +0000 UTC" && valueString != "" && valueString != "0001-01-01 00:00:00 +0000 UTC" {
 		log.V(3).Info("CompareLogLogic: Any value for 'empty time' ", "name", name, "value", valueString)
 		return true
 	}