extend logging support for testing (#850)

## Description

Updating logging to help display/control within testing envs.
Restore error tracking within gc iterators.

## Type of change

- [x] 🐛 Bugfix
- [x] 🤖 Test

## Issue(s)

* #824

## Test Plan

- [ ] 💪 Manual
- [x]  Unit test
- [x] 💚 E2E
This commit is contained in:
Keepers 2022-09-15 07:18:05 -06:00 committed by GitHub
parent 0c8a03a826
commit e92cb1b62b
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
7 changed files with 86 additions and 65 deletions

View File

@ -14,6 +14,7 @@ import (
"github.com/alcionai/corso/src/internal/tester" "github.com/alcionai/corso/src/internal/tester"
"github.com/alcionai/corso/src/pkg/account" "github.com/alcionai/corso/src/pkg/account"
"github.com/alcionai/corso/src/pkg/control" "github.com/alcionai/corso/src/pkg/control"
"github.com/alcionai/corso/src/pkg/logger"
"github.com/alcionai/corso/src/pkg/repository" "github.com/alcionai/corso/src/pkg/repository"
"github.com/alcionai/corso/src/pkg/selectors" "github.com/alcionai/corso/src/pkg/selectors"
"github.com/alcionai/corso/src/pkg/storage" "github.com/alcionai/corso/src/pkg/storage"
@ -127,6 +128,8 @@ func (suite *RestoreExchangeIntegrationSuite) TestExchangeRestoreCmd() {
for _, set := range backupDataSets { for _, set := range backupDataSets {
suite.T().Run(set.String(), func(t *testing.T) { suite.T().Run(set.String(), func(t *testing.T) {
ctx := config.SetViper(tester.NewContext(), suite.vpr) ctx := config.SetViper(tester.NewContext(), suite.vpr)
ctx, _ = logger.SeedLevel(ctx, logger.Development)
defer logger.Flush(ctx)
cmd := tester.StubRootCmd( cmd := tester.StubRootCmd(
"restore", "exchange", "restore", "exchange",

View File

@ -168,12 +168,15 @@ func (suite *ExchangeIteratorSuite) TestIterativeFunctions() {
// Create collection for iterate test // Create collection for iterate test
collections := make(map[string]*Collection) collections := make(map[string]*Collection)
var errs error var errs error
errUpdater := func(id string, err error) {
errs = support.WrapAndAppend(id, err, errs)
}
// callbackFunc iterates through all models.Messageable and fills exchange.Collection.jobs[] // callbackFunc iterates through all models.Messageable and fills exchange.Collection.jobs[]
// with corresponding item IDs. New collections are created for each directory // with corresponding item IDs. New collections are created for each directory
callbackFunc := test.iterativeFunction( callbackFunc := test.iterativeFunction(
ctx, ctx,
qp, qp,
errs, errUpdater,
collections, collections,
nil) nil)

View File

@ -33,7 +33,7 @@ type displayable interface {
type GraphIterateFunc func( type GraphIterateFunc func(
ctx context.Context, ctx context.Context,
qp graph.QueryParams, qp graph.QueryParams,
errs error, errUpdater func(string, error),
collections map[string]*Collection, collections map[string]*Collection,
statusUpdater support.StatusUpdater, statusUpdater support.StatusUpdater,
) func(any) bool ) func(any) bool
@ -103,7 +103,7 @@ func resolveCollectionPath(
func IterateSelectAllDescendablesForCollections( func IterateSelectAllDescendablesForCollections(
ctx context.Context, ctx context.Context,
qp graph.QueryParams, qp graph.QueryParams,
errs error, errUpdater func(string, error),
collections map[string]*Collection, collections map[string]*Collection,
statusUpdater support.StatusUpdater, statusUpdater support.StatusUpdater,
) func(any) bool { ) func(any) bool {
@ -128,11 +128,7 @@ func IterateSelectAllDescendablesForCollections(
} }
if r, err := maybeGetAndPopulateFolderResolver(ctx, qp, category); err != nil { if r, err := maybeGetAndPopulateFolderResolver(ctx, qp, category); err != nil {
errs = support.WrapAndAppend( errUpdater("getting folder resolver for category "+category.String(), err)
"getting folder resolver for category "+category.String(),
err,
errs,
)
} else { } else {
resolver = r resolver = r
} }
@ -142,7 +138,7 @@ func IterateSelectAllDescendablesForCollections(
entry, ok := pageItem.(descendable) entry, ok := pageItem.(descendable)
if !ok { if !ok {
errs = support.WrapAndAppendf(qp.User, errors.New("descendable conversion failure"), errs) errUpdater(qp.User, errors.New("descendable conversion failure"))
return true return true
} }
@ -156,8 +152,8 @@ func IterateSelectAllDescendablesForCollections(
false, false,
) )
if err != nil { if err != nil {
errs = support.WrapAndAppend("converting to resource path", err, errs) // This really shouldn't happen unless we have a bad category.
// This really shouldn't be happening unless we have a bad category. errUpdater("converting to resource path", err)
return true return true
} }
@ -173,7 +169,7 @@ func IterateSelectAllDescendablesForCollections(
if err != nil { if err != nil {
if !errors.Is(err, errNilResolver) { if !errors.Is(err, errNilResolver) {
errs = support.WrapAndAppend("", err, errs) errUpdater("", err)
} }
} else { } else {
dirPath = newPath dirPath = newPath
@ -181,7 +177,7 @@ func IterateSelectAllDescendablesForCollections(
service, err := createService(qp.Credentials, qp.FailFast) service, err := createService(qp.Credentials, qp.FailFast)
if err != nil { if err != nil {
errs = support.WrapAndAppend(qp.User, err, errs) errUpdater(qp.User, err)
return true return true
} }
@ -208,7 +204,7 @@ func IterateSelectAllDescendablesForCollections(
func IterateSelectAllEventsFromCalendars( func IterateSelectAllEventsFromCalendars(
ctx context.Context, ctx context.Context,
qp graph.QueryParams, qp graph.QueryParams,
errs error, errUpdater func(string, error),
collections map[string]*Collection, collections map[string]*Collection,
statusUpdater support.StatusUpdater, statusUpdater support.StatusUpdater,
) func(any) bool { ) func(any) bool {
@ -219,21 +215,15 @@ func IterateSelectAllEventsFromCalendars(
shell, ok := pageItem.(models.Calendarable) shell, ok := pageItem.(models.Calendarable)
if !ok { if !ok {
errs = support.WrapAndAppend( errUpdater(qp.User, errors.New("casting pageItem to models.Calendarable"))
qp.User,
errors.New("calendar event"),
errs)
return true return true
} }
service, err := createService(qp.Credentials, qp.FailFast) service, err := createService(qp.Credentials, qp.FailFast)
if err != nil { if err != nil {
errs = support.WrapAndAppend( errUpdater(
qp.User, qp.User,
errors.Wrap(err, "unable to create service during IterateSelectAllEventsFromCalendars"), errors.Wrap(err, "creating service for IterateSelectAllEventsFromCalendars"))
errs,
)
return true return true
} }
@ -243,11 +233,7 @@ func IterateSelectAllEventsFromCalendars(
CalendarsById(*shell.GetId()). CalendarsById(*shell.GetId()).
Events().Get() Events().Get()
if err != nil { if err != nil {
errs = support.WrapAndAppend( errUpdater(qp.User, err)
qp.User,
err,
errs,
)
} }
directory := shell.GetName() directory := shell.GetName()
@ -269,7 +255,7 @@ func IterateSelectAllEventsFromCalendars(
if _, ok := collections[*directory]; !ok { if _, ok := collections[*directory]; !ok {
service, err := createService(qp.Credentials, qp.FailFast) service, err := createService(qp.Credentials, qp.FailFast)
if err != nil { if err != nil {
errs = support.WrapAndAppend(qp.User, err, errs) errUpdater(qp.User, err)
return true return true
} }
@ -281,8 +267,8 @@ func IterateSelectAllEventsFromCalendars(
false, false,
) )
if err != nil { if err != nil {
// This really shouldn't be happening. // we shouldn't ever hit this error
errs = support.WrapAndAppend("converting to resource path", err, errs) errUpdater("converting to resource path", err)
return true return true
} }
@ -310,7 +296,7 @@ func IterateSelectAllEventsFromCalendars(
func IterateAndFilterMessagesForCollections( func IterateAndFilterMessagesForCollections(
ctx context.Context, ctx context.Context,
qp graph.QueryParams, qp graph.QueryParams,
errs error, errUpdater func(string, error),
collections map[string]*Collection, collections map[string]*Collection,
statusUpdater support.StatusUpdater, statusUpdater support.StatusUpdater,
) func(any) bool { ) func(any) bool {
@ -325,7 +311,7 @@ func IterateAndFilterMessagesForCollections(
statusUpdater, statusUpdater,
) )
if err != nil { if err != nil {
errs = support.WrapAndAppend(qp.User, err, errs) errUpdater(qp.User, err)
return false return false
} }
@ -334,7 +320,7 @@ func IterateAndFilterMessagesForCollections(
message, ok := messageItem.(descendable) message, ok := messageItem.(descendable)
if !ok { if !ok {
errs = support.WrapAndAppend(qp.User, errors.New("message iteration failure"), errs) errUpdater(qp.User, errors.New("casting messageItem to descendable"))
return true return true
} }
// Saving only messages for the created directories // Saving only messages for the created directories
@ -352,7 +338,7 @@ func IterateAndFilterMessagesForCollections(
func IterateFilterFolderDirectoriesForCollections( func IterateFilterFolderDirectoriesForCollections(
ctx context.Context, ctx context.Context,
qp graph.QueryParams, qp graph.QueryParams,
errs error, errUpdater func(string, error),
collections map[string]*Collection, collections map[string]*Collection,
statusUpdater support.StatusUpdater, statusUpdater support.StatusUpdater,
) func(any) bool { ) func(any) bool {
@ -363,22 +349,13 @@ func IterateFilterFolderDirectoriesForCollections(
resolver, err := maybeGetAndPopulateFolderResolver(ctx, qp, path.EmailCategory) resolver, err := maybeGetAndPopulateFolderResolver(ctx, qp, path.EmailCategory)
if err != nil { if err != nil {
errs = support.WrapAndAppend( errUpdater("getting folder resolver for category email", err)
"getting folder resolver for category email",
err,
errs,
)
} }
return func(folderItem any) bool { return func(folderItem any) bool {
folder, ok := folderItem.(displayable) folder, ok := folderItem.(displayable)
if !ok { if !ok {
errs = support.WrapAndAppend( errUpdater(qp.User, errors.New("casting folderItem to displayable"))
qp.User,
errors.New("unable to transform folderable item"),
errs,
)
return true return true
} }
// Continue to iterate if folder name is empty // Continue to iterate if folder name is empty
@ -399,8 +376,8 @@ func IterateFilterFolderDirectoriesForCollections(
false, false,
) )
if err != nil { if err != nil {
// This really shouldn't be happening. // we shouldn't ever hit this error.
errs = support.WrapAndAppend("converting to resource path", err, errs) errUpdater("converting to resource path", err)
return true return true
} }
@ -415,7 +392,7 @@ func IterateFilterFolderDirectoriesForCollections(
if err != nil { if err != nil {
if !errors.Is(err, errNilResolver) { if !errors.Is(err, errNilResolver) {
errs = support.WrapAndAppend("", err, errs) errUpdater("", err)
} }
} else { } else {
dirPath = p dirPath = p
@ -423,14 +400,9 @@ func IterateFilterFolderDirectoriesForCollections(
service, err = createService(qp.Credentials, qp.FailFast) service, err = createService(qp.Credentials, qp.FailFast)
if err != nil { if err != nil {
errs = support.WrapAndAppend( errUpdater(
*folder.GetDisplayName(), *folder.GetDisplayName(),
errors.Wrap( errors.Wrap(err, "creating service to iterate filterFolder directories for user: "+qp.User))
err,
"unable to create service a folder query service for "+qp.User,
),
errs,
)
return true return true
} }

View File

@ -151,10 +151,14 @@ func CollectMailFolders(
return errors.Wrap(err, "unable to create iterator during mail folder query service") return errors.Wrap(err, "unable to create iterator during mail folder query service")
} }
errUpdater := func(id string, e error) {
err = support.WrapAndAppend(id, e, err)
}
callbackFunc := IterateFilterFolderDirectoriesForCollections( callbackFunc := IterateFilterFolderDirectoriesForCollections(
ctx, ctx,
qp, qp,
err, errUpdater,
collections, collections,
statusUpdater, statusUpdater,
) )

View File

@ -370,10 +370,14 @@ func (gc *GraphConnector) createCollections(
return nil, err return nil, err
} }
errUpdater := func(id string, err error) {
errs = support.WrapAndAppend(id, err, errs)
}
// callbackFunc iterates through all M365 object target and fills exchange.Collection.jobs[] // callbackFunc iterates through all M365 object target and fills exchange.Collection.jobs[]
// with corresponding item M365IDs. New collections are created for each directory. // with corresponding item M365IDs. New collections are created for each directory.
// Each directory used the M365 Identifier. The use of ID stops collisions betweens users // Each directory used the M365 Identifier. The use of ID stops collisions betweens users
callbackFunc := gIter(ctx, qp, errs, collections, gc.UpdateStatus) callbackFunc := gIter(ctx, qp, errUpdater, collections, gc.UpdateStatus)
iterateError := pageIterator.Iterate(callbackFunc) iterateError := pageIterator.Iterate(callbackFunc)
if iterateError != nil { if iterateError != nil {

View File

@ -270,6 +270,10 @@ func (suite *GraphConnectorIntegrationSuite) TestCreateAndDeleteMailFolder() {
if aFolder != nil { if aFolder != nil {
err = exchange.DeleteMailFolder(suite.connector.Service(), suite.user, *aFolder.GetId()) err = exchange.DeleteMailFolder(suite.connector.Service(), suite.user, *aFolder.GetId())
assert.NoError(suite.T(), err) assert.NoError(suite.T(), err)
if err != nil {
suite.T().Log(support.ConnectorStackErrorTrace(err))
}
} }
} }
@ -284,6 +288,10 @@ func (suite *GraphConnectorIntegrationSuite) TestCreateAndDeleteContactFolder()
if aFolder != nil { if aFolder != nil {
err = exchange.DeleteContactFolder(suite.connector.Service(), suite.user, *aFolder.GetId()) err = exchange.DeleteContactFolder(suite.connector.Service(), suite.user, *aFolder.GetId())
assert.NoError(suite.T(), err) assert.NoError(suite.T(), err)
if err != nil {
suite.T().Log(support.ConnectorStackErrorTrace(err))
}
} }
} }
@ -299,5 +307,9 @@ func (suite *GraphConnectorIntegrationSuite) TestCreateAndDeleteCalendar() {
if calendar != nil { if calendar != nil {
err = exchange.DeleteCalendar(service, suite.user, *calendar.GetId()) err = exchange.DeleteCalendar(service, suite.user, *calendar.GetId())
assert.NoError(suite.T(), err) assert.NoError(suite.T(), err)
if err != nil {
suite.T().Log(support.ConnectorStackErrorTrace(err))
}
} }
} }

View File

@ -38,11 +38,7 @@ func AddLogLevelFlag(parent *cobra.Command) {
fs.StringVar(&llFlag, "log-level", "info", "set the log level to debug|info|warn|error") fs.StringVar(&llFlag, "log-level", "info", "set the log level to debug|info|warn|error")
} }
func singleton(level logLevel) *zap.SugaredLogger { func genLogger(level logLevel) (*zapcore.Core, *zap.SugaredLogger) {
if loggerton != nil {
return loggerton
}
// when testing, ensure debug logging matches the test.v setting // when testing, ensure debug logging matches the test.v setting
for _, arg := range os.Args { for _, arg := range os.Args {
if arg == `--test.v=true` { if arg == `--test.v=true` {
@ -68,7 +64,6 @@ func singleton(level logLevel) *zap.SugaredLogger {
core := zapcore.NewTee( core := zapcore.NewTee(
zapcore.NewCore(consoleEncoder, out, levelFilter), zapcore.NewCore(consoleEncoder, out, levelFilter),
) )
logCore = &core
// then try to set up a logger directly // then try to set up a logger directly
var ( var (
@ -96,8 +91,23 @@ func singleton(level logLevel) *zap.SugaredLogger {
lgr = zap.New(*logCore) lgr = zap.New(*logCore)
} }
return &core, lgr.Sugar()
}
func singleton(level logLevel) *zap.SugaredLogger {
if loggerton != nil {
return loggerton
}
if logCore != nil {
lgr := zap.New(*logCore)
loggerton = lgr.Sugar() loggerton = lgr.Sugar()
return loggerton
}
logCore, loggerton = genLogger(level)
return loggerton return loggerton
} }
@ -141,6 +151,14 @@ func Seed(ctx context.Context) (ctxOut context.Context, zsl *zap.SugaredLogger)
return // return values handled in defer return // return values handled in defer
} }
// SeedLevel embeds a logger into the context with the given log-level.
func SeedLevel(ctx context.Context, level logLevel) (context.Context, *zap.SugaredLogger) {
_, zsl := genLogger(level)
ctxWV := context.WithValue(ctx, ctxKey, zsl)
return ctxWV, zsl
}
// Ctx retrieves the logger embedded in the context. // Ctx retrieves the logger embedded in the context.
func Ctx(ctx context.Context) *zap.SugaredLogger { func Ctx(ctx context.Context) *zap.SugaredLogger {
l := ctx.Value(ctxKey) l := ctx.Value(ctxKey)
@ -164,3 +182,8 @@ func levelOf(lvl string) logLevel {
return Info return Info
} }
// Flush writes out all buffered logs.
func Flush(ctx context.Context) {
_ = Ctx(ctx).Sync()
}