Investigate the unreasonably fast denial latency metrics

[beautifulentropy]

Something we are seeing in some metrics that we checked today is that consistently 50% of keys are "NotFound". We really do not expect to see this under normal operating conditions unless 50% of callers have never interacted with our key-value rate limits system before. This could explain why we're seeing super fast denials. It's not that the denials are the only data being served locally it's that the only denials we're getting are being served locally. Denials are expected to be the fastest operation because they're just one GET operation and a little math which exits really early. Where as an allowed call must GET + make newTAT + SET newTAT.

I wrote a couple of tests to ensure that the sharding implementation we're using from go-redis, when combined with our custom DNS SRV resolver, is actually doing what it's supposed to. The following test ensures that two separately configured redis.Ring clients:

• are distributing writes somewhat evenly
• are sharding pipeline writes consistently
• are sharding pipeline reads consistently

func TestSharding(t *testing.T) {
	logger := blog.NewMock()
	ring1 := newTestRedisRing()
	ring2 := newTestRedisRing()
	lookup1, err := newLookup([]cmd.ServiceDomain{
		{
			Service: "redisratelimits",
			Domain:  "service.consul",
		},
	},
		"consul.service.consul",
		250*time.Millisecond,
		ring1,
		logger,
		metrics.NoopRegisterer,
	)
	test.AssertNotError(t, err, "Expected newLookup construction to succeed")
	lookup1.start()
	defer lookup1.stop()
	lookup2, err := newLookup([]cmd.ServiceDomain{
		{
			Service: "redisratelimits",
			Domain:  "service.consul",
		},
	},
		"consul.service.consul",
		250*time.Millisecond,
		ring2,
		logger,
		metrics.NoopRegisterer,
	)
	test.AssertNotError(t, err, "Expected newLookup construction to succeed")
	lookup2.start()
	defer lookup2.stop()

	pipeline := ring1.Pipeline()
	for i := 0; i < 1000; i++ {
		err := pipeline.Set(context.Background(), fmt.Sprintf("key%d", i), "value", 0).Err()
		test.AssertNotError(t, err, "Expected GET to succeed for all shards")
	}
	cmd, err := pipeline.Exec(context.Background())
	test.AssertNotError(t, err, "Expected EXEC to succeed for all shards")
	for _, c := range cmd {
		_, err := c.(*redis.StatusCmd).Result()
		test.AssertNotError(t, err, "Expected GET to succeed for all shards")
	}

	var shard1 *redis.Client
	var shard2 *redis.Client
	err = ring1.ForEachShard(context.Background(), func(ctx context.Context, shard *redis.Client) error {
		if shard1 == nil {
			shard1 = shard
		} else {
			shard2 = shard
		}
		return nil
	})
	test.AssertNotError(t, err, "Expected ForEach to succeed")

	shard1Keyspace := shard1.Info(context.Background(), "keyspace").Val()
	shard2Keyspace := shard2.Info(context.Background(), "keyspace").Val()

	fmt.Println(shard1.Options().Addr, shard1Keyspace)
	fmt.Println(shard2.Options().Addr, shard2Keyspace)

	// Try to read all written keys from both shards using a pipeline.
	pipeline = ring2.Pipeline()
	for i := 0; i < 1000; i++ {
		err := pipeline.Get(context.Background(), fmt.Sprintf("key%d", i)).Err()
		test.AssertNotError(t, err, "Expected GET to succeed for all shards")
	}
	cmd, err = pipeline.Exec(context.Background())
	test.AssertNotError(t, err, "Expected EXEC to succeed for all shards")
	for _, c := range cmd {
		_, err := c.(*redis.StringCmd).Result()
		test.AssertNotError(t, err, "Expected GET to succeed for all shards")
	}

	err = ring2.ForEachShard(context.Background(), func(ctx context.Context, shard *redis.Client) error {
		if shard1 == nil {
			shard1 = shard
		} else {
			shard2 = shard
		}
		return nil
	})
	test.AssertNotError(t, err, "Expected ForEach to succeed")

	shard1Keyspace = shard1.Info(context.Background(), "keyspace").Val()
	shard2Keyspace = shard2.Info(context.Background(), "keyspace").Val()

	fmt.Println(shard1.Options().Addr, shard1Keyspace)
	fmt.Println(shard2.Options().Addr, shard2Keyspace)
}

=== RUN   TestSharding
10.33.33.5:4218
db0:keys=525,expires=0,avg_ttl=0

10.33.33.4:4218
db0:keys=475,expires=0,avg_ttl=0

10.33.33.5:4218
db0:keys=525,expires=0,avg_ttl=0

10.33.33.4:4218
db0:keys=475,expires=0,avg_ttl=0