VAULT-24798: audit - improve error messages

audit/entry_filter.go

@@ -11,7 +11,6 @@ import (
 	"github.com/hashicorp/eventlogger"
 	"github.com/hashicorp/go-bexpr"
 	"github.com/hashicorp/vault/helper/namespace"
-	"github.com/hashicorp/vault/internal/observability/event"
 	"github.com/hashicorp/vault/sdk/logical"
 )
 
@@ -27,16 +26,14 @@ type EntryFilter struct {
 // NewEntryFilter should be used to create an EntryFilter node.
 // The filter supplied should be in bexpr format and reference fields from logical.LogInputBexpr.
 func NewEntryFilter(filter string) (*EntryFilter, error) {
-	const op = "audit.NewEntryFilter"
-
 	filter = strings.TrimSpace(filter)
 	if filter == "" {
-		return nil, fmt.Errorf("%s: cannot create new audit filter with empty filter expression: %w", op, event.ErrInvalidParameter)
+		return nil, fmt.Errorf("cannot create new audit filter with empty filter expression: %w", ErrExternalOptions)
 	}
 
 	eval, err := bexpr.CreateEvaluator(filter)
 	if err != nil {
-		return nil, fmt.Errorf("%s: cannot create new audit filter: %w", op, err)
+		return nil, fmt.Errorf("cannot create new audit filter: %w: %w", ErrExternalOptions, err)
 	}
 
 	// Validate the filter by attempting to evaluate it with an empty input.
@@ -45,7 +42,7 @@ func NewEntryFilter(filter string) (*EntryFilter, error) {
 	li := logical.LogInputBexpr{}
 	_, err = eval.Evaluate(li)
 	if err != nil {
-		return nil, fmt.Errorf("%s: filter references an unsupported field: %s", op, filter)
+		return nil, fmt.Errorf("filter references an unsupported field: %s: %w: %w", filter, ErrExternalOptions, err)
 	}
 
 	return &EntryFilter{evaluator: eval}, nil
@@ -64,21 +61,19 @@ func (*EntryFilter) Type() eventlogger.NodeType {
 // Process will attempt to parse the incoming event data and decide whether it
 // should be filtered or remain in the pipeline and passed to the next node.
 func (f *EntryFilter) Process(ctx context.Context, e *eventlogger.Event) (*eventlogger.Event, error) {
-	const op = "audit.(EntryFilter).Process"
-
 	select {
 	case <-ctx.Done():
 		return nil, ctx.Err()
 	default:
 	}
 
 	if e == nil {
-		return nil, fmt.Errorf("%s: event is nil: %w", op, event.ErrInvalidParameter)
+		return nil, fmt.Errorf("event is nil: %w", ErrInvalidParameter)
 	}
 
 	a, ok := e.Payload.(*AuditEvent)
 	if !ok {
-		return nil, fmt.Errorf("%s: cannot parse event payload: %w", op, event.ErrInvalidParameter)
+		return nil, fmt.Errorf("cannot parse event payload: %w", ErrInvalidParameter)
 	}
 
 	// If we don't have data to process, then we're done.
@@ -88,14 +83,14 @@ func (f *EntryFilter) Process(ctx context.Context, e *eventlogger.Event) (*event
 
 	ns, err := namespace.FromContext(ctx)
 	if err != nil {
-		return nil, fmt.Errorf("%s: cannot obtain namespace: %w", op, err)
+		return nil, fmt.Errorf("cannot obtain namespace: %w", err)
 	}
 
 	datum := a.Data.BexprDatum(ns.Path)
 
 	result, err := f.evaluator.Evaluate(datum)
 	if err != nil {
-		return nil, fmt.Errorf("%s: unable to evaluate filter: %w", op, err)
+		return nil, fmt.Errorf("unable to evaluate filter: %w", err)
 	}
 
 	if result {

audit/entry_filter_test.go

@@ -27,22 +27,22 @@ func TestEntryFilter_NewEntryFilter(t *testing.T) {
 		"empty-filter": {
 			Filter:               "",
 			IsErrorExpected:      true,
-			ExpectedErrorMessage: "audit.NewEntryFilter: cannot create new audit filter with empty filter expression: invalid parameter",
+			ExpectedErrorMessage: "cannot create new audit filter with empty filter expression: invalid configuration",
 		},
 		"spacey-filter": {
 			Filter:               "    ",
 			IsErrorExpected:      true,
-			ExpectedErrorMessage: "audit.NewEntryFilter: cannot create new audit filter with empty filter expression: invalid parameter",
+			ExpectedErrorMessage: "cannot create new audit filter with empty filter expression: invalid configuration",
 		},
 		"bad-filter": {
 			Filter:               "____",
 			IsErrorExpected:      true,
-			ExpectedErrorMessage: "audit.NewEntryFilter: cannot create new audit filter",
+			ExpectedErrorMessage: "cannot create new audit filter",
 		},
 		"unsupported-field-filter": {
 			Filter:               "foo == bar",
 			IsErrorExpected:      true,
-			ExpectedErrorMessage: "audit.NewEntryFilter: filter references an unsupported field: foo == bar",
+			ExpectedErrorMessage: "filter references an unsupported field: foo == bar",
 		},
 		"good-filter-operation": {
 			Filter:          "operation == create",
@@ -122,7 +122,7 @@ func TestEntryFilter_Process_ContextDone(t *testing.T) {
 
 	// Fake event logger event
 	e := &eventlogger.Event{
-		Type:      eventlogger.EventType(event.AuditType.String()),
+		Type:      event.AuditType.AsEventType(),
 		CreatedAt: time.Now(),
 		Formatted: make(map[string][]byte),
 		Payload:   a,
@@ -146,7 +146,7 @@ func TestEntryFilter_Process_NilEvent(t *testing.T) {
 	require.NoError(t, err)
 	e, err := l.Process(context.Background(), nil)
 	require.Error(t, err)
-	require.EqualError(t, err, "audit.(EntryFilter).Process: event is nil: invalid parameter")
+	require.EqualError(t, err, "event is nil: invalid internal parameter")
 
 	// Ensure that the pipeline won't continue.
 	require.Nil(t, e)
@@ -162,15 +162,15 @@ func TestEntryFilter_Process_BadPayload(t *testing.T) {
 	require.NoError(t, err)
 
 	e := &eventlogger.Event{
-		Type:      eventlogger.EventType(event.AuditType.String()),
+		Type:      event.AuditType.AsEventType(),
 		CreatedAt: time.Now(),
 		Formatted: make(map[string][]byte),
 		Payload:   nil,
 	}
 
 	e2, err := l.Process(context.Background(), e)
 	require.Error(t, err)
-	require.EqualError(t, err, "audit.(EntryFilter).Process: cannot parse event payload: invalid parameter")
+	require.EqualError(t, err, "cannot parse event payload: invalid internal parameter")
 
 	// Ensure that the pipeline won't continue.
 	require.Nil(t, e2)
@@ -191,7 +191,7 @@ func TestEntryFilter_Process_NoAuditDataInPayload(t *testing.T) {
 	a.Data = nil
 
 	e := &eventlogger.Event{
-		Type:      eventlogger.EventType(event.AuditType.String()),
+		Type:      event.AuditType.AsEventType(),
 		CreatedAt: time.Now(),
 		Formatted: make(map[string][]byte),
 		Payload:   a,
@@ -223,7 +223,7 @@ func TestEntryFilter_Process_FilterSuccess(t *testing.T) {
 	}
 
 	e := &eventlogger.Event{
-		Type:      eventlogger.EventType(event.AuditType.String()),
+		Type:      event.AuditType.AsEventType(),
 		CreatedAt: time.Now(),
 		Formatted: make(map[string][]byte),
 		Payload:   a,
@@ -256,7 +256,7 @@ func TestEntryFilter_Process_FilterFail(t *testing.T) {
 	}
 
 	e := &eventlogger.Event{
-		Type:      eventlogger.EventType(event.AuditType.String()),
+		Type:      event.AuditType.AsEventType(),
 		CreatedAt: time.Now(),
 		Formatted: make(map[string][]byte),
 		Payload:   a,

audit/entry_formatter.go

@@ -18,7 +18,6 @@ import (
 	"github.com/hashicorp/go-hclog"
 	"github.com/hashicorp/go-multierror"
 	"github.com/hashicorp/vault/helper/namespace"
-	"github.com/hashicorp/vault/internal/observability/event"
 	"github.com/hashicorp/vault/sdk/helper/jsonutil"
 	"github.com/hashicorp/vault/sdk/helper/salt"
 	"github.com/hashicorp/vault/sdk/logical"
@@ -36,34 +35,92 @@ type timeProvider interface {
 	formattedTime() string
 }
 
+// FormatterConfig is used to provide basic configuration to a formatter.
+// Use NewFormatterConfig to initialize the FormatterConfig struct.
+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
+
+	// The required/target format for the event (supported: JSONFormat and JSONxFormat).
+	RequiredFormat format
+
+	// headerFormatter specifies the formatter used for headers that existing in any incoming audit request.
+	headerFormatter HeaderFormatter
+
+	// Prefix specifies a Prefix that should be prepended to any formatted request or response before serialization.
+	Prefix string
+}
+
 // EntryFormatter should be used to format audit requests and responses.
+// NOTE: Use NewEntryFormatter to initialize the EntryFormatter struct.
 type EntryFormatter struct {
 	config FormatterConfig
 	salter Salter
 	logger hclog.Logger
 	name   string
 }
 
+// NewFormatterConfig should be used to create a FormatterConfig.
+// Accepted options: WithElision, WithFormat, WithHMACAccessor, WithOmitTime, WithPrefix, WithRaw.
+func NewFormatterConfig(headerFormatter HeaderFormatter, opt ...Option) (FormatterConfig, error) {
+	if headerFormatter == nil || reflect.ValueOf(headerFormatter).IsNil() {
+		return FormatterConfig{}, fmt.Errorf("header formatter is required: %w", ErrInvalidParameter)
+	}
+
+	opts, err := getOpts(opt...)
+	if err != nil {
+		return FormatterConfig{}, err
+	}
+
+	return FormatterConfig{
+		headerFormatter:    headerFormatter,
+		ElideListResponses: opts.withElision,
+		HMACAccessor:       opts.withHMACAccessor,
+		OmitTime:           opts.withOmitTime,
+		Prefix:             opts.withPrefix,
+		Raw:                opts.withRaw,
+		RequiredFormat:     opts.withFormat,
+	}, nil
+}
+
 // NewEntryFormatter should be used to create an EntryFormatter.
 func NewEntryFormatter(name string, config FormatterConfig, salter Salter, logger hclog.Logger) (*EntryFormatter, error) {
-	const op = "audit.NewEntryFormatter"
-
 	name = strings.TrimSpace(name)
 	if name == "" {
-		return nil, fmt.Errorf("%s: name is required: %w", op, event.ErrInvalidParameter)
+		return nil, fmt.Errorf("name is required: %w", ErrInvalidParameter)
 	}
 
 	if salter == nil {
-		return nil, fmt.Errorf("%s: cannot create a new audit formatter with nil salter: %w", op, event.ErrInvalidParameter)
+		return nil, fmt.Errorf("cannot create a new audit formatter with nil salter: %w", ErrInvalidParameter)
 	}
 
 	if logger == nil || reflect.ValueOf(logger).IsNil() {
-		return nil, fmt.Errorf("%s: cannot create a new audit formatter with nil logger: %w", op, event.ErrInvalidParameter)
-	}
-
-	// We need to ensure that the format isn't just some default empty string.
-	if err := config.RequiredFormat.validate(); err != nil {
-		return nil, fmt.Errorf("%s: format not valid: %w", op, err)
+		return nil, fmt.Errorf("cannot create a new audit formatter with nil logger: %w", ErrInvalidParameter)
 	}
 
 	return &EntryFormatter{
@@ -87,8 +144,6 @@ func (*EntryFormatter) Type() eventlogger.NodeType {
 // Process will attempt to parse the incoming event data into a corresponding
 // audit Request/Response which is serialized to JSON/JSONx and stored within the event.
 func (f *EntryFormatter) Process(ctx context.Context, e *eventlogger.Event) (_ *eventlogger.Event, retErr error) {
-	const op = "audit.(EntryFormatter).Process"
-
 	// Return early if the context was cancelled, eventlogger will not carry on
 	// asking nodes to process, so any sink node in the pipeline won't be called.
 	select {
@@ -100,16 +155,16 @@ func (f *EntryFormatter) Process(ctx context.Context, e *eventlogger.Event) (_ *
 	// Perform validation on the event, then retrieve the underlying AuditEvent
 	// and LogInput (from the AuditEvent Data).
 	if e == nil {
-		return nil, fmt.Errorf("%s: event is nil: %w", op, event.ErrInvalidParameter)
+		return nil, fmt.Errorf("event is nil: %w", ErrInvalidParameter)
 	}
 
 	a, ok := e.Payload.(*AuditEvent)
 	if !ok {
-		return nil, fmt.Errorf("%s: cannot parse event payload: %w", op, event.ErrInvalidParameter)
+		return nil, fmt.Errorf("cannot parse event payload: %w", ErrInvalidParameter)
 	}
 
 	if a.Data == nil {
-		return nil, fmt.Errorf("%s: cannot audit event (%s) with no data: %w", op, a.Subtype, event.ErrInvalidParameter)
+		return nil, fmt.Errorf("cannot audit event (%s) with no data: %w", a.Subtype, ErrInvalidParameter)
 	}
 
 	// Handle panics
@@ -126,13 +181,13 @@ func (f *EntryFormatter) Process(ctx context.Context, e *eventlogger.Event) (_ *
 			"stacktrace", string(debug.Stack()))
 
 		// Ensure that we add this error onto any pre-existing error that was being returned.
-		retErr = multierror.Append(retErr, fmt.Errorf("%s: panic generating audit log: %q", op, f.name)).ErrorOrNil()
+		retErr = multierror.Append(retErr, fmt.Errorf("panic generating audit log: %q", f.name)).ErrorOrNil()
 	}()
 
 	// Take a copy of the event data before we modify anything.
 	data, err := a.Data.Clone()
 	if err != nil {
-		return nil, fmt.Errorf("%s: unable to copy audit event data: %w", op, err)
+		return nil, fmt.Errorf("unable to clone audit event data: %w", err)
 	}
 
 	// If the request is present in the input data, apply header configuration
@@ -144,7 +199,7 @@ func (f *EntryFormatter) Process(ctx context.Context, e *eventlogger.Event) (_ *
 		// e.g. via: /sys/config/auditing/request-headers/:name
 		data.Request.Headers, err = f.config.headerFormatter.ApplyConfig(ctx, data.Request.Headers, f.salter)
 		if err != nil {
-			return nil, fmt.Errorf("%s: unable to transform headers for auditing: %w", op, err)
+			return nil, fmt.Errorf("unable to transform headers for auditing: %w", err)
 		}
 	}
 
@@ -165,25 +220,25 @@ func (f *EntryFormatter) Process(ctx context.Context, e *eventlogger.Event) (_ *
 	case ResponseType:
 		entry, err = f.FormatResponse(ctx, data, a)
 	default:
-		return nil, fmt.Errorf("%s: unknown audit event subtype: %q", op, a.Subtype)
+		return nil, fmt.Errorf("unknown audit event subtype: %q", a.Subtype)
 	}
 	if err != nil {
-		return nil, fmt.Errorf("%s: unable to parse %s from audit event: %w", op, a.Subtype.String(), err)
+		return nil, fmt.Errorf("unable to parse %s from audit event: %w", a.Subtype, err)
 	}
 
 	result, err := jsonutil.EncodeJSON(entry)
 	if err != nil {
-		return nil, fmt.Errorf("%s: unable to format %s: %w", op, a.Subtype.String(), err)
+		return nil, fmt.Errorf("unable to format %s: %w", a.Subtype, err)
 	}
 
 	if f.config.RequiredFormat == JSONxFormat {
 		var err error
 		result, err = jsonx.EncodeJSONBytes(result)
 		if err != nil {
-			return nil, fmt.Errorf("%s: unable to encode JSONx using JSON data: %w", op, err)
+			return nil, fmt.Errorf("unable to encode JSONx using JSON data: %w", err)
 		}
 		if result == nil {
-			return nil, fmt.Errorf("%s: encoded JSONx was nil: %w", op, err)
+			return nil, fmt.Errorf("encoded JSONx was nil: %w", err)
 		}
 	}
 
@@ -569,31 +624,6 @@ func (f *EntryFormatter) FormatResponse(ctx context.Context, in *logical.LogInpu
 	return respEntry, nil
 }
 
-// NewFormatterConfig should be used to create a FormatterConfig.
-// Accepted options: WithElision, WithFormat, WithHMACAccessor, WithOmitTime, WithPrefix, WithRaw.
-func NewFormatterConfig(headerFormatter HeaderFormatter, opt ...Option) (FormatterConfig, error) {
-	const op = "audit.NewFormatterConfig"
-
-	if headerFormatter == nil || reflect.ValueOf(headerFormatter).IsNil() {
-		return FormatterConfig{}, fmt.Errorf("%s: header formatter is required: %w", op, event.ErrInvalidParameter)
-	}
-
-	opts, err := getOpts(opt...)
-	if err != nil {
-		return FormatterConfig{}, fmt.Errorf("%s: error applying options: %w", op, err)
-	}
-
-	return FormatterConfig{
-		headerFormatter:    headerFormatter,
-		ElideListResponses: opts.withElision,
-		HMACAccessor:       opts.withHMACAccessor,
-		OmitTime:           opts.withOmitTime,
-		Prefix:             opts.withPrefix,
-		Raw:                opts.withRaw,
-		RequiredFormat:     opts.withFormat,
-	}, nil
-}
-
 // getRemoteAddr safely gets the remote address avoiding a nil pointer
 func getRemoteAddr(req *logical.Request) string {
 	if req != nil && req.Connection != nil {