VAULT-24013: Audit regression attempting to recover from panic (#25605)

* Add Logger to BackendConfig

* EntryFormatter use logger and recover panics

* Added TODO to consider

* Add 'name' to entry formatter

* Add test for the panic

* Fix NoopAudit with update params

* emit counter metric even when 0

* Fix vault package tests

* changelog

* Remove old comment during test writing
This commit is contained in:
Peter Wilson
2024-02-26 10:33:30 +00:00
committed by GitHub
parent 273ba49195
commit 67c16342d8
14 changed files with 255 additions and 64 deletions

View File

@@ -8,11 +8,15 @@ import (
"crypto/tls"
"errors"
"fmt"
"reflect"
"runtime/debug"
"strings"
"time"
"github.com/go-jose/go-jose/v3/jwt"
"github.com/hashicorp/eventlogger"
"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"
@@ -28,21 +32,32 @@ var (
// EntryFormatter should be used to format audit requests and responses.
type EntryFormatter struct {
salter Salter
headerFormatter HeaderFormatter
config FormatterConfig
salter Salter
logger hclog.Logger
headerFormatter HeaderFormatter
name string
prefix string
}
// NewEntryFormatter should be used to create an EntryFormatter.
// Accepted options: WithHeaderFormatter, WithPrefix.
func NewEntryFormatter(config FormatterConfig, salter Salter, opt ...Option) (*EntryFormatter, error) {
func NewEntryFormatter(name string, config FormatterConfig, salter Salter, logger hclog.Logger, opt ...Option) (*EntryFormatter, error) {
const op = "audit.NewEntryFormatter"
name = strings.TrimSpace(name)
if name == "" {
return nil, fmt.Errorf("%s: name is required: %w", op, event.ErrInvalidParameter)
}
if salter == nil {
return nil, fmt.Errorf("%s: cannot create a new audit formatter with nil salter: %w", op, event.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)
@@ -54,9 +69,11 @@ func NewEntryFormatter(config FormatterConfig, salter Salter, opt ...Option) (*E
}
return &EntryFormatter{
salter: salter,
config: config,
salter: salter,
logger: logger,
headerFormatter: opts.withHeaderFormatter,
name: name,
prefix: opts.withPrefix,
}, nil
}
@@ -73,7 +90,7 @@ 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, error) {
func (f *EntryFormatter) Process(ctx context.Context, e *eventlogger.Event) (_ *eventlogger.Event, retErr error) {
const op = "audit.(EntryFormatter).Process"
select {
@@ -95,6 +112,23 @@ func (f *EntryFormatter) Process(ctx context.Context, e *eventlogger.Event) (*ev
return nil, fmt.Errorf("%s: cannot audit event (%s) with no data: %w", op, a.Subtype, event.ErrInvalidParameter)
}
// Handle panics
defer func() {
r := recover()
if r == nil {
return
}
f.logger.Error("panic during logging",
"request_path", a.Data.Request.Path,
"audit_device_path", f.name,
"error", r,
"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()
}()
// Take a copy of the event data before we modify anything.
data, err := a.Data.Clone()
if err != nil {

View File

@@ -13,6 +13,8 @@ import (
"time"
"github.com/hashicorp/eventlogger"
"github.com/hashicorp/go-hclog"
"github.com/hashicorp/go-sockaddr"
"github.com/hashicorp/vault/helper/namespace"
"github.com/hashicorp/vault/internal/observability/event"
"github.com/hashicorp/vault/sdk/helper/jsonutil"
@@ -62,20 +64,42 @@ func TestNewEntryFormatter(t *testing.T) {
t.Parallel()
tests := map[string]struct {
Name string
UseStaticSalt bool
Logger hclog.Logger
Options []Option // Only supports WithPrefix
IsErrorExpected bool
ExpectedErrorMessage string
ExpectedFormat format
ExpectedPrefix string
}{
"empty-name": {
Name: "",
IsErrorExpected: true,
ExpectedErrorMessage: "audit.NewEntryFormatter: name is required: invalid parameter",
},
"spacey-name": {
Name: " ",
IsErrorExpected: true,
ExpectedErrorMessage: "audit.NewEntryFormatter: name is required: invalid parameter",
},
"nil-salter": {
Name: "juan",
UseStaticSalt: false,
IsErrorExpected: true,
ExpectedErrorMessage: "audit.NewEntryFormatter: cannot create a new audit formatter with nil salter: invalid parameter",
},
"nil-logger": {
Name: "juan",
UseStaticSalt: true,
Logger: nil,
IsErrorExpected: true,
ExpectedErrorMessage: "audit.NewEntryFormatter: cannot create a new audit formatter with nil logger: invalid parameter",
},
"static-salter": {
Name: "juan",
UseStaticSalt: true,
Logger: hclog.NewNullLogger(),
IsErrorExpected: false,
Options: []Option{
WithFormat(JSONFormat.String()),
@@ -83,12 +107,16 @@ func TestNewEntryFormatter(t *testing.T) {
ExpectedFormat: JSONFormat,
},
"default": {
Name: "juan",
UseStaticSalt: true,
Logger: hclog.NewNullLogger(),
IsErrorExpected: false,
ExpectedFormat: JSONFormat,
},
"config-json": {
Name: "juan",
UseStaticSalt: true,
Logger: hclog.NewNullLogger(),
Options: []Option{
WithFormat(JSONFormat.String()),
},
@@ -96,7 +124,9 @@ func TestNewEntryFormatter(t *testing.T) {
ExpectedFormat: JSONFormat,
},
"config-jsonx": {
Name: "juan",
UseStaticSalt: true,
Logger: hclog.NewNullLogger(),
Options: []Option{
WithFormat(JSONxFormat.String()),
},
@@ -104,7 +134,9 @@ func TestNewEntryFormatter(t *testing.T) {
ExpectedFormat: JSONxFormat,
},
"config-json-prefix": {
Name: "juan",
UseStaticSalt: true,
Logger: hclog.NewNullLogger(),
Options: []Option{
WithPrefix("foo"),
WithFormat(JSONFormat.String()),
@@ -114,7 +146,9 @@ func TestNewEntryFormatter(t *testing.T) {
ExpectedPrefix: "foo",
},
"config-jsonx-prefix": {
Name: "juan",
UseStaticSalt: true,
Logger: hclog.NewNullLogger(),
Options: []Option{
WithPrefix("foo"),
WithFormat(JSONxFormat.String()),
@@ -137,7 +171,7 @@ func TestNewEntryFormatter(t *testing.T) {
cfg, err := NewFormatterConfig(tc.Options...)
require.NoError(t, err)
f, err := NewEntryFormatter(cfg, ss, tc.Options...)
f, err := NewEntryFormatter(tc.Name, cfg, ss, tc.Logger, tc.Options...)
switch {
case tc.IsErrorExpected:
@@ -162,7 +196,7 @@ func TestEntryFormatter_Reopen(t *testing.T) {
cfg, err := NewFormatterConfig()
require.NoError(t, err)
f, err := NewEntryFormatter(cfg, ss)
f, err := NewEntryFormatter("juan", cfg, ss, hclog.NewNullLogger())
require.NoError(t, err)
require.NotNil(t, f)
require.NoError(t, f.Reopen())
@@ -176,7 +210,7 @@ func TestEntryFormatter_Type(t *testing.T) {
cfg, err := NewFormatterConfig()
require.NoError(t, err)
f, err := NewEntryFormatter(cfg, ss)
f, err := NewEntryFormatter("juan", cfg, ss, hclog.NewNullLogger())
require.NoError(t, err)
require.NotNil(t, f)
require.Equal(t, eventlogger.NodeTypeFormatter, f.Type())
@@ -321,7 +355,7 @@ func TestEntryFormatter_Process(t *testing.T) {
cfg, err := NewFormatterConfig(WithFormat(tc.RequiredFormat.String()))
require.NoError(t, err)
f, err := NewEntryFormatter(cfg, ss)
f, err := NewEntryFormatter("juan", cfg, ss, hclog.NewNullLogger())
require.NoError(t, err)
require.NotNil(t, f)
@@ -386,7 +420,7 @@ func BenchmarkAuditFileSink_Process(b *testing.B) {
cfg, err := NewFormatterConfig()
require.NoError(b, err)
ss := newStaticSalt(b)
formatter, err := NewEntryFormatter(cfg, ss)
formatter, err := NewEntryFormatter("juan", cfg, ss, hclog.NewNullLogger())
require.NoError(b, err)
require.NotNil(b, formatter)
@@ -457,7 +491,7 @@ func TestEntryFormatter_FormatRequest(t *testing.T) {
ss := newStaticSalt(t)
cfg, err := NewFormatterConfig()
require.NoError(t, err)
f, err := NewEntryFormatter(cfg, ss)
f, err := NewEntryFormatter("juan", cfg, ss, hclog.NewNullLogger())
require.NoError(t, err)
var ctx context.Context
@@ -526,7 +560,7 @@ func TestEntryFormatter_FormatResponse(t *testing.T) {
ss := newStaticSalt(t)
cfg, err := NewFormatterConfig()
require.NoError(t, err)
f, err := NewEntryFormatter(cfg, ss)
f, err := NewEntryFormatter("juan", cfg, ss, hclog.NewNullLogger())
require.NoError(t, err)
var ctx context.Context
@@ -636,7 +670,7 @@ func TestEntryFormatter_Process_JSON(t *testing.T) {
for name, tc := range cases {
cfg, err := NewFormatterConfig(WithHMACAccessor(false))
require.NoError(t, err)
formatter, err := NewEntryFormatter(cfg, ss, WithPrefix(tc.Prefix))
formatter, err := NewEntryFormatter("juan", cfg, ss, hclog.NewNullLogger(), WithPrefix(tc.Prefix))
require.NoError(t, err)
in := &logical.LogInput{
@@ -797,7 +831,7 @@ func TestEntryFormatter_Process_JSONx(t *testing.T) {
WithFormat(JSONxFormat.String()),
)
require.NoError(t, err)
formatter, err := NewEntryFormatter(cfg, tempStaticSalt, WithPrefix(tc.Prefix))
formatter, err := NewEntryFormatter("juan", cfg, tempStaticSalt, hclog.NewNullLogger(), WithPrefix(tc.Prefix))
require.NoError(t, err)
require.NotNil(t, formatter)
@@ -913,7 +947,7 @@ func TestEntryFormatter_FormatResponse_ElideListResponses(t *testing.T) {
var err error
format := func(t *testing.T, config FormatterConfig, operation logical.Operation, inputData map[string]any) *ResponseEntry {
formatter, err = NewEntryFormatter(config, ss)
formatter, err = NewEntryFormatter("juan", config, ss, hclog.NewNullLogger())
require.NoError(t, err)
require.NotNil(t, formatter)
@@ -975,7 +1009,7 @@ func TestEntryFormatter_Process_NoMutation(t *testing.T) {
cfg, err := NewFormatterConfig()
require.NoError(t, err)
ss := newStaticSalt(t)
formatter, err := NewEntryFormatter(cfg, ss)
formatter, err := NewEntryFormatter("juan", cfg, ss, hclog.NewNullLogger())
require.NoError(t, err)
require.NotNil(t, formatter)
@@ -1025,6 +1059,66 @@ func TestEntryFormatter_Process_NoMutation(t *testing.T) {
require.NotEqual(t, a2, a)
}
// TestEntryFormatter_Process_Panic tries to send data into the EntryFormatter
// which will currently cause a panic when a response is formatted due to the
// underlying hashing that is done with reflectwalk.
func TestEntryFormatter_Process_Panic(t *testing.T) {
t.Parallel()
// Create the formatter node.
cfg, err := NewFormatterConfig()
require.NoError(t, err)
ss := newStaticSalt(t)
formatter, err := NewEntryFormatter("juan", cfg, ss, hclog.NewNullLogger())
require.NoError(t, err)
require.NotNil(t, formatter)
// The secret sauce, create a bad addr.
// see: https://github.com/hashicorp/vault/issues/16462
badAddr, err := sockaddr.NewSockAddr("10.10.10.2/32 10.10.10.3/32")
require.NoError(t, err)
in := &logical.LogInput{
Auth: &logical.Auth{
ClientToken: "foo",
Accessor: "bar",
EntityID: "foobarentity",
DisplayName: "testtoken",
NoDefaultPolicy: true,
Policies: []string{"root"},
TokenType: logical.TokenTypeService,
},
Request: &logical.Request{
Operation: logical.UpdateOperation,
Path: "/foo",
Connection: &logical.Connection{
RemoteAddr: "127.0.0.1",
},
WrapInfo: &logical.RequestWrapInfo{
TTL: 60 * time.Second,
},
Headers: map[string][]string{
"foo": {"bar"},
},
Data: map[string]interface{}{},
},
Response: &logical.Response{
Data: map[string]any{
"token_bound_cidrs": []*sockaddr.SockAddrMarshaler{
{SockAddr: badAddr},
},
},
},
}
e := fakeEvent(t, ResponseType, in)
e2, err := formatter.Process(namespace.RootContext(nil), e)
require.Error(t, err)
require.Contains(t, err.Error(), "audit.(EntryFormatter).Process: panic generating audit log: \"juan\"")
require.Nil(t, e2)
}
// 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 (f *EntryFormatter) hashExpectedValueForComparison(input map[string]any) map[string]any {

View File

@@ -6,6 +6,7 @@ package audit
import (
"context"
"github.com/hashicorp/go-hclog"
"github.com/hashicorp/vault/internal/observability/event"
"github.com/hashicorp/vault/sdk/helper/salt"
"github.com/hashicorp/vault/sdk/logical"
@@ -231,6 +232,9 @@ type BackendConfig struct {
// MountPath is the path where this Backend is mounted
MountPath string
// Logger is used to emit log messages usually captured in the server logs.
Logger hclog.Logger
}
// Factory is the factory function to create an audit backend.

View File

@@ -6,12 +6,14 @@ package file
import (
"context"
"fmt"
"reflect"
"strconv"
"strings"
"sync"
"sync/atomic"
"github.com/hashicorp/eventlogger"
"github.com/hashicorp/go-hclog"
"github.com/hashicorp/go-secure-stdlib/parseutil"
"github.com/hashicorp/vault/audit"
"github.com/hashicorp/vault/internal/observability/event"
@@ -48,10 +50,15 @@ func Factory(_ context.Context, conf *audit.BackendConfig, headersConfig audit.H
if conf.SaltConfig == nil {
return nil, fmt.Errorf("%s: nil salt config", op)
}
if conf.SaltView == nil {
return nil, fmt.Errorf("%s: nil salt view", op)
}
if conf.Logger == nil || reflect.ValueOf(conf.Logger).IsNil() {
return nil, fmt.Errorf("%s: nil logger", op)
}
// The config options 'fallback' and 'filter' are mutually exclusive, a fallback
// device catches everything, so it cannot be allowed to filter.
var fallback bool
@@ -115,7 +122,7 @@ func Factory(_ context.Context, conf *audit.BackendConfig, headersConfig audit.H
audit.WithPrefix(conf.Config["prefix"]),
}
err = b.configureFormatterNode(cfg, formatterOpts...)
err = b.configureFormatterNode(conf.MountPath, cfg, conf.Logger, formatterOpts...)
if err != nil {
return nil, fmt.Errorf("%s: error configuring formatter node: %w", op, err)
}
@@ -242,7 +249,7 @@ func (b *Backend) configureFilterNode(filter string) error {
}
// configureFormatterNode is used to configure a formatter node and associated ID on the Backend.
func (b *Backend) configureFormatterNode(formatConfig audit.FormatterConfig, opts ...audit.Option) error {
func (b *Backend) configureFormatterNode(name string, formatConfig audit.FormatterConfig, logger hclog.Logger, opts ...audit.Option) error {
const op = "file.(Backend).configureFormatterNode"
formatterNodeID, err := event.GenerateNodeID()
@@ -250,7 +257,7 @@ func (b *Backend) configureFormatterNode(formatConfig audit.FormatterConfig, opt
return fmt.Errorf("%s: error generating random NodeID for formatter node: %w", op, err)
}
formatterNode, err := audit.NewEntryFormatter(formatConfig, b, opts...)
formatterNode, err := audit.NewEntryFormatter(name, formatConfig, b, logger, opts...)
if err != nil {
return fmt.Errorf("%s: error creating formatter: %w", op, err)
}

View File

@@ -11,6 +11,7 @@ import (
"testing"
"github.com/hashicorp/eventlogger"
"github.com/hashicorp/go-hclog"
"github.com/hashicorp/vault/audit"
"github.com/hashicorp/vault/internal/observability/event"
"github.com/hashicorp/vault/sdk/helper/salt"
@@ -37,6 +38,7 @@ func TestAuditFile_fileModeNew(t *testing.T) {
MountPath: "foo/bar",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
}
_, err = Factory(context.Background(), backendConfig, nil)
require.NoError(t, err)
@@ -68,6 +70,7 @@ func TestAuditFile_fileModeExisting(t *testing.T) {
MountPath: "foo/bar",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
}
_, err = Factory(context.Background(), backendConfig, nil)
@@ -101,6 +104,7 @@ func TestAuditFile_fileMode0000(t *testing.T) {
MountPath: "foo/bar",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
}
_, err = Factory(context.Background(), backendConfig, nil)
@@ -129,6 +133,7 @@ func TestAuditFile_EventLogger_fileModeNew(t *testing.T) {
MountPath: "foo/bar",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
}
_, err = Factory(context.Background(), backendConfig, nil)
@@ -320,7 +325,7 @@ func TestBackend_configureFormatterNode(t *testing.T) {
formatConfig, err := audit.NewFormatterConfig()
require.NoError(t, err)
err = b.configureFormatterNode(formatConfig)
err = b.configureFormatterNode("juan", formatConfig, hclog.NewNullLogger())
require.NoError(t, err)
require.Len(t, b.nodeIDList, 1)
@@ -485,7 +490,7 @@ func TestBackend_configureFilterFormatterSink(t *testing.T) {
err = b.configureFilterNode("path == bar")
require.NoError(t, err)
err = b.configureFormatterNode(formatConfig)
err = b.configureFormatterNode("juan", formatConfig, hclog.NewNullLogger())
require.NoError(t, err)
err = b.configureSinkNode("foo", "/tmp/foo", "0777", "json")
@@ -533,11 +538,22 @@ func TestBackend_Factory_Conf(t *testing.T) {
isErrorExpected: true,
expectedErrorMessage: "file.Factory: nil salt view",
},
"nil-logger": {
backendConfig: &audit.BackendConfig{
MountPath: "discard",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: nil,
},
isErrorExpected: true,
expectedErrorMessage: "file.Factory: nil logger",
},
"fallback-device-with-filter": {
backendConfig: &audit.BackendConfig{
MountPath: "discard",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"fallback": "true",
"file_path": discard,
@@ -552,6 +568,7 @@ func TestBackend_Factory_Conf(t *testing.T) {
MountPath: "discard",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"fallback": "false",
"file_path": discard,
@@ -598,6 +615,7 @@ func TestBackend_IsFallback(t *testing.T) {
MountPath: "discard",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"fallback": "true",
"file_path": discard,
@@ -610,6 +628,7 @@ func TestBackend_IsFallback(t *testing.T) {
MountPath: "discard",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"fallback": "false",
"file_path": discard,

View File

@@ -6,11 +6,13 @@ package socket
import (
"context"
"fmt"
"reflect"
"strconv"
"strings"
"sync"
"github.com/hashicorp/eventlogger"
"github.com/hashicorp/go-hclog"
"github.com/hashicorp/go-secure-stdlib/parseutil"
"github.com/hashicorp/vault/audit"
"github.com/hashicorp/vault/internal/observability/event"
@@ -43,6 +45,10 @@ func Factory(_ context.Context, conf *audit.BackendConfig, headersConfig audit.H
return nil, fmt.Errorf("%s: nil salt view", op)
}
if conf.Logger == nil || reflect.ValueOf(conf.Logger).IsNil() {
return nil, fmt.Errorf("%s: nil logger", op)
}
address, ok := conf.Config["address"]
if !ok {
return nil, fmt.Errorf("%s: address is required", op)
@@ -97,7 +103,7 @@ func Factory(_ context.Context, conf *audit.BackendConfig, headersConfig audit.H
audit.WithPrefix(conf.Config["prefix"]),
}
err = b.configureFormatterNode(cfg, opts...)
err = b.configureFormatterNode(conf.MountPath, cfg, conf.Logger, opts...)
if err != nil {
return nil, fmt.Errorf("%s: error configuring formatter node: %w", op, err)
}
@@ -225,7 +231,7 @@ func (b *Backend) configureFilterNode(filter string) error {
}
// configureFormatterNode is used to configure a formatter node and associated ID on the Backend.
func (b *Backend) configureFormatterNode(formatConfig audit.FormatterConfig, opts ...audit.Option) error {
func (b *Backend) configureFormatterNode(name string, formatConfig audit.FormatterConfig, logger hclog.Logger, opts ...audit.Option) error {
const op = "socket.(Backend).configureFormatterNode"
formatterNodeID, err := event.GenerateNodeID()
@@ -233,7 +239,7 @@ func (b *Backend) configureFormatterNode(formatConfig audit.FormatterConfig, opt
return fmt.Errorf("%s: error generating random NodeID for formatter node: %w", op, err)
}
formatterNode, err := audit.NewEntryFormatter(formatConfig, b, opts...)
formatterNode, err := audit.NewEntryFormatter(name, formatConfig, b, logger, opts...)
if err != nil {
return fmt.Errorf("%s: error creating formatter: %w", op, err)
}

View File

@@ -8,6 +8,7 @@ import (
"testing"
"github.com/hashicorp/eventlogger"
"github.com/hashicorp/go-hclog"
"github.com/hashicorp/vault/audit"
"github.com/hashicorp/vault/internal/observability/event"
"github.com/hashicorp/vault/sdk/helper/salt"
@@ -196,7 +197,7 @@ func TestBackend_configureFormatterNode(t *testing.T) {
formatConfig, err := audit.NewFormatterConfig()
require.NoError(t, err)
err = b.configureFormatterNode(formatConfig)
err = b.configureFormatterNode("juan", formatConfig, hclog.NewNullLogger())
require.NoError(t, err)
require.Len(t, b.nodeIDList, 1)
@@ -317,7 +318,7 @@ func TestBackend_configureFilterFormatterSink(t *testing.T) {
err = b.configureFilterNode("mount_type == kv")
require.NoError(t, err)
err = b.configureFormatterNode(formatConfig)
err = b.configureFormatterNode("juan", formatConfig, hclog.NewNullLogger())
require.NoError(t, err)
err = b.configureSinkNode("foo", "https://hashicorp.com", "json")
@@ -365,11 +366,22 @@ func TestBackend_Factory_Conf(t *testing.T) {
isErrorExpected: true,
expectedErrorMessage: "socket.Factory: nil salt view",
},
"nil-logger": {
backendConfig: &audit.BackendConfig{
MountPath: "discard",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: nil,
},
isErrorExpected: true,
expectedErrorMessage: "socket.Factory: nil logger",
},
"no-address": {
backendConfig: &audit.BackendConfig{
MountPath: "discard",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{},
},
isErrorExpected: true,
@@ -380,6 +392,7 @@ func TestBackend_Factory_Conf(t *testing.T) {
MountPath: "discard",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"address": "",
},
@@ -392,6 +405,7 @@ func TestBackend_Factory_Conf(t *testing.T) {
MountPath: "discard",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"address": " ",
},
@@ -404,6 +418,7 @@ func TestBackend_Factory_Conf(t *testing.T) {
MountPath: "discard",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"address": "hashicorp.com",
"write_timeout": "5s",
@@ -416,6 +431,7 @@ func TestBackend_Factory_Conf(t *testing.T) {
MountPath: "discard",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"address": "hashicorp.com",
"write_timeout": "qwerty",
@@ -429,6 +445,7 @@ func TestBackend_Factory_Conf(t *testing.T) {
MountPath: "discard",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"address": "hashicorp.com",
"write_timeout": "5s",
@@ -443,6 +460,7 @@ func TestBackend_Factory_Conf(t *testing.T) {
MountPath: "discard",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"address": "hashicorp.com",
"write_timeout": "2s",
@@ -491,6 +509,7 @@ func TestBackend_IsFallback(t *testing.T) {
MountPath: "qwerty",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"fallback": "true",
"address": "hashicorp.com",
@@ -504,6 +523,7 @@ func TestBackend_IsFallback(t *testing.T) {
MountPath: "qwerty",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"fallback": "false",
"address": "hashicorp.com",

View File

@@ -6,11 +6,13 @@ package syslog
import (
"context"
"fmt"
"reflect"
"strconv"
"strings"
"sync"
"github.com/hashicorp/eventlogger"
"github.com/hashicorp/go-hclog"
"github.com/hashicorp/go-secure-stdlib/parseutil"
"github.com/hashicorp/vault/audit"
"github.com/hashicorp/vault/internal/observability/event"
@@ -43,6 +45,10 @@ func Factory(_ context.Context, conf *audit.BackendConfig, headersConfig audit.H
return nil, fmt.Errorf("%s: nil salt view", op)
}
if conf.Logger == nil || reflect.ValueOf(conf.Logger).IsNil() {
return nil, fmt.Errorf("%s: nil logger", op)
}
// Get facility or default to AUTH
facility, ok := conf.Config["facility"]
if !ok {
@@ -94,7 +100,7 @@ func Factory(_ context.Context, conf *audit.BackendConfig, headersConfig audit.H
audit.WithPrefix(conf.Config["prefix"]),
}
err = b.configureFormatterNode(cfg, formatterOpts...)
err = b.configureFormatterNode(conf.MountPath, cfg, conf.Logger, formatterOpts...)
if err != nil {
return nil, fmt.Errorf("%s: error configuring formatter node: %w", op, err)
}
@@ -216,7 +222,7 @@ func (b *Backend) configureFilterNode(filter string) error {
}
// configureFormatterNode is used to configure a formatter node and associated ID on the Backend.
func (b *Backend) configureFormatterNode(formatConfig audit.FormatterConfig, opts ...audit.Option) error {
func (b *Backend) configureFormatterNode(name string, formatConfig audit.FormatterConfig, logger hclog.Logger, opts ...audit.Option) error {
const op = "syslog.(Backend).configureFormatterNode"
formatterNodeID, err := event.GenerateNodeID()
@@ -224,7 +230,7 @@ func (b *Backend) configureFormatterNode(formatConfig audit.FormatterConfig, opt
return fmt.Errorf("%s: error generating random NodeID for formatter node: %w", op, err)
}
formatterNode, err := audit.NewEntryFormatter(formatConfig, b, opts...)
formatterNode, err := audit.NewEntryFormatter(name, formatConfig, b, logger, opts...)
if err != nil {
return fmt.Errorf("%s: error creating formatter: %w", op, err)
}

View File

@@ -7,6 +7,8 @@ import (
"context"
"testing"
"github.com/hashicorp/go-hclog"
"github.com/hashicorp/eventlogger"
"github.com/hashicorp/vault/audit"
"github.com/hashicorp/vault/internal/observability/event"
@@ -196,7 +198,7 @@ func TestBackend_configureFormatterNode(t *testing.T) {
formatConfig, err := audit.NewFormatterConfig()
require.NoError(t, err)
err = b.configureFormatterNode(formatConfig)
err = b.configureFormatterNode("juan", formatConfig, hclog.NewNullLogger())
require.NoError(t, err)
require.Len(t, b.nodeIDList, 1)
@@ -299,7 +301,7 @@ func TestBackend_configureFilterFormatterSink(t *testing.T) {
err = b.configureFilterNode("mount_type == kv")
require.NoError(t, err)
err = b.configureFormatterNode(formatConfig)
err = b.configureFormatterNode("juan", formatConfig, hclog.NewNullLogger())
require.NoError(t, err)
err = b.configureSinkNode("foo", "json")
@@ -352,6 +354,7 @@ func TestBackend_Factory_Conf(t *testing.T) {
MountPath: "discard",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"fallback": "false",
"filter": "mount_type == kv",
@@ -364,6 +367,7 @@ func TestBackend_Factory_Conf(t *testing.T) {
MountPath: "discard",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"fallback": "true",
"filter": "mount_type == kv",
@@ -410,6 +414,7 @@ func TestBackend_IsFallback(t *testing.T) {
MountPath: "qwerty",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"fallback": "true",
},
@@ -421,6 +426,7 @@ func TestBackend_IsFallback(t *testing.T) {
MountPath: "qwerty",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
Config: map[string]string{
"fallback": "false",
},

3
changelog/25605.txt Normal file
View File

@@ -0,0 +1,3 @@
```release-note:bug
audit: Handle a potential panic while formatting audit entries for an audit log
```

View File

@@ -217,7 +217,11 @@ func (m *mockBuiltinRegistry) DeprecationStatus(name string, pluginType consts.P
}
func TestNoopAudit(t testing.T, path string, config map[string]string, opts ...audit.Option) *NoopAudit {
cfg := &audit.BackendConfig{Config: config, MountPath: path}
cfg := &audit.BackendConfig{
Config: config,
MountPath: path,
Logger: NewTestLogger(t),
}
n, err := NewNoopAudit(cfg, opts...)
if err != nil {
t.Fatal(err)
@@ -265,7 +269,7 @@ func NewNoopAudit(config *audit.BackendConfig, opts ...audit.Option) (*NoopAudit
return nil, fmt.Errorf("error generating random NodeID for formatter node: %w", err)
}
formatterNode, err := audit.NewEntryFormatter(cfg, noopBackend, opts...)
formatterNode, err := audit.NewEntryFormatter(config.MountPath, cfg, noopBackend, config.Logger, opts...)
if err != nil {
return nil, fmt.Errorf("error creating formatter: %w", err)
}

View File

@@ -516,6 +516,7 @@ func (c *Core) newAuditBackend(ctx context.Context, entry *MountEntry, view logi
HMACType: "hmac-sha256",
Location: salt.DefaultLocation,
}
auditLogger := c.baseLogger.Named("audit")
be, err := f(
ctx, &audit.BackendConfig{
@@ -523,6 +524,7 @@ func (c *Core) newAuditBackend(ctx context.Context, entry *MountEntry, view logi
SaltConfig: saltConfig,
Config: conf,
MountPath: entry.Path,
Logger: auditLogger,
},
c.auditedHeaders)
if err != nil {
@@ -532,8 +534,6 @@ func (c *Core) newAuditBackend(ctx context.Context, entry *MountEntry, view logi
return nil, fmt.Errorf("nil backend returned from %q factory function", entry.Type)
}
auditLogger := c.baseLogger.Named("audit")
switch entry.Type {
case "file":
key := "audit_file|" + entry.Path

View File

@@ -7,7 +7,6 @@ import (
"context"
"errors"
"fmt"
"runtime/debug"
"strings"
"sync"
"time"
@@ -218,23 +217,16 @@ func (a *AuditBroker) LogRequest(ctx context.Context, in *logical.LogInput) (ret
}
defer metrics.MeasureSince([]string{"audit", "log_request"}, time.Now())
defer func() {
metricVal := float32(0.0)
if ret != nil {
metricVal = 1.0
}
metrics.IncrCounter([]string{"audit", "log_request_failure"}, metricVal)
}()
var retErr *multierror.Error
defer func() {
if r := recover(); r != nil {
a.logger.Error("panic during logging", "request_path", in.Request.Path, "error", r, "stacktrace", string(debug.Stack()))
retErr = multierror.Append(retErr, fmt.Errorf("panic generating audit log"))
}
ret = retErr.ErrorOrNil()
failure := float32(0.0)
if ret != nil {
failure = 1.0
}
metrics.IncrCounter([]string{"audit", "log_request_failure"}, failure)
}()
e, err := audit.NewEvent(audit.RequestType)
if err != nil {
retErr = multierror.Append(retErr, err)
@@ -293,23 +285,16 @@ func (a *AuditBroker) LogResponse(ctx context.Context, in *logical.LogInput) (re
}
defer metrics.MeasureSince([]string{"audit", "log_response"}, time.Now())
defer func() {
metricVal := float32(0.0)
if ret != nil {
metricVal = 1.0
}
metrics.IncrCounter([]string{"audit", "log_response_failure"}, metricVal)
}()
var retErr *multierror.Error
defer func() {
if r := recover(); r != nil {
a.logger.Error("panic during logging", "request_path", in.Request.Path, "error", r, "stacktrace", string(debug.Stack()))
retErr = multierror.Append(retErr, fmt.Errorf("panic generating audit log"))
}
ret = retErr.ErrorOrNil()
failure := float32(0.0)
if ret != nil {
failure = 1.0
}
metrics.IncrCounter([]string{"audit", "log_response_failure"}, failure)
}()
e, err := audit.NewEvent(audit.ResponseType)
if err != nil {
retErr = multierror.Append(retErr, err)

View File

@@ -10,6 +10,7 @@ import (
"time"
"github.com/hashicorp/eventlogger"
"github.com/hashicorp/go-hclog"
"github.com/hashicorp/vault/audit"
"github.com/hashicorp/vault/builtin/audit/file"
"github.com/hashicorp/vault/builtin/audit/syslog"
@@ -41,6 +42,7 @@ func testAuditBackend(t *testing.T, path string, config map[string]string) audit
HMAC: sha256.New,
HMACType: "hmac-sha256",
},
Logger: corehelpers.NewTestLogger(t),
Config: config,
MountPath: path,
}
@@ -283,6 +285,7 @@ func BenchmarkAuditBroker_File_Request_DevNull(b *testing.B) {
MountPath: "test",
SaltConfig: &salt.Config{},
SaltView: &logical.InmemStorage{},
Logger: hclog.NewNullLogger(),
}
sink, err := file.Factory(context.Background(), backendConfig, nil)