From 58df026a3e0b1e2645a81566ff526b6dd5ebec69 Mon Sep 17 00:00:00 2001 From: Joseph Schorr Date: Mon, 29 Jan 2024 17:55:53 -0500 Subject: [PATCH 1/3] Add additional logging to e2e --- e2e/newenemy/newenemy_test.go | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/e2e/newenemy/newenemy_test.go b/e2e/newenemy/newenemy_test.go index f4bfd3389d..7c37737442 100644 --- a/e2e/newenemy/newenemy_test.go +++ b/e2e/newenemy/newenemy_test.go @@ -360,6 +360,7 @@ func checkDataNoNewEnemy(ctx context.Context, t testing.TB, slowNodeID int, crdb Updates: []*v1.RelationshipUpdate{blockusers[i]}, }) require.NoError(t, err) + t.Log("r1 token: ", r1.WrittenAt.Token) // sleeping in between the writes seems to let cockroach clear out // pending transactions in the background and has a better chance @@ -373,6 +374,13 @@ func checkDataNoNewEnemy(ctx context.Context, t testing.TB, slowNodeID int, crdb Updates: []*v1.RelationshipUpdate{allowlists[i]}, }) require.NoError(t, err) + t.Log("r2 token: ", r2.WrittenAt.Token) + + z1, _ := zedtoken.DecodeRevision(r1.WrittenAt, revisions.CommonDecoder{Kind: revisions.HybridLogicalClock}) + z2, _ := zedtoken.DecodeRevision(r2.WrittenAt, revisions.CommonDecoder{Kind: revisions.HybridLogicalClock}) + + t.Log("z1 revision: ", z1) + t.Log("z2 revision: ", z2) canHas, err := spicedb[1].Client().V1().Permissions().CheckPermission(context.Background(), &v1.CheckPermissionRequest{ Consistency: &v1.Consistency{Requirement: &v1.Consistency_AtExactSnapshot{AtExactSnapshot: r2.WrittenAt}}, @@ -396,8 +404,6 @@ func checkDataNoNewEnemy(ctx context.Context, t testing.TB, slowNodeID int, crdb ns2AllowlistLeader := getLeaderNodeForNamespace(ctx, crdb[2].Conn(), allowlists[i].Relationship.Subject.Object.ObjectType) r1leader, r2leader := getLeaderNode(ctx, crdb[2].Conn(), blockusers[i].Relationship), getLeaderNode(ctx, crdb[2].Conn(), allowlists[i].Relationship) - z1, _ := zedtoken.DecodeRevision(r1.WrittenAt, revisions.CommonDecoder{Kind: revisions.HybridLogicalClock}) - z2, _ := zedtoken.DecodeRevision(r2.WrittenAt, revisions.CommonDecoder{Kind: revisions.HybridLogicalClock}) t.Log(sleep, z1, z2, z1.GreaterThan(z2), r1leader, r2leader, ns1BlocklistLeader, ns1UserLeader, ns2ResourceLeader, ns2AllowlistLeader) if z1.GreaterThan(z2) { From fd5a6cd93decb3565a112497fdc92e3e6877d07e Mon Sep 17 00:00:00 2001 From: Joseph Schorr Date: Mon, 29 Jan 2024 18:14:33 -0500 Subject: [PATCH 2/3] Ensure NewForHLC returns an error if the incoming decimal is invalid This shouldn't be possible, but there are some indications it might be --- internal/datastore/crdb/crdb.go | 2 +- internal/datastore/crdb/stats.go | 2 +- internal/datastore/revisions/hlcrevision.go | 10 ++++++--- .../datastore/revisions/hlcrevision_test.go | 3 ++- pkg/zedtoken/zedtoken_test.go | 22 ++++++++++++++----- 5 files changed, 28 insertions(+), 11 deletions(-) diff --git a/internal/datastore/crdb/crdb.go b/internal/datastore/crdb/crdb.go index b74423fd7d..069f21f625 100644 --- a/internal/datastore/crdb/crdb.go +++ b/internal/datastore/crdb/crdb.go @@ -478,7 +478,7 @@ func readCRDBNow(ctx context.Context, reader pgxcommon.DBFuncQuerier) (datastore return datastore.NoRevision, fmt.Errorf("unable to read timestamp: %w", err) } - return revisions.NewForHLC(hlcNow), nil + return revisions.NewForHLC(hlcNow) } func readClusterTTLNanos(ctx context.Context, conn pgxcommon.DBFuncQuerier) (int64, error) { diff --git a/internal/datastore/crdb/stats.go b/internal/datastore/crdb/stats.go index 4d9f35a1f8..abebe1b1f5 100644 --- a/internal/datastore/crdb/stats.go +++ b/internal/datastore/crdb/stats.go @@ -105,5 +105,5 @@ func updateCounter(ctx context.Context, tx pgx.Tx, change int64) (datastore.Revi return datastore.NoRevision, fmt.Errorf("unable to executed upsert counter query: %w", err) } - return revisions.NewForHLC(timestamp), nil + return revisions.NewForHLC(timestamp) } diff --git a/internal/datastore/revisions/hlcrevision.go b/internal/datastore/revisions/hlcrevision.go index 6f14ced5f8..03a1299a07 100644 --- a/internal/datastore/revisions/hlcrevision.go +++ b/internal/datastore/revisions/hlcrevision.go @@ -73,9 +73,13 @@ func HLCRevisionFromString(revisionStr string) (HLCRevision, error) { } // NewForHLC creates a new revision for the given hybrid logical clock. -func NewForHLC(decimal decimal.Decimal) HLCRevision { - rev, _ := HLCRevisionFromString(decimal.String()) - return rev +func NewForHLC(decimal decimal.Decimal) (HLCRevision, error) { + rev, err := HLCRevisionFromString(decimal.String()) + if err != nil { + return zeroHLC, fmt.Errorf("invalid HLC decimal: %v (%s) => %w", decimal, decimal.String(), err) + } + + return rev, nil } // NewHLCForTime creates a new revision for the given time. diff --git a/internal/datastore/revisions/hlcrevision_test.go b/internal/datastore/revisions/hlcrevision_test.go index c74e391e5f..962abdfa1f 100644 --- a/internal/datastore/revisions/hlcrevision_test.go +++ b/internal/datastore/revisions/hlcrevision_test.go @@ -24,7 +24,8 @@ func TestNewForHLC(t *testing.T) { d, err := decimal.NewFromString(tc) require.NoError(t, err) - rev := NewForHLC(d) + rev, err := NewForHLC(d) + require.NoError(t, err) require.Equal(t, tc, rev.String()) }) } diff --git a/pkg/zedtoken/zedtoken_test.go b/pkg/zedtoken/zedtoken_test.go index 2fdf22a659..09bbc4d48e 100644 --- a/pkg/zedtoken/zedtoken_test.go +++ b/pkg/zedtoken/zedtoken_test.go @@ -166,10 +166,16 @@ var hlcDecodeTests = []struct { expectError bool }{ { - format: "V1 ZedToken", - token: "CAIaFQoTMTYyMTUzODE4OTAyODkyODAwMA==", - expectedRevision: revisions.NewForHLC(decimal.NewFromInt(1621538189028928000)), - expectError: false, + format: "V1 ZedToken", + token: "CAIaFQoTMTYyMTUzODE4OTAyODkyODAwMA==", + expectedRevision: func() datastore.Revision { + r, err := revisions.NewForHLC(decimal.NewFromInt(1621538189028928000)) + if err != nil { + panic(err) + } + return r + }(), + expectError: false, }, { format: "V1 ZedToken", @@ -179,7 +185,13 @@ var hlcDecodeTests = []struct { if err != nil { panic(err) } - return revisions.NewForHLC(v) + + r, err := revisions.NewForHLC(v) + if err != nil { + panic(err) + } + + return r })(), expectError: false, }, From 349eb2018343292a36cf3c9e28e39fa75e912499 Mon Sep 17 00:00:00 2001 From: Joseph Schorr Date: Mon, 29 Jan 2024 18:28:18 -0500 Subject: [PATCH 3/3] Fix NewForHLC for unpadded strings --- internal/datastore/revisions/hlcrevision.go | 11 ++++++----- .../datastore/revisions/hlcrevision_test.go | 17 +++++++++++++++++ 2 files changed, 23 insertions(+), 5 deletions(-) diff --git a/internal/datastore/revisions/hlcrevision.go b/internal/datastore/revisions/hlcrevision.go index 03a1299a07..957992b03c 100644 --- a/internal/datastore/revisions/hlcrevision.go +++ b/internal/datastore/revisions/hlcrevision.go @@ -50,13 +50,14 @@ func parseHLCRevisionString(revisionStr string) (datastore.Revision, error) { return datastore.NoRevision, fmt.Errorf("invalid revision string: %q", revisionStr) } - logicalclock, err := strconv.ParseInt(pieces[1], 10, 32) - if err != nil { - return datastore.NoRevision, fmt.Errorf("invalid revision string: %q", revisionStr) + if len(pieces[1]) > logicalClockLength { + return datastore.NoRevision, spiceerrors.MustBugf("invalid revision string due to unexpected logical clock size (%d): %q", len(pieces[1]), revisionStr) } - if len(pieces[1]) != logicalClockLength { - return datastore.NoRevision, spiceerrors.MustBugf("invalid revision string due to unexpected logical clock size (%d): %q", len(pieces[1]), revisionStr) + paddedLogicalClockStr := pieces[1] + strings.Repeat("0", logicalClockLength-len(pieces[1])) + logicalclock, err := strconv.ParseInt(paddedLogicalClockStr, 10, 32) + if err != nil { + return datastore.NoRevision, fmt.Errorf("invalid revision string: %q", revisionStr) } return HLCRevision{timestamp, uint32(logicalclock) + logicalClockOffset}, nil diff --git a/internal/datastore/revisions/hlcrevision_test.go b/internal/datastore/revisions/hlcrevision_test.go index 962abdfa1f..6aefa6be7b 100644 --- a/internal/datastore/revisions/hlcrevision_test.go +++ b/internal/datastore/revisions/hlcrevision_test.go @@ -17,6 +17,8 @@ func TestNewForHLC(t *testing.T) { "-1", "1.0000000023", "1703283409994227985.0000000004", + "1703283409994227985.0000000040", + "1703283409994227985.0010000000", } for _, tc := range tcs { @@ -41,6 +43,7 @@ func TestTimestampNanoSec(t *testing.T) { "1.0000000023": 1, "9223372036854775807.0000000002": 9223372036854775807, "1703283409994227985.0000000004": 1703283409994227985, + "1703283409994227985.0000000040": 1703283409994227985, } for tc, nano := range tcs { @@ -63,6 +66,11 @@ func TestInexactFloat64(t *testing.T) { "1.0000000023": 1.0000000023, "9223372036854775807.0000000002": 9223372036854775807.0000000002, "1703283409994227985.0000000004": 1703283409994227985.0000000004, + "1703283409994227985.0000000040": 1703283409994227985.000000004, + "1703283409994227985.000000004": 1703283409994227985.000000004, + "1703283409994227985.0010": 1703283409994227985.001, + "1703283409994227985.0010000000": 1703283409994227985.001, + "1703283409994227985.001": 1703283409994227985.001, } for tc, floatValue := range tcs { @@ -117,6 +125,15 @@ func TestHLCKeyEquals(t *testing.T) { { "1703283409994227985.0000000005", "1703283409994227985.0000000005", true, }, + { + "1703283409994227985.0000000050", "1703283409994227985.0000000050", true, + }, + { + "1703283409994227985.0000000050", "1703283409994227985.0000000005", false, + }, + { + "1703283409994227985.000000005", "1703283409994227985.0000000050", true, + }, } for _, tc := range tcs {