Scrubbing env vars from logs

cmd/containerd-shim-runhcs-v1/options/runhcs.proto

@@ -105,6 +105,9 @@ message Options {
 	// no_inherit_host_timezone specifies to skip inheriting the hosts time zone for WCOW UVMs and instead default to
 	// UTC.
 	bool no_inherit_host_timezone = 19;
+
+	// scrub_logs enables removing environment variables and other protentially sensitive information form logs
+	bool scrub_logs = 20;
 }
 
 // ProcessDetails contains additional information about a process. This is the additional

cmd/containerd-shim-runhcs-v1/serve.go

@@ -14,6 +14,7 @@ import (
 	"github.com/Microsoft/go-winio"
 	runhcsopts "github.com/Microsoft/hcsshim/cmd/containerd-shim-runhcs-v1/options"
 	"github.com/Microsoft/hcsshim/internal/extendedtask"
+	"github.com/Microsoft/hcsshim/internal/scrub"
 	"github.com/Microsoft/hcsshim/internal/shimdiag"
 	"github.com/Microsoft/hcsshim/pkg/octtrpc"
 	"github.com/containerd/containerd/log"
@@ -84,7 +85,7 @@ var serveCommand = cli.Command{
 		}
 
 		if shimOpts.Debug && shimOpts.LogLevel != "" {
-			logrus.Warning("Both Debug and LogLevel specified, Debug will be overriden")
+			logrus.Warning("Both Debug and LogLevel specified, Debug will be overridden")
 		}
 
 		// For now keep supporting the debug option, this used to be the only way to specify a different logging
@@ -158,6 +159,11 @@ var serveCommand = cli.Command{
 
 		os.Stdin.Close()
 
+		// enable scrubbing
+		if shimOpts.ScrubLogs {
+			scrub.SetScrubbing(true)
+		}
+
 		// Force the cli.ErrWriter to be os.Stdout for this. We use stderr for
 		// the panic.log attached via start.
 		cli.ErrWriter = os.Stdout

internal/gcs/bridge.go

@@ -15,6 +15,7 @@ import (
 	"syscall"
 	"time"
 
+	"github.com/Microsoft/hcsshim/internal/scrub"
 	"github.com/sirupsen/logrus"
 	"golang.org/x/sys/windows"
 )
@@ -365,6 +366,7 @@ func (brdg *bridge) recvLoop() error {
 func (brdg *bridge) sendLoop() {
 	var buf bytes.Buffer
 	enc := json.NewEncoder(&buf)
+	enc.SetEscapeHTML(false)
 	for {
 		select {
 		case <-brdg.waitCh:
@@ -392,11 +394,26 @@ func (brdg *bridge) writeMessage(buf *bytes.Buffer, enc *json.Encoder, typ msgTy
 	}
 	// Update the message header with the size.
 	binary.LittleEndian.PutUint32(buf.Bytes()[hdrOffSize:], uint32(buf.Len()))
+
+	if brdg.log.Logger.GetLevel() >= logrus.DebugLevel {
+		b := buf.Bytes()[hdrSize:]
+		switch typ {
+		// container environment vars are in rpCreate for linux; rpcExecuteProcess for windows
+		case msgType(rpcCreate) | msgTypeRequest:
+			b, err = scrub.BridgeCreate(b)
+		case msgType(rpcExecuteProcess) | msgTypeRequest:
+			b, err = scrub.BridgeExecProcess(b)
+		}
+		if err != nil {
+			brdg.log.WithError(err).Warning("could not scrub bridge payload")
+		}
+		brdg.log.WithFields(logrus.Fields{
+			"payload":    string(b),
+			"type":       typ,
+			"message-id": id}).Debug("bridge send")
+	}
+
 	// Write the message.
-	brdg.log.WithFields(logrus.Fields{
-		"payload":    string(buf.Bytes()[hdrSize:]),
-		"type":       typ,
-		"message-id": id}).Debug("bridge send")
 	_, err = buf.WriteTo(brdg.conn)
 	if err != nil {
 		return fmt.Errorf("bridge write: %s", err)

internal/scrub/scrub.go

@@ -0,0 +1,174 @@
+// This package scrubs objects of customer information to pass to logging
+package scrub
+
+import (
+	"bytes"
+	"encoding/json"
+	"errors"
+	"sync/atomic"
+
+	hcsschema "github.com/Microsoft/hcsshim/internal/hcs/schema2"
+)
+
+// scrubbing utilities to remove user information from arbitrary objects
+
+type genMap = map[string]interface{}
+type scrubberFunc func(genMap) error
+
+const ScrubbedReplacement = "<scrubbed>"
+
+var (
+	ErrUnknownType = errors.New("encoded object is of unknown type")
+
+	// case sensitive keywords, so "env" is not a substring on "Environment"
+	_scrubKeywords = [][]byte{[]byte("env"), []byte("Environment")}
+
+	_scrub int32
+)
+
+// SetScrubbing enables scrubbing
+func SetScrubbing(enable bool) {
+	v := int32(0) // cant convert from bool to int32 directly
+	if enable {
+		v = 1
+	}
+	atomic.StoreInt32(&_scrub, v)
+}
+
+// ScrubbingEnabled checks if scrubbing is enabled
+func ScrubbingEnabled() bool {
+	v := atomic.LoadInt32(&_scrub)
+	return v != 0
+}
+
+// for HCS Create Process requests with config parameters of
+// type internal/hcs/schema2.ProcessParameters (aka hcsshema.ProcessParameters)
+func ProcessParameters(s string) (string, error) {
+	// todo: deal with v1 ProcessConfig
+	b := []byte(s)
+	if !ScrubbingEnabled() || !hasKeywords(b) || !json.Valid(b) {
+		return s, nil
+	}
+
+	pp := hcsschema.ProcessParameters{}
+	if err := json.Unmarshal(b, &pp); err != nil {
+		return "", err
+	}
+	pp.Environment = map[string]string{ScrubbedReplacement: ScrubbedReplacement}
+
+	buf := bytes.NewBuffer(b[:0])
+	if err := encode(buf, pp); err != nil {
+		return "", err
+	}
+	return buf.String(), nil
+}
+
+// for requests sent over the bridge of type
+// internal/gcs/protocol.containerCreate wrapping a internal/hcsoci.linuxHostedSystem
+func BridgeCreate(b []byte) ([]byte, error) {
+	return scrubBytes(b, scrubLinuxHostedSystem)
+}
+
+func scrubLinuxHostedSystem(m genMap) error {
+	if !isRequestBase(m) {
+		return ErrUnknownType
+	}
+	if m, ok := index(m, "ContainerConfig"); ok {
+		if m, ok := index(m, "OciSpecification"); ok {
+			if m, ok := index(m, "process"); ok {
+				if _, ok := m["env"]; ok {
+					m["env"] = []string{ScrubbedReplacement}
+					return nil
+				}
+			}
+		}
+	}
+	return ErrUnknownType
+}
+
+// for requests sent over the bridge of type internal/gcs/protocol.containerExecuteProcess
+func BridgeExecProcess(b []byte) ([]byte, error) {
+	return scrubBytes(b, scrubExecuteProcess)
+}
+
+func scrubExecuteProcess(m genMap) error {
+	if !isRequestBase(m) {
+		return ErrUnknownType
+	}
+	if m, ok := index(m, "Settings"); ok {
+		if ss, ok := m["ProcessParameters"]; ok {
+			// ProcessParameters is a json encoded struct passed as a regular sting field
+			s, ok := ss.(string)
+			if !ok {
+				return ErrUnknownType
+			}
+
+			s, err := ProcessParameters(s)
+			if err != nil {
+				return err
+			}
+
+			m["ProcessParameters"] = s
+			return nil
+		}
+	}
+	return ErrUnknownType
+}
+
+func scrubBytes(b []byte, scrub scrubberFunc) ([]byte, error) {
+	if !ScrubbingEnabled() || !hasKeywords(b) || !json.Valid(b) {
+		return b, nil
+	}
+
+	m := make(genMap)
+	if err := json.Unmarshal(b, &m); err != nil {
+		return nil, err
+	}
+
+	// could use regexp, but if the env strings contain braces, the regexp fails
+	// parsing into individual structs would require access to private structs
+	if err := scrub(m); err != nil {
+		return nil, err
+	}
+
+	buf := &bytes.Buffer{}
+	if err := encode(buf, m); err != nil {
+		return nil, err
+	}
+	return buf.Bytes(), nil
+}
+
+func encode(buf *bytes.Buffer, v interface{}) error {
+	enc := json.NewEncoder(buf)
+	enc.SetEscapeHTML(false)
+	if err := enc.Encode(v); err != nil {
+		return err
+	}
+	return nil
+}
+
+func isRequestBase(m genMap) bool {
+	// neither of these are (currently) `omitempty`
+	_, a := m["ActivityId"]
+	_, c := m["ContainerId"]
+	return a && c
+}
+
+// combination `m, ok := m[s]` and `m, ok := m.(genMap)`
+func index(m genMap, s string) (genMap, bool) {
+	if m, ok := m[s]; ok {
+		mm, ok := m.(genMap)
+		return mm, ok
+	}
+
+	return m, false
+}
+
+func hasKeywords(b []byte) bool {
+	for _, bb := range _scrubKeywords {
+		if bytes.Contains(b, bb) {
+			return true
+		}
+	}
+	return false
+}

internal/vmcompute/vmcompute.go

@@ -9,6 +9,7 @@ import (
 	"github.com/Microsoft/hcsshim/internal/log"
 	"github.com/Microsoft/hcsshim/internal/logfields"
 	"github.com/Microsoft/hcsshim/internal/oc"
+	"github.com/Microsoft/hcsshim/internal/scrub"
 	"github.com/Microsoft/hcsshim/internal/timeout"
 	"go.opencensus.io/trace"
 )
@@ -389,7 +390,12 @@ func HcsCreateProcess(ctx gcontext.Context, computeSystem HcsSystem, processPara
 		}
 		oc.SetSpanStatus(span, hr)
 	}()
-	span.AddAttributes(trace.StringAttribute("processParameters", processParameters))
+	if span.IsRecordingEvents() {
+		// wont handle v1 process parameters
+		if s, err := scrub.ProcessParameters(processParameters); err == nil {
+			span.AddAttributes(trace.StringAttribute("processParameters", s))
+		}
+	}
 
 	return processInformation, process, result, execute(ctx, timeout.SyscallWatcher, func() error {
 		var resultp *uint16