Audit: optional logger for sinks will log on errors when context is done (#27859)

* Added optional logger for sink nodes (supplied by backends) will log on errors when context is also done

* changelog

audit/backend_file.go

@@ -76,12 +76,12 @@ func newFileBackend(conf *BackendConfig, headersConfig HeaderFormatter) (*FileBa
 		return nil, err
 	}
 
-	var opt []event.Option
+	sinkOpts := []event.Option{event.WithLogger(conf.Logger)}
 	if mode, ok := conf.Config[optionMode]; ok {
-		opt = append(opt, event.WithFileMode(mode))
+		sinkOpts = append(sinkOpts, event.WithFileMode(mode))
 	}
 
-	err = b.configureSinkNode(conf.MountPath, filePath, cfg.requiredFormat, opt...)
+	err = b.configureSinkNode(conf.MountPath, filePath, cfg.requiredFormat, sinkOpts...)
 	if err != nil {
 		return nil, err
 	}

audit/backend_socket.go

@@ -70,6 +70,7 @@ func newSocketBackend(conf *BackendConfig, headersConfig HeaderFormatter) (*Sock
 	sinkOpts := []event.Option{
 		event.WithSocketType(socketType),
 		event.WithMaxDuration(writeDeadline),
+		event.WithLogger(conf.Logger),
 	}
 
 	err = event.ValidateOptions(sinkOpts...)

audit/backend_syslog.go

@@ -60,6 +60,7 @@ func newSyslogBackend(conf *BackendConfig, headersConfig HeaderFormatter) (*Sysl
 	sinkOpts := []event.Option{
 		event.WithFacility(facility),
 		event.WithTag(tag),
+		event.WithLogger(conf.Logger),
 	}
 
 	err = event.ValidateOptions(sinkOpts...)

changelog/27859.txt

@@ -0,0 +1,4 @@
+```release-note:improvement
+audit: sinks (file, socket, syslog) will attempt to log errors to the server operational 
+log before returning (if there are errors to log, and the context is done).
+```

internal/observability/event/options.go

@@ -6,10 +6,12 @@ package event
 import (
 	"fmt"
 	"os"
+	"reflect"
 	"strconv"
 	"strings"
 	"time"
 
+	"github.com/hashicorp/go-hclog"
 	"github.com/hashicorp/go-secure-stdlib/parseutil"
 	"github.com/hashicorp/go-uuid"
 )
@@ -26,6 +28,7 @@ type options struct {
 	withSocketType  string
 	withMaxDuration time.Duration
 	withFileMode    *os.FileMode
+	withLogger      hclog.Logger
 }
 
 // getDefaultOptions returns Options with their default values.
@@ -201,3 +204,15 @@ func WithFileMode(mode string) Option {
 		return nil
 	}
 }
+
+// WithLogger provides an Option to supply a logger which will be used to write logs.
+// NOTE: If no logger is supplied then logging may not be possible.
+func WithLogger(l hclog.Logger) Option {
+	return func(o *options) error {
+		if l != nil && !reflect.ValueOf(l).IsNil() {
+			o.withLogger = l
+		}
+
+		return nil
+	}
+}

internal/observability/event/options_test.go

@@ -8,6 +8,7 @@ import (
 	"testing"
 	"time"
 
+	"github.com/hashicorp/go-hclog"
 	"github.com/stretchr/testify/require"
 )
 
@@ -423,3 +424,37 @@ func TestOptions_WithFileMode(t *testing.T) {
 		})
 	}
 }
+
+// TestOptions_WithLogger exercises WithLogger Option to ensure it performs as expected.
+func TestOptions_WithLogger(t *testing.T) {
+	t.Parallel()
+
+	tests := map[string]struct {
+		value         hclog.Logger
+		isNilExpected bool
+	}{
+		"nil-pointer": {
+			value:         nil,
+			isNilExpected: true,
+		},
+		"logger": {
+			value: hclog.NewNullLogger(),
+		},
+	}
+
+	for name, tc := range tests {
+		t.Run(name, func(t *testing.T) {
+			t.Parallel()
+
+			opts := &options{}
+			applyOption := WithLogger(tc.value)
+			err := applyOption(opts)
+			require.NoError(t, err)
+			if tc.isNilExpected {
+				require.Nil(t, opts.withLogger)
+			} else {
+				require.NotNil(t, opts.withLogger)
+			}
+		})
+	}
+}

internal/observability/event/sink_file.go

@@ -14,6 +14,7 @@ import (
 	"sync"
 
 	"github.com/hashicorp/eventlogger"
+	"github.com/hashicorp/go-hclog"
 )
 
 // defaultFileMode is the default file permissions (read/write for everyone).
@@ -31,6 +32,7 @@ type FileSink struct {
 	fileMode       os.FileMode
 	path           string
 	requiredFormat string
+	logger         hclog.Logger
 }
 
 // NewFileSink should be used to create a new FileSink.
@@ -69,6 +71,7 @@ func NewFileSink(path string, format string, opt ...Option) (*FileSink, error) {
 		fileMode:       mode,
 		requiredFormat: format,
 		path:           p,
+		logger:         opts.withLogger,
 	}
 
 	// Ensure that the file can be successfully opened for writing;
@@ -82,13 +85,22 @@ func NewFileSink(path string, format string, opt ...Option) (*FileSink, error) {
 }
 
 // Process handles writing the event to the file sink.
