From e6b7b7f60a42226416b479e5309a8fd15ee7f92d Mon Sep 17 00:00:00 2001 From: Louis Ruch Date: Fri, 8 Apr 2022 18:04:12 -0700 Subject: [PATCH] feat(db): Suppress not found events during db lookups (#1979) --- internal/db/read_writer.go | 45 ++++++++++++--------- internal/db/read_writer_test.go | 71 +++++++++++++++++++++++++++++++++ internal/errors/option.go | 2 + 3 files changed, 100 insertions(+), 18 deletions(-) diff --git a/internal/db/read_writer.go b/internal/db/read_writer.go index e335b7b02..49d77c733 100644 --- a/internal/db/read_writer.go +++ b/internal/db/read_writer.go @@ -3,7 +3,6 @@ package db import ( "context" "database/sql" - stderrors "errors" "fmt" "reflect" "time" @@ -437,7 +436,7 @@ func (w *Db) DoTx(ctx context.Context, retries uint, backOff Backoff, handler Tx } // LookupByPublicId will lookup resource by its public_id or private_id, which -// must be unique. Options are ignored. +// must be unique. WithDebug is the only valid option, all other options are ignored. func (rw *Db) LookupById(ctx context.Context, resourceWithIder interface{}, opt ...Option) error { const op = "db.LookupById" if rw.underlying == nil { @@ -445,7 +444,13 @@ func (rw *Db) LookupById(ctx context.Context, resourceWithIder interface{}, opt } opts := GetOpts(opt...) if err := dbw.New(rw.underlying.wrapped).LookupBy(ctx, resourceWithIder, dbw.WithDebug(opts.withDebug)); err != nil { - return wrapError(ctx, err, op) + var errOpts []errors.Option + if errors.Is(err, dbw.ErrRecordNotFound) { + // Not found is a common workflow in the application layer during lookup, suppress + // the event here and allow the caller to log event if needed. + errOpts = append(errOpts, errors.WithoutEvent()) + } + return wrapError(ctx, err, op, errOpts...) } return nil } @@ -465,7 +470,13 @@ func (rw *Db) LookupWhere(ctx context.Context, resource interface{}, where strin } opts := GetOpts(opt...) if err := dbw.New(rw.underlying.wrapped).LookupWhere(ctx, resource, where, args, dbw.WithDebug(opts.withDebug)); err != nil { - return wrapError(ctx, err, op) + var errOpts []errors.Option + if errors.Is(err, dbw.ErrRecordNotFound) { + // Not found is a common workflow in the application layer during lookup, suppress + // the event here and allow the caller to log event if needed. + errOpts = append(errOpts, errors.WithoutEvent()) + } + return wrapError(ctx, err, op, errOpts...) } return nil } @@ -507,19 +518,17 @@ func wrapError(ctx context.Context, err error, op string, errOpts ...errors.Opti // See github.com/hashicorp/go-dbw/error.go for appropriate errors to test // for and wrap switch { - case stderrors.Is(err, dbw.ErrUnknown): - return errors.Wrap(ctx, err, errors.Op(op), errors.WithCode(errors.Unknown)) - case stderrors.Is(err, dbw.ErrInvalidParameter): - return errors.Wrap(ctx, err, errors.Op(op), errors.WithCode(errors.InvalidParameter)) - case stderrors.Is(err, dbw.ErrInternal): - return errors.Wrap(ctx, err, errors.Op(op), errors.WithCode(errors.Internal)) - case stderrors.Is(err, dbw.ErrRecordNotFound): - return errors.Wrap(ctx, err, errors.Op(op), errors.WithCode(errors.RecordNotFound)) - case stderrors.Is(err, dbw.ErrMaxRetries): - return errors.Wrap(ctx, err, errors.Op(op), errors.WithCode(errors.MaxRetries)) - case stderrors.Is(err, dbw.ErrInvalidFieldMask): - return errors.Wrap(ctx, err, errors.Op(op), errors.WithCode(errors.InvalidFieldMask)) - default: - return errors.Wrap(ctx, err, errors.Op(op), errOpts...) + case errors.Is(err, dbw.ErrInvalidParameter): + errOpts = append(errOpts, errors.WithCode(errors.InvalidParameter)) + case errors.Is(err, dbw.ErrInternal): + errOpts = append(errOpts, errors.WithCode(errors.Internal)) + case errors.Is(err, dbw.ErrRecordNotFound): + errOpts = append(errOpts, errors.WithCode(errors.RecordNotFound)) + case errors.Is(err, dbw.ErrMaxRetries): + errOpts = append(errOpts, errors.WithCode(errors.MaxRetries)) + case errors.Is(err, dbw.ErrInvalidFieldMask): + errOpts = append(errOpts, errors.WithCode(errors.InvalidFieldMask)) } + + return errors.Wrap(ctx, err, errors.Op(op), errOpts...) } diff --git a/internal/db/read_writer_test.go b/internal/db/read_writer_test.go index fa59681f2..cf0135e44 100644 --- a/internal/db/read_writer_test.go +++ b/internal/db/read_writer_test.go @@ -4,16 +4,21 @@ import ( "context" stderrors "errors" "fmt" + "io/ioutil" + "os" "strconv" "strings" + "sync" "testing" "time" "github.com/hashicorp/boundary/internal/db/db_test" "github.com/hashicorp/boundary/internal/db/timestamp" "github.com/hashicorp/boundary/internal/errors" + "github.com/hashicorp/boundary/internal/observability/event" "github.com/hashicorp/boundary/internal/oplog" "github.com/hashicorp/boundary/internal/oplog/store" + "github.com/hashicorp/go-hclog" wrapping "github.com/hashicorp/go-kms-wrapping/v2" "github.com/hashicorp/go-secure-stdlib/base62" "github.com/hashicorp/go-uuid" @@ -908,6 +913,72 @@ func TestDb_LookupWhere(t *testing.T) { }) } +// TestDb_LookupNotFoundEvent validates that not found error events are suppressed when +// LookupById and LookupWhere are called. +func TestDb_LookupNotFoundEvent(t *testing.T) { + // this test and its subtests cannot be run in parallel because of it's + // dependency on the sysEventer + event.TestEnableEventing(t, true) + conn, _ := TestSetup(t, "postgres") + TestCreateTables(t, conn) + + c := event.TestEventerConfig(t, "TestDb_LookupNotFoundEvent") + testLock := &sync.Mutex{} + testLogger := hclog.New(&hclog.LoggerOptions{ + Mutex: testLock, + Name: "test", + }) + e, err := event.NewEventer(testLogger, testLock, "TestDb_LookupNotFoundEvent", c.EventerConfig) + require.NoError(t, err) + + info := &event.RequestInfo{Id: "867-5309", EventId: "411"} + ctx, err := event.NewEventerContext(context.Background(), e) + require.NoError(t, err) + ctx, err = event.NewRequestInfoContext(ctx, info) + require.NoError(t, err) + + t.Run("lookup-where", func(t *testing.T) { + assert, require := assert.New(t), require.New(t) + w := New(conn) + id, err := uuid.GenerateUUID() + require.NoError(err) + + var foundUser db_test.TestUser + err = w.LookupWhere(ctx, &foundUser, "public_id = ?", []interface{}{id}) + require.Error(err) + assert.True(errors.Match(errors.T(errors.RecordNotFound), err)) + + defer func() { _ = os.WriteFile(c.AllEvents.Name(), nil, 0o666) }() + + b, err := ioutil.ReadFile(c.AllEvents.Name()) + require.NoError(err) + // No events should have been written with the above error + assert.Len(b, 0) + }) + t.Run("lookup-by-id", func(t *testing.T) { + assert, require := assert.New(t), require.New(t) + w := New(conn) + id, err := uuid.GenerateUUID() + require.NoError(err) + + foundUser := db_test.TestUser{ + StoreTestUser: &db_test.StoreTestUser{ + PublicId: id, + }, + } + err = w.LookupById(ctx, &foundUser) + require.Error(err) + assert.True(errors.Match(errors.T(errors.RecordNotFound), err)) + + defer func() { _ = os.WriteFile(c.AllEvents.Name(), nil, 0o666) }() + + b, err := ioutil.ReadFile(c.AllEvents.Name()) + require.NoError(err) + // No events should have been written with the above error + assert.Len(b, 0) + }) +} + func TestDb_SearchWhere(t *testing.T) { t.Parallel() conn, _ := TestSetup(t, "postgres") diff --git a/internal/errors/option.go b/internal/errors/option.go index c5b3a712e..89bc577ab 100644 --- a/internal/errors/option.go +++ b/internal/errors/option.go @@ -57,6 +57,8 @@ func WithCode(code Code) Option { } } +// WithoutEvent provides an option to suppress the event when wrapping or +// creating a new error. func WithoutEvent() Option { return func(o *Options) { o.withoutEvent = true