From e3b6d035fb259b88f9876226a286a23e5f0dcf2f Mon Sep 17 00:00:00 2001 From: Keepers Date: Wed, 18 Jan 2023 09:43:19 -0700 Subject: [PATCH] extra loggng and error wraps (#2155) ## Description Adds info logging on all throttling responses, and some extra error handling in container resolvers. ## Does this PR need a docs update or release note? - [x] :no_entry: No ## Type of change - [x] :broom: Tech Debt/Cleanup ## Test Plan - [x] :muscle: Manual --- .../connector/exchange/contact_folder_cache.go | 12 +++++------- .../connector/exchange/event_calendar_cache.go | 8 ++++---- .../connector/exchange/mail_folder_cache.go | 10 +++++----- src/internal/connector/graph/service_helper.go | 13 +++++++++---- src/internal/connector/support/errors.go | 16 ++++++++++++++-- 5 files changed, 37 insertions(+), 22 deletions(-) diff --git a/src/internal/connector/exchange/contact_folder_cache.go b/src/internal/connector/exchange/contact_folder_cache.go index 9ac83e665..b2c077a2e 100644 --- a/src/internal/connector/exchange/contact_folder_cache.go +++ b/src/internal/connector/exchange/contact_folder_cache.go @@ -26,15 +26,13 @@ func (cfc *contactFolderCache) populateContactRoot( ) error { f, err := cfc.getter.GetContainerByID(ctx, cfc.userID, directoryID) if err != nil { - return errors.Wrapf( - err, - "fetching root contact folder: "+support.ConnectorStackErrorTrace(err)) + return support.ConnectorStackErrorTraceWrap(err, "fetching root folder") } temp := graph.NewCacheFolder(f, path.Builder{}.Append(baseContainerPath...)) if err := cfc.addFolder(temp); err != nil { - return errors.Wrap(err, "adding cache root") + return errors.Wrap(err, "adding resolver dir") } return nil @@ -50,16 +48,16 @@ func (cfc *contactFolderCache) Populate( baseContainerPather ...string, ) error { if err := cfc.init(ctx, baseID, baseContainerPather); err != nil { - return err + return errors.Wrap(err, "initializing") } err := cfc.enumer.EnumerateContainers(ctx, cfc.userID, baseID, cfc.addFolder) if err != nil { - return err + return errors.Wrap(err, "enumerating containers") } if err := cfc.populatePaths(ctx); err != nil { - return errors.Wrap(err, "contacts resolver") + return errors.Wrap(err, "populating paths") } return nil diff --git a/src/internal/connector/exchange/event_calendar_cache.go b/src/internal/connector/exchange/event_calendar_cache.go index c383a74e6..2b4e1b22d 100644 --- a/src/internal/connector/exchange/event_calendar_cache.go +++ b/src/internal/connector/exchange/event_calendar_cache.go @@ -31,7 +31,7 @@ func (ecc *eventCalendarCache) Populate( err := ecc.enumer.EnumerateContainers(ctx, ecc.userID, "", ecc.addFolder) if err != nil { - return err + return errors.Wrap(err, "enumerating containers") } return nil @@ -41,20 +41,20 @@ func (ecc *eventCalendarCache) Populate( // @returns error iff the required values are not accessible. func (ecc *eventCalendarCache) AddToCache(ctx context.Context, f graph.Container) error { if err := checkIDAndName(f); err != nil { - return errors.Wrap(err, "adding cache folder") + return errors.Wrap(err, "validating container") } temp := graph.NewCacheFolder(f, path.Builder{}.Append(*f.GetDisplayName())) if err := ecc.addFolder(temp); err != nil { - return errors.Wrap(err, "adding cache folder") + return errors.Wrap(err, "adding container") } // Populate the path for this entry so calls to PathInCache succeed no matter // when they're made. _, err := ecc.IDToPath(ctx, *f.GetId()) if err != nil { - return errors.Wrap(err, "adding cache entry") + return errors.Wrap(err, "setting path to container id") } return nil diff --git a/src/internal/connector/exchange/mail_folder_cache.go b/src/internal/connector/exchange/mail_folder_cache.go index a2b92593c..06d4b1285 100644 --- a/src/internal/connector/exchange/mail_folder_cache.go +++ b/src/internal/connector/exchange/mail_folder_cache.go @@ -35,7 +35,7 @@ func (mc *mailFolderCache) populateMailRoot( f, err := mc.getter.GetContainerByID(ctx, mc.userID, fldr) if err != nil { - return errors.Wrap(err, "fetching root folder"+support.ConnectorStackErrorTrace(err)) + return support.ConnectorStackErrorTraceWrap(err, "fetching root folder") } if fldr == DefaultMailFolder { @@ -44,7 +44,7 @@ func (mc *mailFolderCache) populateMailRoot( temp := graph.NewCacheFolder(f, path.Builder{}.Append(directory)) if err := mc.addFolder(temp); err != nil { - return errors.Wrap(err, "initializing mail resolver") + return errors.Wrap(err, "adding resolver dir") } } @@ -62,16 +62,16 @@ func (mc *mailFolderCache) Populate( baseContainerPath ...string, ) error { if err := mc.init(ctx); err != nil { - return err + return errors.Wrap(err, "initializing") } err := mc.enumer.EnumerateContainers(ctx, mc.userID, "", mc.addFolder) if err != nil { - return err + return errors.Wrap(err, "enumerating containers") } if err := mc.populatePaths(ctx); err != nil { - return errors.Wrap(err, "mail resolver") + return errors.Wrap(err, "populating paths") } return nil diff --git a/src/internal/connector/graph/service_helper.go b/src/internal/connector/graph/service_helper.go index db39fcb34..76ff54ad4 100644 --- a/src/internal/connector/graph/service_helper.go +++ b/src/internal/connector/graph/service_helper.go @@ -1,7 +1,7 @@ package graph import ( - nethttp "net/http" + "net/http" "net/http/httputil" "os" "strings" @@ -47,7 +47,7 @@ func CreateAdapter(tenant, client, secret string) (*msgraphsdk.GraphRequestAdapt } // CreateHTTPClient creates the httpClient with middlewares and timeout configured -func CreateHTTPClient() *nethttp.Client { +func CreateHTTPClient() *http.Client { clientOptions := msgraphsdk.GetDefaultClientOptions() middlewares := msgraphgocore.GetDefaultMiddlewaresWithOptions(&clientOptions) middlewares = append(middlewares, &LoggingMiddleware{}) @@ -67,8 +67,8 @@ type LoggingMiddleware struct{} func (handler *LoggingMiddleware) Intercept( pipeline khttp.Pipeline, middlewareIndex int, - req *nethttp.Request, -) (*nethttp.Response, error) { + req *http.Request, +) (*http.Response, error) { var ( ctx = req.Context() resp, err = pipeline.Next(req, middlewareIndex) @@ -82,6 +82,11 @@ func (handler *LoggingMiddleware) Intercept( return resp, err } + // special case for supportability: log all throttling cases. + if resp.StatusCode == http.StatusTooManyRequests { + logger.Ctx(ctx).Infow("graph api throttling", "method", req.Method, "url", req.URL) + } + if logger.DebugAPI || os.Getenv(logGraphRequestsEnvKey) != "" { respDump, _ := httputil.DumpResponse(resp, true) diff --git a/src/internal/connector/support/errors.go b/src/internal/connector/support/errors.go index 4289e5058..8f73ea8fa 100644 --- a/src/internal/connector/support/errors.go +++ b/src/internal/connector/support/errors.go @@ -89,8 +89,20 @@ func concatenateStringFromPointers(orig string, pointers []*string) string { return orig } -// ConnectorStackErrorTrace is a helper function that wraps the -// stack trace for oDataError types from querying the M365 back store. +// ConnectorStackErrorTraceWrap is a helper function that wraps the +// stack trace for oDataErrors (if the error has one) onto the prefix. +// If no stack trace is found, wraps the error with only the prefix. +func ConnectorStackErrorTraceWrap(e error, prefix string) error { + cset := ConnectorStackErrorTrace(e) + if len(cset) > 0 { + return errors.Wrap(e, prefix+": "+cset) + } + + return errors.Wrap(e, prefix) +} + +// ConnectorStackErrorTracew is a helper function that extracts +// the stack trace for oDataErrors, if the error has one. func ConnectorStackErrorTrace(e error) string { eMessage := ""