From 776ee5c9bf688e806a0553ac16ba49cbe7cac97e Mon Sep 17 00:00:00 2001 From: Kim Christensen Date: Sun, 15 Dec 2024 23:09:49 +0100 Subject: [PATCH] feat: Mask sensitive values logged through spans closes #3216 closes #2256 Signed-off-by: Kim Christensen --- pkg/portercontext/context.go | 60 ++++++++++++--- pkg/portercontext/context_test.go | 73 +++++++++++++++++++ pkg/portercontext/plugins.go | 3 +- tests/integration/install_test.go | 21 ++++++ .../helpers.sh | 21 ++++++ .../porter.yaml | 50 +++++++++++++ 6 files changed, 215 insertions(+), 13 deletions(-) create mode 100755 tests/integration/testdata/bundles/failing-bundle-with-sensitive-data/helpers.sh create mode 100644 tests/integration/testdata/bundles/failing-bundle-with-sensitive-data/porter.yaml diff --git a/pkg/portercontext/context.go b/pkg/portercontext/context.go index 3cbc99961..26829ee59 100644 --- a/pkg/portercontext/context.go +++ b/pkg/portercontext/context.go @@ -21,6 +21,7 @@ import ( "github.com/spf13/afero" "go.opentelemetry.io/otel/attribute" "go.uber.org/zap" + "go.uber.org/zap/buffer" "go.uber.org/zap/zapcore" ) @@ -79,6 +80,8 @@ type Context struct { // InternalPluginKey is the current plugin that Porter is running as, e.g. storage.porter.mongodb InternalPluginKey string + + censoredWriter *CensoredWriter } // New creates a new context in the specified directory. @@ -95,13 +98,14 @@ func New() *Context { } c := &Context{ - environ: getEnviron(), - FileSystem: aferox.NewAferox(pwd, afero.NewOsFs()), - In: os.Stdin, - Out: NewCensoredWriter(os.Stdout), - Err: NewCensoredWriter(os.Stderr), - correlationId: correlationId, - timestampLogs: true, + environ: getEnviron(), + FileSystem: aferox.NewAferox(pwd, afero.NewOsFs()), + In: os.Stdin, + Out: NewCensoredWriter(os.Stdout), + Err: NewCensoredWriter(os.Stderr), + correlationId: correlationId, + timestampLogs: true, + censoredWriter: NewCensoredWriter(os.Stdout), } // Make the correlation id available for the plugins to use @@ -132,6 +136,7 @@ func (c *Context) makeLogEncoding() zapcore.EncoderConfig { encoder.AppendString("") } } + return enc } @@ -234,7 +239,7 @@ func (c *Context) makeConsoleLogger() zapcore.Core { encoding.TimeKey = "" encoding.LevelKey = "" } - consoleEncoder := zapcore.NewConsoleEncoder(encoding) + censoredEncoder := &CensoredEncoder{Encoder: zapcore.NewConsoleEncoder(encoding), censoredWriter: c.censoredWriter} isInformational := func(lvl zapcore.Level) bool { return lvl < zapcore.ErrorLevel && lvl >= c.logCfg.Verbosity @@ -245,10 +250,9 @@ func (c *Context) makeConsoleLogger() zapcore.Core { }) return zapcore.NewTee( - zapcore.NewCore(consoleEncoder, zapcore.AddSync(stdout), stdoutEnabler), - zapcore.NewCore(consoleEncoder, zapcore.AddSync(stderr), stderrEnabler), + zapcore.NewCore(censoredEncoder, zapcore.AddSync(stdout), stdoutEnabler), + zapcore.NewCore(censoredEncoder, zapcore.AddSync(stderr), stderrEnabler), ) - // return zapcore.NewCore(consoleEncoder, zapcore.AddSync(stdout), c.logCfg.Verbosity) } func (c *Context) configureFileLog(dir string) (zapcore.Core, error) { @@ -268,7 +272,8 @@ func (c *Context) configureFileLog(dir string) (zapcore.Core, error) { // Split logs to the console and file fileEncoder := zapcore.NewJSONEncoder(c.makeLogEncoding()) - return zapcore.NewCore(fileEncoder, zapcore.AddSync(c.logFile), c.logCfg.LogLevel), nil + censoredEncoder := &CensoredEncoder{Encoder: fileEncoder, censoredWriter: c.censoredWriter} + return zapcore.NewCore(censoredEncoder, zapcore.AddSync(c.logFile), c.logCfg.LogLevel), nil } func (c *Context) buildLogFileName() string { @@ -451,6 +456,16 @@ func (cw *CensoredWriter) Write(b []byte) (int, error) { return len(b), err } +func (cw *CensoredWriter) Censor(b []byte) []byte { + for _, val := range cw.sensitiveValues { + if strings.TrimSpace(val) != "" { + b = bytes.Replace(b, []byte(val), []byte("*******"), -1) + } + } + + return b +} + func (c *Context) CopyDirectory(srcDir, destDir string, includeBaseDir bool) error { var stripPrefix string if includeBaseDir { @@ -527,9 +542,30 @@ func (c *Context) SetSensitiveValues(vals []string) { out := NewCensoredWriter(c.Out) out.SetSensitiveValues(vals) c.Out = out + c.censoredWriter.SetSensitiveValues(vals) err := NewCensoredWriter(c.Err) err.SetSensitiveValues(vals) c.Err = err } } + +type CensoredEncoder struct { + zapcore.Encoder + censoredWriter *CensoredWriter +} + +func (ce CensoredEncoder) Clone() zapcore.Encoder { + return &CensoredEncoder{Encoder: ce.Encoder.Clone(), censoredWriter: ce.censoredWriter} +} + +func (ce CensoredEncoder) EncodeEntry(entry zapcore.Entry, fields []zapcore.Field) (*buffer.Buffer, error) { + entry.Message = string(ce.censoredWriter.Censor([]byte(entry.Message))) + for _, field := range fields { + if field.Type == zapcore.StringType { + field.String = string(ce.censoredWriter.Censor([]byte(field.String))) + } + } + + return ce.Encoder.EncodeEntry(entry, fields) +} diff --git a/pkg/portercontext/context_test.go b/pkg/portercontext/context_test.go index 6b60896b5..3dc1a6018 100644 --- a/pkg/portercontext/context_test.go +++ b/pkg/portercontext/context_test.go @@ -131,3 +131,76 @@ func TestContext_PluginLogCollectorLevel(t *testing.T) { require.Contains(t, lines[3], "\"@level\":\"error\"") require.Contains(t, lines[3], "\"@message\":\"error log\"") } + +func TestContext_SensitiveLogsAreCensored(t *testing.T) { + c := NewTestContext(t) + defer c.Close() + c.ConfigureLogging(context.Background(), LogConfiguration{ + Verbosity: zapcore.DebugLevel, + }) + c.SetSensitiveValues([]string{"topsecret"}) + + c.logger.Info("this is a test with sensitive data: topsecret") + + logs := c.captureLogs.String() + require.Contains(t, logs, "this is a test with sensitive data: *******") + require.NotContains(t, logs, "topsecret") +} + +func TestContext_TracesWithSensitiveLogsAreCensored(t *testing.T) { + c := NewTestContext(t) + c.ConfigureLogging(context.Background(), LogConfiguration{ + Verbosity: zapcore.DebugLevel, + }) + c.SetSensitiveValues([]string{"topsecret"}) + + _, log := c.StartRootSpan(context.Background(), t.Name()) + log.Debug("this is a test with sensitive data: topsecret") + log.EndSpan() + c.Close() + + logs := c.captureLogs.String() + require.Contains(t, logs, "this is a test with sensitive data: *******") + require.NotContains(t, logs, "topsecret") +} + +func TestContext_PluginLogsAreCensored(t *testing.T) { + c := NewTestContext(t) + c.IsInternalPlugin = true + c.ConfigureLogging(context.Background(), LogConfiguration{ + Verbosity: zapcore.DebugLevel, + }) + c.SetSensitiveValues([]string{"topsecret"}) + + _, log := c.StartRootSpan(context.Background(), t.Name()) + log.Debug("this is a test with sensitive data: topsecret") + log.EndSpan() + c.Close() + + logs := c.captureLogs.String() + require.Contains(t, logs, "this is a test with sensitive data: *******") + require.NotContains(t, logs, "topsecret") +} + +func TestContext_LogToFileWithCensoredValues(t *testing.T) { + c := NewTestContext(t) + c.ConfigureLogging(context.Background(), LogConfiguration{ + Verbosity: zapcore.DebugLevel, + LogLevel: zapcore.DebugLevel, + LogToFile: true, + LogDirectory: "/.porter/logs", + }) + c.SetSensitiveValues([]string{"topsecret"}) + c.timestampLogs = false // turn off timestamps so we can compare more easily + logfile := c.logFile.Name() + _, log := c.StartRootSpan(context.Background(), t.Name()) + log.Info("this is a test with sensitive data: topsecret") + + log.EndSpan() + c.Close() + + logContents, err := c.FileSystem.ReadFile(logfile) + require.NoError(t, err) + require.Contains(t, string(logContents), "this is a test with sensitive data: *******") + require.NotContains(t, string(logContents), "topsecret") +} diff --git a/pkg/portercontext/plugins.go b/pkg/portercontext/plugins.go index 190b88369..48b9832bc 100644 --- a/pkg/portercontext/plugins.go +++ b/pkg/portercontext/plugins.go @@ -22,7 +22,8 @@ func (c *Context) makePluginLogger(pluginKey string, cfg LogConfiguration) zapco enc := zap.NewProductionEncoderConfig() jsonEncoder := zapcore.NewJSONEncoder(enc) - return zapcore.NewCore(jsonEncoder, zapcore.AddSync(pluginLogger), cfg.Verbosity) + censoredEncoder := &CensoredEncoder{Encoder: jsonEncoder, censoredWriter: c.censoredWriter} + return zapcore.NewCore(censoredEncoder, zapcore.AddSync(pluginLogger), cfg.Verbosity) } // Accepts zap log commands and translates them to a format that hclog understands diff --git a/tests/integration/install_test.go b/tests/integration/install_test.go index 60d4bb66c..3c1746361 100644 --- a/tests/integration/install_test.go +++ b/tests/integration/install_test.go @@ -127,3 +127,24 @@ func TestInstall_stringParam(t *testing.T) { output := p.TestConfig.TestContext.GetOutput() require.Contains(t, output, "Hello, Demo Time", "expected action output to contain provided file contents") } + +func TestInstall_SensitiveValuesAreNotLogged(t *testing.T) { + p := porter.NewTestPorter(t) + defer p.Close() + ctx := p.SetupIntegrationTest() + + p.AddTestBundleDir("testdata/bundles/failing-bundle-with-sensitive-data", false) + + installOpts := porter.NewInstallOptions() + installOpts.Params = []string{"password=topsecret"} + + err := installOpts.Validate(ctx, []string{}, p.Porter) + require.NoError(t, err) + + err = p.InstallBundle(ctx, installOpts) + require.Error(t, err) + + output := p.TestConfig.TestContext.GetOutput() + require.NotContains(t, output, "topsecret", "expected sensitive data to not be logged") + require.Contains(t, output, "*******") +} diff --git a/tests/integration/testdata/bundles/failing-bundle-with-sensitive-data/helpers.sh b/tests/integration/testdata/bundles/failing-bundle-with-sensitive-data/helpers.sh new file mode 100755 index 000000000..379878574 --- /dev/null +++ b/tests/integration/testdata/bundles/failing-bundle-with-sensitive-data/helpers.sh @@ -0,0 +1,21 @@ +#!/usr/bin/env bash +set -euo pipefail + +install() { + echo Hello, $1 +} + +open_door() { + echo opening door using $1 +} + +upgrade() { + echo World 2.0 +} + +uninstall() { + echo Goodbye World +} + +# Call the requested function and pass the arguments as-is +"$@" diff --git a/tests/integration/testdata/bundles/failing-bundle-with-sensitive-data/porter.yaml b/tests/integration/testdata/bundles/failing-bundle-with-sensitive-data/porter.yaml new file mode 100644 index 000000000..eccf9d949 --- /dev/null +++ b/tests/integration/testdata/bundles/failing-bundle-with-sensitive-data/porter.yaml @@ -0,0 +1,50 @@ +schemaVersion: 1.0.0-alpha.1 +name: mybuns +version: 0.1.2 +description: "A test bundle for sensitive data" +registry: localhost:5000 + +parameters: + - name: name + description: "author name" + type: string + default: "porter" + - name: password + description: "The super secret data" + type: string + sensitive: true + +outputs: + - name: mylogs + applyTo: + - install + - upgrade + - name: result + applyTo: + - install + sensitive: true + +mixins: + - exec + +install: + - exec: + description: "Failing step to test sensitive data logging" + command: fail + arguments: + - open_door + - "{{ bundle.parameters.password }}" + +upgrade: + - exec: + description: "upgrade" + command: ./helpers.sh + arguments: + - upgrade + +uninstall: + - exec: + description: "uninstall" + command: ./helpers.sh + arguments: + - uninstall