Add option 'elide_list_responses' to audit backends (hashicorp#18128)

This PR relates to a feature request logged through HashiCorp commercial
support.

Vault lacks pagination in its APIs. As a result, certain list operations
can return **very** large responses.  The user's chosen audit sinks may
experience difficulty consuming audit records that swell to tens of
megabytes of JSON.

In our case, one of the systems consuming audit log data could not cope,
and failed.

The responses of list operations are typically not very interesting, as
they are mostly lists of keys, or, even when they include a "key_info"
field, are not returning confidential information. They become even less
interesting once HMAC-ed by the audit system.

Some example Vault "list" operations that are prone to becoming very
large in an active Vault installation are:

    auth/token/accessors/
    identity/entity/id/
    identity/entity-alias/id/
    pki/certs/

In response, I've coded a new option that can be applied to audit
backends, `elide_list_responses`. When enabled, response data is elided
from audit logs, only when the operation type is "list".

For added safety, the elision only applies to the "keys" and "key_info"
fields within the response data - these are conventionally the only
fields present in a list response - see logical.ListResponse, and
logical.ListResponseWithInfo. However, other fields are technically
possible if a plugin author writes unusual code, and these will be
preserved in the audit log even with this option enabled.

The elision replaces the values of the "keys" and "key_info" fields with
an integer count of the number of entries. This allows even the elided
audit logs to still be useful for answering questions like "Was any data
returned?" or "How many records were listed?".

Author: maxb

audit/format.go

@@ -192,7 +192,24 @@ func (f *AuditFormatter) FormatResponse(ctx context.Context, w io.Writer, config
 		connState = in.Request.Connection.ConnState
 	}
 
-	if !config.Raw {
+	elideListResponseData := config.ElideListResponses && req.Operation == logical.ListOperation
+
+	var respData map[string]interface{}
+	if config.Raw {
+		// In the non-raw case, elision of list response data occurs inside HashResponse, to avoid redundant deep
+		// copies and hashing of data only to elide it later. In the raw case, we need to do it here.
+		if elideListResponseData && resp.Data != nil {
+			// Copy the data map before making changes, but we only need to go one level deep in this case
+			respData = make(map[string]interface{}, len(resp.Data))
+			for k, v := range resp.Data {
+				respData[k] = v
+			}
+
+			doElideListResponseData(respData)
+		} else {
+			respData = resp.Data
+		}
+	} else {
 		auth, err = HashAuth(salt, auth, config.HMACAccessor)
 		if err != nil {
 			return err
@@ -203,10 +220,12 @@ func (f *AuditFormatter) FormatResponse(ctx context.Context, w io.Writer, config
 			return err
 		}
 
-		resp, err = HashResponse(salt, resp, config.HMACAccessor, in.NonHMACRespDataKeys)
+		resp, err = HashResponse(salt, resp, config.HMACAccessor, in.NonHMACRespDataKeys, elideListResponseData)
 		if err != nil {
 			return err
 		}
+
+		respData = resp.Data
 	}
 
 	var errString string
@@ -315,7 +334,7 @@ func (f *AuditFormatter) FormatResponse(ctx context.Context, w io.Writer, config
 			MountAccessor: req.MountAccessor,
 			Auth:          respAuth,
 			Secret:        respSecret,
-			Data:          resp.Data,
+			Data:          respData,
 			Warnings:      resp.Warnings,
 			Redirect:      resp.Redirect,
 			WrapInfo:      respWrapInfo,
@@ -495,7 +514,7 @@ func parseVaultTokenFromJWT(token string) *string {
 	return &claims.ID
 }
 
-// Create a formatter not backed by a persistent salt.
+// NewTemporaryFormatter creates a formatter not backed by a persistent salt
 func NewTemporaryFormatter(format, prefix string) *AuditFormatter {
 	temporarySalt := func(ctx context.Context) (*salt.Salt, error) {
 		return salt.NewNonpersistentSalt(), nil
@@ -516,3 +535,22 @@ func NewTemporaryFormatter(format, prefix string) *AuditFormatter {
 	}
 	return ret
 }
+
+// doElideListResponseData performs the actual elision of list operation response data, once surrounding code has
+// determined it should apply to a particular request. The data map that is passed in must be a copy that is safe to
+// modify in place, but need not be a full recursive deep copy, as only top-level keys are changed.
+//
+// See the documentation of the controlling option in FormatterConfig for more information on the purpose.
+func doElideListResponseData(data map[string]interface{}) {
+	for k, v := range data {
+		if k == "keys" {
+			if vSlice, ok := v.([]string); ok {
+				data[k] = len(vSlice)
+			}
+		} else if k == "key_info" {
+			if vMap, ok := v.(map[string]interface{}); ok {
+				data[k] = len(vMap)
+			}
+		}
+	}
+}

audit/format_test.go

@@ -3,45 +3,74 @@ package audit
 import (
 	"context"
 	"io"
-	"io/ioutil"
 	"testing"
 
+	"github.com/hashicorp/vault/helper/namespace"
 	"github.com/hashicorp/vault/sdk/helper/salt"
 	"github.com/hashicorp/vault/sdk/logical"
+	"github.com/mitchellh/copystructure"
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
 )
 
-type noopFormatWriter struct {
-	salt     *salt.Salt
-	SaltFunc func() (*salt.Salt, error)
+type testingFormatWriter struct {
+	salt         *salt.Salt
+	lastRequest  *AuditRequestEntry
+	lastResponse *AuditResponseEntry
 }
 
-func (n *noopFormatWriter) WriteRequest(_ io.Writer, _ *AuditRequestEntry) error {
+func (fw *testingFormatWriter) WriteRequest(_ io.Writer, entry *AuditRequestEntry) error {
+	fw.lastRequest = entry
 	return nil
 }
 
-func (n *noopFormatWriter) WriteResponse(_ io.Writer, _ *AuditResponseEntry) error {
+func (fw *testingFormatWriter) WriteResponse(_ io.Writer, entry *AuditResponseEntry) error {
+	fw.lastResponse = entry
 	return nil
 }
 
-func (n *noopFormatWriter) Salt(ctx context.Context) (*salt.Salt, error) {
-	if n.salt != nil {
-		return n.salt, nil
+func (fw *testingFormatWriter) Salt(ctx context.Context) (*salt.Salt, error) {
+	if fw.salt != nil {
+		return fw.salt, nil
 	}
 	var err error
-	n.salt, err = salt.NewSalt(ctx, nil, nil)
+	fw.salt, err = salt.NewSalt(ctx, nil, nil)
 	if err != nil {
 		return nil, err
 	}
-	return n.salt, nil
+	return fw.salt, nil
+}
+
+// hashExpectedValueForComparison replicates enough of the audit HMAC process on a piece of expected data in a test,
+// so that we can use assert.Equal to compare the expected and output values.
+func (fw *testingFormatWriter) hashExpectedValueForComparison(input map[string]interface{}) map[string]interface{} {
+	// Copy input before modifying, since we may re-use the same data in another test
+	copied, err := copystructure.Copy(input)
+	if err != nil {
+		panic(err)
+	}
+	copiedAsMap := copied.(map[string]interface{})
+
+	salter, err := fw.Salt(context.Background())
+	if err != nil {
+		panic(err)
+	}
+
+	err = hashMap(salter.GetIdentifiedHMAC, copiedAsMap, nil)
+	if err != nil {
+		panic(err)
+	}
+
+	return copiedAsMap
 }
 
 func TestFormatRequestErrors(t *testing.T) {
 	config := FormatterConfig{}
 	formatter := AuditFormatter{
-		AuditFormatWriter: &noopFormatWriter{},
+		AuditFormatWriter: &testingFormatWriter{},
 	}
 
-	if err := formatter.FormatRequest(context.Background(), ioutil.Discard, config, &logical.LogInput{}); err == nil {
+	if err := formatter.FormatRequest(context.Background(), io.Discard, config, &logical.LogInput{}); err == nil {
 		t.Fatal("expected error due to nil request")
 	}
 
@@ -56,10 +85,10 @@ func TestFormatRequestErrors(t *testing.T) {
 func TestFormatResponseErrors(t *testing.T) {
 	config := FormatterConfig{}
 	formatter := AuditFormatter{
-		AuditFormatWriter: &noopFormatWriter{},
+		AuditFormatWriter: &testingFormatWriter{},
 	}
 
-	if err := formatter.FormatResponse(context.Background(), ioutil.Discard, config, &logical.LogInput{}); err == nil {
+	if err := formatter.FormatResponse(context.Background(), io.Discard, config, &logical.LogInput{}); err == nil {
 		t.Fatal("expected error due to nil request")
 	}
 
@@ -70,3 +99,123 @@ func TestFormatResponseErrors(t *testing.T) {
 		t.Fatal("expected error due to nil writer")
 	}
 }
+
+func TestElideListResponses(t *testing.T) {
+	tfw := testingFormatWriter{}
+	formatter := AuditFormatter{&tfw}
+	ctx := namespace.RootContext(context.Background())
+
+	type test struct {
+		name         string
+		inputData    map[string]interface{}
+		expectedData map[string]interface{}
+	}
+
+	tests := []test{
+		{
+			"nil data",
+			nil,
+			nil,
+		},
+		{
+			"Normal list (keys only)",
+			map[string]interface{}{
+				"keys": []string{"foo", "bar", "baz"},
+			},
+			map[string]interface{}{
+				"keys": 3,
+			},
+		},
+		{
+			"Enhanced list (has key_info)",
+			map[string]interface{}{
+				"keys": []string{"foo", "bar", "baz", "quux"},
+				"key_info": map[string]interface{}{
+					"foo":  "alpha",
+					"bar":  "beta",
+					"baz":  "gamma",
+					"quux": "delta",
+				},
+			},
+			map[string]interface{}{
+				"keys":     4,
+				"key_info": 4,
+			},
+		},
+		{
+			"Unconventional other values in a list response are not touched",
+			map[string]interface{}{
+				"keys":           []string{"foo", "bar"},
+				"something_else": "baz",
+			},
+			map[string]interface{}{
+				"keys":           2,
+				"something_else": "baz",
+			},
+		},
+		{
+			"Conventional values in a list response are not elided if their data types are unconventional",
+			map[string]interface{}{
+				"keys": map[string]interface{}{
+					"You wouldn't expect keys to be a map": nil,
+				},
+				"key_info": []string{
+					"You wouldn't expect key_info to be a slice",
+				},
+			},
+			map[string]interface{}{
+				"keys": map[string]interface{}{
+					"You wouldn't expect keys to be a map": nil,
+				},
+				"key_info": []string{
+					"You wouldn't expect key_info to be a slice",
+				},
+			},
+		},
+	}
+	oneInterestingTestCase := tests[2]
+
+	formatResponse := func(
+		t *testing.T,
+		config FormatterConfig,
+		operation logical.Operation,
+		inputData map[string]interface{},
+	) {
+		err := formatter.FormatResponse(ctx, io.Discard, config, &logical.LogInput{
+			Request:  &logical.Request{Operation: operation},
+			Response: &logical.Response{Data: inputData},
+		})
+		require.Nil(t, err)
+	}
+
+	t.Run("Default case", func(t *testing.T) {
+		config := FormatterConfig{ElideListResponses: true}
+		for _, tc := range tests {
+			t.Run(tc.name, func(t *testing.T) {
+				formatResponse(t, config, logical.ListOperation, tc.inputData)
+				assert.Equal(t, tfw.hashExpectedValueForComparison(tc.expectedData), tfw.lastResponse.Response.Data)
+			})
+		}
+	})
+
+	t.Run("When Operation is not list, eliding does not happen", func(t *testing.T) {
+		config := FormatterConfig{ElideListResponses: true}
+		tc := oneInterestingTestCase
+		formatResponse(t, config, logical.ReadOperation, tc.inputData)
+		assert.Equal(t, tfw.hashExpectedValueForComparison(tc.inputData), tfw.lastResponse.Response.Data)
+	})
+
+	t.Run("When ElideListResponses is false, eliding does not happen", func(t *testing.T) {
+		config := FormatterConfig{ElideListResponses: false}
+		tc := oneInterestingTestCase
+		formatResponse(t, config, logical.ListOperation, tc.inputData)
+		assert.Equal(t, tfw.hashExpectedValueForComparison(tc.inputData), tfw.lastResponse.Response.Data)
+	})
+
+	t.Run("When Raw is true, eliding still happens", func(t *testing.T) {
+		config := FormatterConfig{ElideListResponses: true, Raw: true}
+		tc := oneInterestingTestCase
+		formatResponse(t, config, logical.ListOperation, tc.inputData)
+		assert.Equal(t, tc.expectedData, tfw.lastResponse.Response.Data)
+	})
+}

audit/formatter.go

@@ -7,7 +7,7 @@ import (
 	"github.com/hashicorp/vault/sdk/logical"
 )
 
-// Formatter is an interface that is responsible for formating a
+// Formatter is an interface that is responsible for formatting a
 // request/response into some format. Formatters write their output
 // to an io.Writer.
 //
@@ -21,6 +21,28 @@ type FormatterConfig struct {
 	Raw          bool
 	HMACAccessor bool
 
+	// Vault lacks pagination in its APIs. As a result, certain list operations can return **very** large responses.
+	// The user's chosen audit sinks may experience difficulty consuming audit records that swell to tens of megabytes
+	// of JSON. The responses of list operations are typically not very interesting, as they are mostly lists of keys,
+	// or, even when they include a "key_info" field, are not returning confidential information. They become even less
+	// interesting once HMAC-ed by the audit system.
+	//
+	// Some example Vault "list" operations that are prone to becoming very large in an active Vault installation are:
+	//   auth/token/accessors/
+	//   identity/entity/id/
+	//   identity/entity-alias/id/
+	//   pki/certs/
+	//
+	// This option exists to provide such users with the option to have response data elided from audit logs, only when
+	// the operation type is "list". For added safety, the elision only applies to the "keys" and "key_info" fields
+	// within the response data - these are conventionally the only fields present in a list response - see
+	// logical.ListResponse, and logical.ListResponseWithInfo. However, other fields are technically possible if a
+	// plugin author writes unusual code, and these will be preserved in the audit log even with this option enabled.
+	// The elision replaces the values of the "keys" and "key_info" fields with an integer count of the number of
+	// entries. This allows even the elided audit logs to still be useful for answering questions like
+	// "Was any data returned?" or "How many records were listed?".
+	ElideListResponses bool
+
 	// This should only ever be used in a testing context
 	OmitTime bool
 }

audit/hashstructure.go

@@ -98,7 +98,13 @@ func hashMap(fn func(string) string, data map[string]interface{}, nonHMACDataKey
 }
 
 // HashResponse returns a hashed copy of the logical.Request input.
-func HashResponse(salter *salt.Salt, in *logical.Response, HMACAccessor bool, nonHMACDataKeys []string) (*logical.Response, error) {
+func HashResponse(
+	salter *salt.Salt,
+	in *logical.Response,
+	HMACAccessor bool,
+	nonHMACDataKeys []string,
+	elideListResponseData bool,
+) (*logical.Response, error) {
 	if in == nil {
 		return nil, nil
 	}
@@ -129,12 +135,20 @@ func HashResponse(salter *salt.Salt, in *logical.Response, HMACAccessor bool, no
 			mapCopy[logical.HTTPRawBody] = string(b)
 		}
 
+		// Processing list response data elision takes place at this point in the code for performance reasons:
+		// - take advantage of the deep copy of resp.Data that was going to be done anyway for hashing
+		// - but elide data before potentially spending time hashing it
+		if elideListResponseData {
+			doElideListResponseData(mapCopy)
+		}
+
 		err = hashMap(fn, mapCopy, nonHMACDataKeys)
 		if err != nil {
 			return nil, err
 		}
 		resp.Data = mapCopy
 	}
+
 	if resp.WrapInfo != nil {
 		var err error
 		resp.WrapInfo, err = HashWrapInfo(salter, resp.WrapInfo, HMACAccessor)

audit/hashstructure_test.go

@@ -293,7 +293,7 @@ func TestHashResponse(t *testing.T) {
 	}
 	for _, tc := range cases {
 		input := fmt.Sprintf("%#v", tc.Input)
-		out, err := HashResponse(localSalt, tc.Input, tc.HMACAccessor, tc.NonHMACDataKeys)
+		out, err := HashResponse(localSalt, tc.Input, tc.HMACAccessor, tc.NonHMACDataKeys, false)
 		if err != nil {
 			t.Fatalf("err: %s\n\n%s", err, input)
 		}