From 443aed639c7ca0831a89bfabf5a54106f622a0a0 Mon Sep 17 00:00:00 2001 From: ashmrtn <3891298+ashmrtn@users.noreply.github.com> Date: Mon, 8 Jan 2024 11:37:02 -0800 Subject: [PATCH] Extra logging and clues context for folder caches (#4988) Add extra logging and clues to errors when populating container caches for Exchange. This could help track down some things related to time spent getting data. --- #### Does this PR need a docs update or release note? - [ ] :white_check_mark: Yes, it's included - [ ] :clock1: Yes, but in a later PR - [x] :no_entry: No #### Type of change - [ ] :sunflower: Feature - [ ] :bug: Bugfix - [ ] :world_map: Documentation - [x] :robot: Supportability/Tests - [ ] :computer: CI/Deployment - [ ] :broom: Tech Debt/Cleanup #### Test Plan - [x] :muscle: Manual - [ ] :zap: Unit test - [ ] :green_heart: E2E --- .../exchange/contacts_container_cache.go | 14 +++++++++++++- .../collection/exchange/events_container_cache.go | 14 +++++++++++++- .../collection/exchange/mail_container_cache.go | 14 +++++++++++++- 3 files changed, 39 insertions(+), 3 deletions(-) diff --git a/src/internal/m365/collection/exchange/contacts_container_cache.go b/src/internal/m365/collection/exchange/contacts_container_cache.go index 857ccf9df..52a762f43 100644 --- a/src/internal/m365/collection/exchange/contacts_container_cache.go +++ b/src/internal/m365/collection/exchange/contacts_container_cache.go @@ -2,12 +2,14 @@ package exchange import ( "context" + "time" "github.com/alcionai/clues" "github.com/microsoftgraph/msgraph-sdk-go/models" "github.com/alcionai/corso/src/internal/common/ptr" "github.com/alcionai/corso/src/pkg/fault" + "github.com/alcionai/corso/src/pkg/logger" "github.com/alcionai/corso/src/pkg/path" "github.com/alcionai/corso/src/pkg/services/m365/api/graph" ) @@ -93,6 +95,10 @@ func (cfc *contactContainerCache) Populate( baseID string, baseContainerPath ...string, ) error { + start := time.Now() + + logger.Ctx(ctx).Info("populating container cache") + if err := cfc.init(ctx, baseID, baseContainerPath); err != nil { return clues.Wrap(err, "initializing") } @@ -104,8 +110,10 @@ func (cfc *contactContainerCache) Populate( cfc.userID, baseID, false) + ctx = clues.Add(ctx, "num_enumerated_containers", len(containers)) + if err != nil { - return clues.Wrap(err, "enumerating containers") + return clues.WrapWC(ctx, err, "enumerating containers") } for _, c := range containers { @@ -127,5 +135,9 @@ func (cfc *contactContainerCache) Populate( return clues.Wrap(err, "populating paths") } + logger.Ctx(ctx).Infow( + "done populating container cache", + "duration", time.Since(start)) + return el.Failure() } diff --git a/src/internal/m365/collection/exchange/events_container_cache.go b/src/internal/m365/collection/exchange/events_container_cache.go index dd1d9e280..e6a9ce3e4 100644 --- a/src/internal/m365/collection/exchange/events_container_cache.go +++ b/src/internal/m365/collection/exchange/events_container_cache.go @@ -2,12 +2,14 @@ package exchange import ( "context" + "time" "github.com/alcionai/clues" "github.com/microsoftgraph/msgraph-sdk-go/models" "github.com/alcionai/corso/src/internal/common/ptr" "github.com/alcionai/corso/src/pkg/fault" + "github.com/alcionai/corso/src/pkg/logger" "github.com/alcionai/corso/src/pkg/path" "github.com/alcionai/corso/src/pkg/services/m365/api" "github.com/alcionai/corso/src/pkg/services/m365/api/graph" @@ -67,6 +69,10 @@ func (ecc *eventContainerCache) Populate( baseID string, baseContainerPath ...string, ) error { + start := time.Now() + + logger.Ctx(ctx).Info("populating container cache") + if err := ecc.init(ctx); err != nil { return clues.Wrap(err, "initializing") } @@ -78,8 +84,10 @@ func (ecc *eventContainerCache) Populate( ecc.userID, "", false) + ctx = clues.Add(ctx, "num_enumerated_containers", len(containers)) + if err != nil { - return clues.Wrap(err, "enumerating containers") + return clues.WrapWC(ctx, err, "enumerating containers") } for _, c := range containers { @@ -104,6 +112,10 @@ func (ecc *eventContainerCache) Populate( return clues.Wrap(err, "populating paths") } + logger.Ctx(ctx).Infow( + "done populating container cache", + "duration", time.Since(start)) + return el.Failure() } diff --git a/src/internal/m365/collection/exchange/mail_container_cache.go b/src/internal/m365/collection/exchange/mail_container_cache.go index b3b9c054b..aa205b258 100644 --- a/src/internal/m365/collection/exchange/mail_container_cache.go +++ b/src/internal/m365/collection/exchange/mail_container_cache.go @@ -2,11 +2,13 @@ package exchange import ( "context" + "time" "github.com/alcionai/clues" "github.com/microsoftgraph/msgraph-sdk-go/models" "github.com/alcionai/corso/src/pkg/fault" + "github.com/alcionai/corso/src/pkg/logger" "github.com/alcionai/corso/src/pkg/path" "github.com/alcionai/corso/src/pkg/services/m365/api" "github.com/alcionai/corso/src/pkg/services/m365/api/graph" @@ -97,6 +99,10 @@ func (mc *mailContainerCache) Populate( baseID string, baseContainerPath ...string, ) error { + start := time.Now() + + logger.Ctx(ctx).Info("populating container cache") + if err := mc.init(ctx); err != nil { return clues.Wrap(err, "initializing") } @@ -108,8 +114,10 @@ func (mc *mailContainerCache) Populate( mc.userID, "", false) + ctx = clues.Add(ctx, "num_enumerated_containers", len(containers)) + if err != nil { - return clues.Wrap(err, "enumerating containers") + return clues.WrapWC(ctx, err, "enumerating containers") } for _, c := range containers { @@ -131,5 +139,9 @@ func (mc *mailContainerCache) Populate( return clues.Wrap(err, "populating paths") } + logger.Ctx(ctx).Infow( + "done populating container cache", + "duration", time.Since(start)) + return el.Failure() }