-func (s *FileSink) Process(ctx context.Context, e *eventlogger.Event) (*eventlogger.Event, error) {
+func (s *FileSink) Process(ctx context.Context, e *eventlogger.Event) (_ *eventlogger.Event, retErr error) {
 	select {
 	case <-ctx.Done():
 		return nil, ctx.Err()
 	default:
 	}
 
+	defer func() {
+		// If the context is errored (cancelled), and we were planning to return
+		// an error, let's also log (if we have a logger) in case the eventlogger's
+		// status channel and errors propagated.
+		if err := ctx.Err(); err != nil && retErr != nil && s.logger != nil {
+			s.logger.Error("file sink error", "context", err, "error", retErr)
+		}
+	}()
+
 	if e == nil {
 		return nil, fmt.Errorf("event is nil: %w", ErrInvalidParameter)
 	}

internal/observability/event/sink_socket.go

@@ -12,6 +12,7 @@ import (
 	"time"
 
 	"github.com/hashicorp/eventlogger"
+	"github.com/hashicorp/go-hclog"
 	"github.com/hashicorp/go-multierror"
 )
 
@@ -25,6 +26,7 @@ type SocketSink struct {
 	maxDuration    time.Duration
 	socketLock     sync.RWMutex
 	connection     net.Conn
+	logger         hclog.Logger
 }
 
 // NewSocketSink should be used to create a new SocketSink.
@@ -52,21 +54,28 @@ func NewSocketSink(address string, format string, opt ...Option) (*SocketSink, e
 		maxDuration:    opts.withMaxDuration,
 		socketLock:     sync.RWMutex{},
 		connection:     nil,
+		logger:         opts.withLogger,
 	}
 
 	return sink, nil
 }
 
 // Process handles writing the event to the socket.
-func (s *SocketSink) Process(ctx context.Context, e *eventlogger.Event) (*eventlogger.Event, error) {
+func (s *SocketSink) Process(ctx context.Context, e *eventlogger.Event) (_ *eventlogger.Event, retErr error) {
 	select {
 	case <-ctx.Done():
 		return nil, ctx.Err()
 	default:
 	}
 
-	s.socketLock.Lock()
-	defer s.socketLock.Unlock()
+	defer func() {
+		// If the context is errored (cancelled), and we were planning to return
+		// an error, let's also log (if we have a logger) in case the eventlogger's
+		// status channel and errors propagated.
+		if err := ctx.Err(); err != nil && retErr != nil && s.logger != nil {
+			s.logger.Error("socket sink error", "context", err, "error", retErr)
+		}
+	}()
 
 	if e == nil {
 		return nil, fmt.Errorf("event is nil: %w", ErrInvalidParameter)
@@ -77,6 +86,9 @@ func (s *SocketSink) Process(ctx context.Context, e *eventlogger.Event) (*eventl
 		return nil, fmt.Errorf("unable to retrieve event formatted as %q: %w", s.requiredFormat, ErrInvalidParameter)
 	}
 
+	s.socketLock.Lock()
+	defer s.socketLock.Unlock()
+
 	// Try writing and return early if successful.
 	err := s.write(ctx, formatted)
 	if err == nil {

internal/observability/event/sink_syslog.go

@@ -9,6 +9,7 @@ import (
 	"strings"
 
 	"github.com/hashicorp/eventlogger"
+	"github.com/hashicorp/go-hclog"
 	gsyslog "github.com/hashicorp/go-syslog"
 )
 
@@ -17,7 +18,8 @@ var _ eventlogger.Node = (*SyslogSink)(nil)
 // SyslogSink is a sink node which handles writing events to syslog.
 type SyslogSink struct {
 	requiredFormat string
-	logger         gsyslog.Syslogger
+	syslogger      gsyslog.Syslogger
+	logger         hclog.Logger
 }
 
 // NewSyslogSink should be used to create a new SyslogSink.
@@ -38,17 +40,32 @@ func NewSyslogSink(format string, opt ...Option) (*SyslogSink, error) {
 		return nil, fmt.Errorf("error creating syslogger: %w", err)
 	}
 
-	return &SyslogSink{requiredFormat: format, logger: logger}, nil
+	syslog := &SyslogSink{
+		requiredFormat: format,
+		syslogger:      logger,
+		logger:         opts.withLogger,
+	}
+
+	return syslog, nil
 }
 
 // Process handles writing the event to the syslog.
-func (s *SyslogSink) Process(ctx context.Context, e *eventlogger.Event) (*eventlogger.Event, error) {
+func (s *SyslogSink) Process(ctx context.Context, e *eventlogger.Event) (_ *eventlogger.Event, retErr error) {
 	select {
 	case <-ctx.Done():
 		return nil, ctx.Err()
 	default:
 	}
 
+	defer func() {
+		// If the context is errored (cancelled), and we were planning to return
+		// an error, let's also log (if we have a logger) in case the eventlogger's
+		// status channel and errors propagated.
+		if err := ctx.Err(); err != nil && retErr != nil && s.logger != nil {
+			s.logger.Error("syslog sink error", "context", err, "error", retErr)
+		}
+	}()
+
 	if e == nil {
 		return nil, fmt.Errorf("event is nil: %w", ErrInvalidParameter)
 	}
@@ -58,7 +75,7 @@ func (s *SyslogSink) Process(ctx context.Context, e *eventlogger.Event) (*eventl
 		return nil, fmt.Errorf("unable to retrieve event formatted as %q: %w", s.requiredFormat, ErrInvalidParameter)
 	}
 
-	_, err := s.logger.Write(formatted)
+	_, err := s.syslogger.Write(formatted)
 	if err != nil {
 		return nil, fmt.Errorf("error writing to syslog: %w", err)
 	}

vault/audit.go

@@ -160,7 +160,6 @@ func (c *Core) enableAudit(ctx context.Context, entry *MountEntry, updateStorage
 		if err != nil {
 			c.logger.Error("new audit backend failed test", "path", entry.Path, "type", entry.Type, "error", err)
 			return fmt.Errorf("audit backend failed test message: %w", err)
-
 		}
 	}