diff --git a/cli/genpolicy/logtranslator.go b/cli/genpolicy/logtranslator.go index 8f7d58534..c9d1e0daa 100644 --- a/cli/genpolicy/logtranslator.go +++ b/cli/genpolicy/logtranslator.go @@ -33,18 +33,40 @@ func (l logTranslator) Write(p []byte) (n int, err error) { return l.w.Write(p) } -var genpolicyLogPrefixReg = regexp.MustCompile(`^\[[^\]\s]+\s+(\w+)\s+([^\]\s]+)\] (.*)`) +var ( + genpolicyLogPrefixReg = regexp.MustCompile(`^\[[^\]\s]+\s+(\w+)\s+([^\]\s]+)\] (.*)`) + errorMessage = regexp.MustCompile(`^thread\s+'main'\s+panicked\s+at`) +) func (l logTranslator) startTranslate() { go func() { defer close(l.stopDoneC) scanner := bufio.NewScanner(l.r) + // Default log level is initially set to 'WARN'. This is only relevant if the first line does not match the logging pattern. + logLevel := "WARN" + for scanner.Scan() { line := scanner.Text() match := genpolicyLogPrefixReg.FindStringSubmatch(line) if len(match) != 4 { // genpolicy prints some warnings without the logger - l.logger.Warn(line) + // we continue logging on the latest used log-level + + // Error is written to stderr by genpolicy without using the logger, + // simple regex to detect the error message on stderr + if errorMessage.MatchString(line) { + logLevel = "ERROR" + } + switch logLevel { + case "ERROR": + l.logger.Error(line) + case "WARN": + l.logger.Warn(line) + case "INFO": + fallthrough + case "DEBUG": + l.logger.Debug(line) + } } else { switch match[1] { case "ERROR": @@ -56,7 +78,10 @@ func (l logTranslator) startTranslate() { case "DEBUG": l.logger.Debug(match[3], "position", match[2]) } + // Update the latest log level + logLevel = match[1] } + } }() } diff --git a/cli/genpolicy/logtranslator_test.go b/cli/genpolicy/logtranslator_test.go index 3f347e0cf..6713c2b19 100644 --- a/cli/genpolicy/logtranslator_test.go +++ b/cli/genpolicy/logtranslator_test.go @@ -11,11 +11,12 @@ import ( func TestGenpolicyLogPrefixReg(t *testing.T) { testCases := []struct { - logLine string - wantMatch bool - wantLevel string - wantPosition string - wantMessage string + logLine string + wantMatch bool + wantLevel string + wantPosition string + wantMessage string + wantNoPrefixErrMatch bool }{ { logLine: `[2024-06-26T09:09:40Z INFO genpolicy::registry] ============================================`, @@ -52,6 +53,11 @@ func TestGenpolicyLogPrefixReg(t *testing.T) { wantPosition: "genpolicy::registry", wantMessage: "Using cache file", }, + { + logLine: `thread 'main' panicked at src/registry.rs:131:17:`, + wantMatch: false, + wantNoPrefixErrMatch: true, + }, { logLine: `Success!"`, wantMatch: false, @@ -66,6 +72,9 @@ func TestGenpolicyLogPrefixReg(t *testing.T) { if !tc.wantMatch { assert.Nil(match) + if tc.wantNoPrefixErrMatch { + assert.True(errorMessage.MatchString(tc.logLine)) + } return } assert.Len(match, 4) diff --git a/packages/by-name/kata/kata-runtime/0018-genpolicy-do-not-log-policy-annotation-in-debug.patch b/packages/by-name/kata/kata-runtime/0018-genpolicy-do-not-log-policy-annotation-in-debug.patch new file mode 100644 index 000000000..5ce1fb3ee --- /dev/null +++ b/packages/by-name/kata/kata-runtime/0018-genpolicy-do-not-log-policy-annotation-in-debug.patch @@ -0,0 +1,64 @@ +From 0000000000000000000000000000000000000000 Mon Sep 17 00:00:00 2001 +From: jmxnzo +Date: Tue, 10 Dec 2024 11:19:29 +0100 +Subject: [PATCH] genpolicy: do not log policy annotation in 'debug' + +--- + src/tools/genpolicy/src/obj_meta.rs | 38 ++++++++++++++++++++++++++++- + 1 file changed, 37 insertions(+), 1 deletion(-) + +diff --git a/src/tools/genpolicy/src/obj_meta.rs b/src/tools/genpolicy/src/obj_meta.rs +index 3da75fc0ff67068af04ea98a6dfdc6989961e17c..327ef13ad4cd6ff8f08d25228e6c108dea3f1606 100644 +--- a/src/tools/genpolicy/src/obj_meta.rs ++++ b/src/tools/genpolicy/src/obj_meta.rs +@@ -8,9 +8,10 @@ + + use serde::{Deserialize, Serialize}; + use std::collections::BTreeMap; ++use std::fmt; + + /// See ObjectMeta in the Kubernetes API reference. +-#[derive(Clone, Debug, Default, Serialize, Deserialize)] ++#[derive(Clone, Default, Serialize, Deserialize)] + pub struct ObjectMeta { + #[serde(skip_serializing_if = "Option::is_none")] + pub name: Option, +@@ -43,3 +44,38 @@ impl ObjectMeta { + self.namespace.as_ref().cloned() + } + } ++ ++ ++impl fmt::Debug for ObjectMeta { ++ fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { ++ let mut debug_struct = f.debug_struct("ObjectMeta"); ++ ++ if let Some(ref name) = self.name { ++ debug_struct.field("name", name); ++ } ++ if let Some(ref generate_name) = self.generateName { ++ debug_struct.field("generateName", generate_name); ++ } ++ if let Some(ref labels) = self.labels { ++ debug_struct.field("labels", labels); ++ } ++ if let Some(ref annotations) = self.annotations { ++ let truncated_annotations: BTreeMap<_, _> = annotations ++ .iter() ++ .map(|(key, value)| { ++ if value.len() > 4096 { ++ (key, format!("{}<... truncated ...>", &value[..4096].to_string())) ++ } else { ++ (key, value.to_string()) ++ } ++ }) ++ .collect(); ++ debug_struct.field("annotations", &truncated_annotations); ++ } ++ if let Some(ref namespace) = self.namespace { ++ debug_struct.field("namespace", namespace); ++ } ++ ++ debug_struct.finish() ++ } ++} diff --git a/packages/by-name/kata/kata-runtime/package.nix b/packages/by-name/kata/kata-runtime/package.nix index c7e0c521a..7b77b6e13 100644 --- a/packages/by-name/kata/kata-runtime/package.nix +++ b/packages/by-name/kata/kata-runtime/package.nix @@ -102,6 +102,11 @@ buildGoModule rec { # No upstream patch available, changes first need to be discussed with Kata maintainers. # See https://katacontainers.slack.com/archives/C879ACQ00/p1731928491942299 ./0017-runtime-allow-initrd-AND-image-to-be-set.patch + + # Simple genpolicy logging redaction of the policy annotation + # This avoids printing the entire annotation on log level debug, which resulted in errors of the logtranslator.go + # TODO(jmxnzo): remove when upstream patch is merged: https://github.com/kata-containers/kata-containers/pull/10647 + ./0018-genpolicy-do-not-log-policy-annotation-in-debug.patch ]; }; diff --git a/packages/by-name/microsoft/genpolicy/0008-genpolicy-include-reference-in-logs-when-auth-failure.patch b/packages/by-name/microsoft/genpolicy/0008-genpolicy-include-reference-in-logs-when-auth-failur.patch similarity index 100% rename from packages/by-name/microsoft/genpolicy/0008-genpolicy-include-reference-in-logs-when-auth-failure.patch rename to packages/by-name/microsoft/genpolicy/0008-genpolicy-include-reference-in-logs-when-auth-failur.patch diff --git a/packages/by-name/microsoft/genpolicy/0009-genpolicy-do-not-log-policy-annotation-in-debug.patch b/packages/by-name/microsoft/genpolicy/0009-genpolicy-do-not-log-policy-annotation-in-debug.patch new file mode 100644 index 000000000..49004b7ae --- /dev/null +++ b/packages/by-name/microsoft/genpolicy/0009-genpolicy-do-not-log-policy-annotation-in-debug.patch @@ -0,0 +1,63 @@ +From 0000000000000000000000000000000000000000 Mon Sep 17 00:00:00 2001 +From: jmxnzo +Date: Mon, 9 Dec 2024 09:56:56 +0100 +Subject: [PATCH] genpolicy: do not log policy annotation in 'debug' + +--- + src/tools/genpolicy/src/obj_meta.rs | 37 ++++++++++++++++++++++++++++- + 1 file changed, 36 insertions(+), 1 deletion(-) + +diff --git a/src/tools/genpolicy/src/obj_meta.rs b/src/tools/genpolicy/src/obj_meta.rs +index 3da75fc0ff67068af04ea98a6dfdc6989961e17c..55ec12f4a9261e340950dc94afe42092d18bc859 100644 +--- a/src/tools/genpolicy/src/obj_meta.rs ++++ b/src/tools/genpolicy/src/obj_meta.rs +@@ -8,9 +8,10 @@ + + use serde::{Deserialize, Serialize}; + use std::collections::BTreeMap; ++use std::fmt; + + /// See ObjectMeta in the Kubernetes API reference. +-#[derive(Clone, Debug, Default, Serialize, Deserialize)] ++#[derive(Clone, Default, Serialize, Deserialize)] + pub struct ObjectMeta { + #[serde(skip_serializing_if = "Option::is_none")] + pub name: Option, +@@ -43,3 +44,37 @@ impl ObjectMeta { + self.namespace.as_ref().cloned() + } + } ++ ++impl fmt::Debug for ObjectMeta { ++ fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { ++ let mut debug_struct = f.debug_struct("ObjectMeta"); ++ ++ if let Some(ref name) = self.name { ++ debug_struct.field("name", name); ++ } ++ if let Some(ref generate_name) = self.generateName { ++ debug_struct.field("generateName", generate_name); ++ } ++ if let Some(ref labels) = self.labels { ++ debug_struct.field("labels", labels); ++ } ++ if let Some(ref annotations) = self.annotations { ++ let truncated_annotations: BTreeMap<_, _> = annotations ++ .iter() ++ .map(|(key, value)| { ++ if value.len() > 4096 { ++ (key, format!("{}<... truncated ...>", &value[..4096].to_string())) ++ } else { ++ (key, value.to_string()) ++ } ++ }) ++ .collect(); ++ debug_struct.field("annotations", &truncated_annotations); ++ } ++ if let Some(ref namespace) = self.namespace { ++ debug_struct.field("namespace", namespace); ++ } ++ ++ debug_struct.finish() ++ } ++} diff --git a/packages/by-name/microsoft/genpolicy/package.nix b/packages/by-name/microsoft/genpolicy/package.nix index 085f15477..d471c36c0 100644 --- a/packages/by-name/microsoft/genpolicy/package.nix +++ b/packages/by-name/microsoft/genpolicy/package.nix @@ -65,7 +65,12 @@ rustPlatform.buildRustPackage rec { # This will be achieved when updating oci_distribution to oci_client crate on microsoft/kata-containers fork. # kata/kata-runtime/0011-genpolicy-bump-oci-distribution-to-v0.12.0.patch introduces this update to kata-containers. # After upstreaming, microsoft/kata-containers fork would need to pick up the changes. - ./0008-genpolicy-include-reference-in-logs-when-auth-failure.patch + ./0008-genpolicy-include-reference-in-logs-when-auth-failur.patch + + # Simple genpolicy logging redaction of the policy annotation + # This avoids printing the entire annotation on log level debug, which resulted in errors of the logtranslator.go + # TODO(jmxnzo): remove when https://github.com/kata-containers/kata-containers/pull/10647 is picked up by microsoft/kata-containers fork + ./0009-genpolicy-do-not-log-policy-annotation-in-debug.patch ]; };