From 7b6484663b6f8f11e004105eba34dd0dcf60d299 Mon Sep 17 00:00:00 2001 From: Keepers Date: Thu, 12 Oct 2023 17:42:35 -0600 Subject: [PATCH] ensure api layer provides non-empty modtime (#4486) enforce the following: * no mod times returned from the api layer are zero-valued * dttm.OrNow() provides a zero value time check * ptr.OrNow() calls dttmOrNow on non-nil time values. * itemPagers for getAddedAndRemoved call ptr.OrNow() * callers to getAddedAndRemoved provide a transformer func which produces the mod time from the paged item, instead of assuming all items use the same interface for mod time. --- #### Does this PR need a docs update or release note? - [x] :white_check_mark: Yes, it's included #### Type of change - [x] :bug: Bugfix #### Test Plan - [x] :zap: Unit test - [x] :green_heart: E2E --- CHANGELOG.md | 1 + src/internal/common/dttm/dttm.go | 10 +- src/internal/common/dttm/dttm_test.go | 41 ++++++ src/internal/common/ptr/pointer.go | 10 +- src/internal/common/ptr/pointer_test.go | 38 +++++ src/pkg/services/m365/api/item_pager.go | 32 +++-- src/pkg/services/m365/api/item_pager_test.go | 137 ++++++++++++------- 7 files changed, 207 insertions(+), 62 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 5ce255cf4..746944f02 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -13,6 +13,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed - Catch and report cases where a protected resource is locked out of access. SDK consumers have a new errs sentinel that allows them to check for this case. +- Fix a case where missing item LastModifiedTimes could cause incremental backups to fail. ## [v0.14.0] (beta) - 2023-10-09 diff --git a/src/internal/common/dttm/dttm.go b/src/internal/common/dttm/dttm.go index d91f7596c..b768e92f8 100644 --- a/src/internal/common/dttm/dttm.go +++ b/src/internal/common/dttm/dttm.go @@ -98,10 +98,18 @@ func Now() string { return FormatNow(Standard) } +func OrNow(t time.Time) time.Time { + if t.IsZero() { + return time.Now().UTC() + } + + return t +} + // FormatNow produces the current time in UTC using the provided // time format. func FormatNow(fmt TimeFormat) string { - return FormatTo(time.Now(), fmt) + return FormatTo(time.Now().UTC(), fmt) } // FormatTo produces the a datetime with the given format. diff --git a/src/internal/common/dttm/dttm_test.go b/src/internal/common/dttm/dttm_test.go index 3100419dc..f2414cf66 100644 --- a/src/internal/common/dttm/dttm_test.go +++ b/src/internal/common/dttm/dttm_test.go @@ -58,6 +58,47 @@ func (suite *DTTMUnitSuite) TestParseTime() { require.Error(t, err, clues.ToCore(err)) } +func (suite *DTTMUnitSuite) TestOrNow() { + var ( + oneMinuteAgo = time.Now().Add(-1 * time.Minute) + inOneHour = time.Now().Add(1 * time.Hour) + empty time.Time + ) + + table := []struct { + name string + input time.Time + expect func(t *testing.T, result time.Time) + }{ + { + name: "a minute ago", + input: oneMinuteAgo, + expect: func(t *testing.T, result time.Time) { + assert.True(t, oneMinuteAgo.Equal(result), "equal") + }, + }, + { + name: "in an hour", + input: inOneHour, + expect: func(t *testing.T, result time.Time) { + assert.True(t, inOneHour.Equal(result), "equal") + }, + }, + { + name: "empty", + input: empty, + expect: func(t *testing.T, result time.Time) { + assert.WithinDuration(t, time.Now(), result, time.Minute) + }, + }, + } + for _, test := range table { + suite.Run(test.name, func() { + test.expect(suite.T(), dttm.OrNow(test.input)) + }) + } +} + func (suite *DTTMUnitSuite) TestExtractTime() { comparable := func(t *testing.T, tt time.Time, shortFormat dttm.TimeFormat) time.Time { ts := dttm.FormatToLegacy(tt.UTC()) diff --git a/src/internal/common/ptr/pointer.go b/src/internal/common/ptr/pointer.go index fa9d3f606..bf7ad194e 100644 --- a/src/internal/common/ptr/pointer.go +++ b/src/internal/common/ptr/pointer.go @@ -1,6 +1,10 @@ package ptr -import "time" +import ( + "time" + + "github.com/alcionai/corso/src/internal/common/dttm" +) // ptr package is a common package used for pointer // access and deserialization. @@ -38,10 +42,10 @@ func ValOK[T any](ptr *T) (T, bool) { // time in UTC. func OrNow(t *time.Time) time.Time { if t == nil { - return time.Now().UTC() + t = &time.Time{} } - return *t + return dttm.OrNow(*t) } // To generates a pointer from any value. Primarily useful diff --git a/src/internal/common/ptr/pointer_test.go b/src/internal/common/ptr/pointer_test.go index fdc8d9c88..d026f301f 100644 --- a/src/internal/common/ptr/pointer_test.go +++ b/src/internal/common/ptr/pointer_test.go @@ -99,3 +99,41 @@ func (suite *PointerSuite) TestVal() { assert.NotEmpty(t, myInt32) assert.NotEmpty(t, myInt64) } + +func (suite *PointerSuite) TestOrNow() { + oneMinuteAgo := time.Now().Add(-1 * time.Minute) + + table := []struct { + name string + p *time.Time + expectEqual bool + }{ + { + name: "populated value", + p: &oneMinuteAgo, + expectEqual: true, + }, + { + name: "nil", + p: nil, + expectEqual: false, + }, + { + name: "pointer to 0 valued time", + p: &time.Time{}, + expectEqual: false, + }, + } + for _, test := range table { + suite.Run(test.name, func() { + t := suite.T() + result := ptr.OrNow(test.p) + + if test.expectEqual { + assert.Equal(t, *test.p, result) + } else { + assert.WithinDuration(t, time.Now(), result, time.Minute) + } + }) + } +} diff --git a/src/pkg/services/m365/api/item_pager.go b/src/pkg/services/m365/api/item_pager.go index a64ae71b7..5423a9869 100644 --- a/src/pkg/services/m365/api/item_pager.go +++ b/src/pkg/services/m365/api/item_pager.go @@ -8,6 +8,7 @@ import ( "github.com/alcionai/clues" + "github.com/alcionai/corso/src/internal/common/dttm" "github.com/alcionai/corso/src/internal/common/ptr" "github.com/alcionai/corso/src/internal/m365/graph" "github.com/alcionai/corso/src/pkg/logger" @@ -206,7 +207,9 @@ func deltaEnumerateItems[T any]( // shared enumeration runner funcs // --------------------------------------------------------------------------- -type addedAndRemovedHandler[T any] func(items []T) (map[string]time.Time, []string, error) +type addedAndRemovedHandler[T any] func( + items []T, +) (map[string]time.Time, []string, error) func getAddedAndRemovedItemIDs[T any]( ctx context.Context, @@ -246,11 +249,15 @@ type getIDer interface { // for added and removed by additionalData[@removed] -type getIDAndAddtler interface { +type getIDModAndAddtler interface { getIDer + getModTimer GetAdditionalData() map[string]any } +// for types that are non-compliant with this interface, +// pagers will need to wrap the return value in a struct +// that provides this compliance. type getModTimer interface { GetLastModifiedDateTime() *time.Time } @@ -262,7 +269,7 @@ func addedAndRemovedByAddtlData[T any]( removed := []string{} for _, item := range items { - giaa, ok := any(item).(getIDAndAddtler) + giaa, ok := any(item).(getIDModAndAddtler) if !ok { return nil, nil, clues.New("item does not provide id and additional data getters"). With("item_type", fmt.Sprintf("%T", item)) @@ -275,10 +282,18 @@ func addedAndRemovedByAddtlData[T any]( var modTime time.Time if mt, ok := giaa.(getModTimer); ok { - modTime = ptr.Val(mt.GetLastModifiedDateTime()) + // Make sure to get a non-zero mod time if the item doesn't have one for + // some reason. Otherwise we can hit an issue where kopia has a + // different mod time for the file than the details does. This occurs + // due to a conversion kopia does on the time from + // time.Time -> nanoseconds for serialization. During incremental + // backups, kopia goes from nanoseconds -> time.Time but there's an + // overflow which yields a different timestamp. + // https://github.com/gohugoio/hugo/issues/6161#issuecomment-725915786 + modTime = ptr.OrNow(mt.GetLastModifiedDateTime()) } - added[ptr.Val(giaa.GetId())] = modTime + added[ptr.Val(giaa.GetId())] = dttm.OrNow(modTime) } else { removed = append(removed, ptr.Val(giaa.GetId())) } @@ -289,8 +304,9 @@ func addedAndRemovedByAddtlData[T any]( // for added and removed by GetDeletedDateTime() -type getIDAndDeletedDateTimer interface { +type getIDModAndDeletedDateTimer interface { getIDer + getModTimer GetDeletedDateTime() *time.Time } @@ -301,7 +317,7 @@ func addedAndRemovedByDeletedDateTime[T any]( removed := []string{} for _, item := range items { - giaddt, ok := any(item).(getIDAndDeletedDateTimer) + giaddt, ok := any(item).(getIDModAndDeletedDateTimer) if !ok { return nil, nil, clues.New("item does not provide id and deleted date time getters"). With("item_type", fmt.Sprintf("%T", item)) @@ -322,7 +338,7 @@ func addedAndRemovedByDeletedDateTime[T any]( modTime = ptr.OrNow(mt.GetLastModifiedDateTime()) } - added[ptr.Val(giaddt.GetId())] = modTime + added[ptr.Val(giaddt.GetId())] = dttm.OrNow(modTime) } else { removed = append(removed, ptr.Val(giaddt.GetId())) } diff --git a/src/pkg/services/m365/api/item_pager_test.go b/src/pkg/services/m365/api/item_pager_test.go index 5644fbfc2..63edb4989 100644 --- a/src/pkg/services/m365/api/item_pager_test.go +++ b/src/pkg/services/m365/api/item_pager_test.go @@ -7,11 +7,11 @@ import ( "time" "github.com/alcionai/clues" - "github.com/microsoftgraph/msgraph-sdk-go/models" "github.com/microsoftgraph/msgraph-sdk-go/models/odataerrors" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" "github.com/stretchr/testify/suite" + "golang.org/x/exp/maps" "github.com/alcionai/corso/src/internal/common/ptr" "github.com/alcionai/corso/src/internal/m365/graph" @@ -41,10 +41,33 @@ func (l deltaNextLink) GetOdataDeltaLink() *string { return l.deltaLink } +// mock item + +var _ getIDModAndAddtler = &testItem{} + +type testItem struct { + id string + modTime time.Time + additionalData map[string]any +} + +//nolint:revive +func (ti testItem) GetId() *string { + return &ti.id +} + +func (ti testItem) GetLastModifiedDateTime() *time.Time { + return &ti.modTime +} + +func (ti testItem) GetAdditionalData() map[string]any { + return ti.additionalData +} + // mock page type testPage struct { - values []any + values []testItem } func (p testPage) GetOdataNextLink() *string { @@ -57,13 +80,13 @@ func (p testPage) GetOdataDeltaLink() *string { return ptr.To("") } -func (p testPage) GetValue() []any { +func (p testPage) GetValue() []testItem { return p.values } // mock item pager -var _ Pager[any] = &testPager{} +var _ Pager[testItem] = &testPager{} type testPager struct { t *testing.T @@ -71,7 +94,7 @@ type testPager struct { pageErr error } -func (p *testPager) GetPage(ctx context.Context) (NextLinkValuer[any], error) { +func (p *testPager) GetPage(ctx context.Context) (NextLinkValuer[testItem], error) { return p.pager, p.pageErr } @@ -81,7 +104,7 @@ func (p testPager) ValidModTimes() bool { return true } // mock id pager -var _ Pager[any] = &testIDsPager{} +var _ Pager[testItem] = &testIDsPager{} type testIDsPager struct { t *testing.T @@ -94,7 +117,7 @@ type testIDsPager struct { func (p *testIDsPager) GetPage( ctx context.Context, -) (NextLinkValuer[any], error) { +) (NextLinkValuer[testItem], error) { if len(p.errorCode) > 0 { ierr := odataerrors.NewMainError() ierr.SetCode(&p.errorCode) @@ -105,21 +128,23 @@ func (p *testIDsPager) GetPage( return nil, err } - values := make([]any, 0, len(p.added)+len(p.removed)) + values := make([]testItem, 0, len(p.added)+len(p.removed)) for a, modTime := range p.added { - // contact chosen arbitrarily, any exchange model should work - itm := models.NewContact() - itm.SetId(ptr.To(a)) - itm.SetLastModifiedDateTime(ptr.To(modTime)) + itm := testItem{ + id: a, + modTime: modTime, + } values = append(values, itm) } for _, r := range p.removed { - // contact chosen arbitrarily, any exchange model should work - itm := models.NewContact() - itm.SetId(ptr.To(r)) - itm.SetAdditionalData(map[string]any{graph.AddtlDataRemoved: struct{}{}}) + itm := testItem{ + id: r, + additionalData: map[string]any{ + graph.AddtlDataRemoved: struct{}{}, + }, + } values = append(values, itm) } @@ -141,7 +166,7 @@ func (p testIDsPager) ValidModTimes() bool { return p.validModTimes } -var _ DeltaPager[any] = &testIDsDeltaPager{} +var _ DeltaPager[testItem] = &testIDsDeltaPager{} type testIDsDeltaPager struct { t *testing.T @@ -154,7 +179,7 @@ type testIDsDeltaPager struct { func (p *testIDsDeltaPager) GetPage( ctx context.Context, -) (DeltaLinkValuer[any], error) { +) (DeltaLinkValuer[testItem], error) { if len(p.errorCode) > 0 { ierr := odataerrors.NewMainError() ierr.SetCode(&p.errorCode) @@ -165,21 +190,23 @@ func (p *testIDsDeltaPager) GetPage( return nil, err } - values := make([]any, 0, len(p.added)+len(p.removed)) + values := make([]testItem, 0, len(p.added)+len(p.removed)) for a, modTime := range p.added { - // contact chosen arbitrarily, any exchange model should work - itm := models.NewContact() - itm.SetId(ptr.To(a)) - itm.SetLastModifiedDateTime(ptr.To(modTime)) + itm := testItem{ + id: a, + modTime: modTime, + } values = append(values, itm) } for _, r := range p.removed { - // contact chosen arbitrarily, any exchange model should work - itm := models.NewContact() - itm.SetId(ptr.To(r)) - itm.SetAdditionalData(map[string]any{graph.AddtlDataRemoved: struct{}{}}) + itm := testItem{ + id: r, + additionalData: map[string]any{ + graph.AddtlDataRemoved: struct{}{}, + }, + } values = append(values, itm) } @@ -216,8 +243,8 @@ func TestPagerUnitSuite(t *testing.T) { func (suite *PagerUnitSuite) TestEnumerateItems() { tests := []struct { name string - getPager func(*testing.T, context.Context) Pager[any] - expect []any + getPager func(*testing.T, context.Context) Pager[testItem] + expect []testItem expectErr require.ErrorAssertionFunc }{ { @@ -225,13 +252,13 @@ func (suite *PagerUnitSuite) TestEnumerateItems() { getPager: func( t *testing.T, ctx context.Context, - ) Pager[any] { + ) Pager[testItem] { return &testPager{ t: t, - pager: testPage{[]any{"foo", "bar"}}, + pager: testPage{[]testItem{{id: "foo"}, {id: "bar"}}}, } }, - expect: []any{"foo", "bar"}, + expect: []testItem{{id: "foo"}, {id: "bar"}}, expectErr: require.NoError, }, { @@ -239,7 +266,7 @@ func (suite *PagerUnitSuite) TestEnumerateItems() { getPager: func( t *testing.T, ctx context.Context, - ) Pager[any] { + ) Pager[testItem] { return &testPager{ t: t, pageErr: assert.AnError, @@ -274,15 +301,17 @@ func (suite *PagerUnitSuite) TestGetAddedAndRemovedItemIDs() { } now := time.Now() + epoch, err := time.Parse(time.DateOnly, "1970-01-01") + require.NoError(suite.T(), err, clues.ToCore(err)) tests := []struct { name string pagerGetter func( *testing.T, - ) Pager[any] + ) Pager[testItem] deltaPagerGetter func( *testing.T, - ) DeltaPager[any] + ) DeltaPager[testItem] prevDelta string expect expected canDelta bool @@ -290,10 +319,10 @@ func (suite *PagerUnitSuite) TestGetAddedAndRemovedItemIDs() { }{ { name: "no prev delta", - pagerGetter: func(t *testing.T) Pager[any] { + pagerGetter: func(t *testing.T) Pager[testItem] { return nil }, - deltaPagerGetter: func(t *testing.T) DeltaPager[any] { + deltaPagerGetter: func(t *testing.T) DeltaPager[testItem] { return &testIDsDeltaPager{ t: t, added: map[string]time.Time{ @@ -317,10 +346,10 @@ func (suite *PagerUnitSuite) TestGetAddedAndRemovedItemIDs() { }, { name: "no prev delta invalid mod times", - pagerGetter: func(t *testing.T) Pager[any] { + pagerGetter: func(t *testing.T) Pager[testItem] { return nil }, - deltaPagerGetter: func(t *testing.T) DeltaPager[any] { + deltaPagerGetter: func(t *testing.T) DeltaPager[testItem] { return &testIDsDeltaPager{ t: t, added: map[string]time.Time{ @@ -332,8 +361,8 @@ func (suite *PagerUnitSuite) TestGetAddedAndRemovedItemIDs() { }, expect: expected{ added: map[string]time.Time{ - "uno": {}, - "dos": {}, + "uno": time.Now().Add(-1 * time.Minute), + "dos": time.Now().Add(-1 * time.Minute), }, removed: []string{"tres", "quatro"}, deltaUpdate: DeltaUpdate{Reset: true}, @@ -342,10 +371,10 @@ func (suite *PagerUnitSuite) TestGetAddedAndRemovedItemIDs() { }, { name: "with prev delta", - pagerGetter: func(t *testing.T) Pager[any] { + pagerGetter: func(t *testing.T) Pager[testItem] { return nil }, - deltaPagerGetter: func(t *testing.T) DeltaPager[any] { + deltaPagerGetter: func(t *testing.T) DeltaPager[testItem] { return &testIDsDeltaPager{ t: t, added: map[string]time.Time{ @@ -370,10 +399,10 @@ func (suite *PagerUnitSuite) TestGetAddedAndRemovedItemIDs() { }, { name: "delta expired", - pagerGetter: func(t *testing.T) Pager[any] { + pagerGetter: func(t *testing.T) Pager[testItem] { return nil }, - deltaPagerGetter: func(t *testing.T) DeltaPager[any] { + deltaPagerGetter: func(t *testing.T) DeltaPager[testItem] { return &testIDsDeltaPager{ t: t, added: map[string]time.Time{ @@ -400,7 +429,7 @@ func (suite *PagerUnitSuite) TestGetAddedAndRemovedItemIDs() { }, { name: "delta not allowed", - pagerGetter: func(t *testing.T) Pager[any] { + pagerGetter: func(t *testing.T) Pager[testItem] { return &testIDsPager{ t: t, added: map[string]time.Time{ @@ -411,7 +440,7 @@ func (suite *PagerUnitSuite) TestGetAddedAndRemovedItemIDs() { validModTimes: true, } }, - deltaPagerGetter: func(t *testing.T) DeltaPager[any] { + deltaPagerGetter: func(t *testing.T) DeltaPager[testItem] { return nil }, expect: expected{ @@ -434,16 +463,24 @@ func (suite *PagerUnitSuite) TestGetAddedAndRemovedItemIDs() { ctx, flush := tester.NewContext(t) defer flush() - added, validModTimes, removed, deltaUpdate, err := getAddedAndRemovedItemIDs[any]( + added, validModTimes, removed, deltaUpdate, err := getAddedAndRemovedItemIDs[testItem]( ctx, test.pagerGetter(t), test.deltaPagerGetter(t), test.prevDelta, test.canDelta, - addedAndRemovedByAddtlData[any]) + addedAndRemovedByAddtlData[testItem]) require.NoErrorf(t, err, "getting added and removed item IDs: %+v", clues.ToCore(err)) - assert.Equal(t, test.expect.added, added, "added item IDs and mod times") + if validModTimes { + assert.Equal(t, test.expect.added, added, "added item IDs and mod times") + } else { + assert.ElementsMatch(t, maps.Keys(test.expect.added), maps.Keys(added), "added item IDs") + for _, modtime := range added { + assert.True(t, modtime.After(epoch), "mod time after epoch") + assert.False(t, modtime.Equal(time.Time{}), "non-zero mod time") + } + } assert.Equal(t, test.expect.validModTimes, validModTimes, "valid mod times") assert.EqualValues(t, test.expect.removed, removed, "removed item IDs") assert.Equal(t, test.expect.deltaUpdate, deltaUpdate, "delta update")