cortex redis client fails to connect

[zswanson]

Describe the bug
Using the downstream Loki build 1.6.1 which references cortex at github.com/cortexproject/cortex v1.2.1-0.20200803161316-7014ff11ed70 I was able to configure redis cache connections to my AWS ElastiCache redis cluster with this configuration:

chunk_store_config:
  chunk_cache_config:
    redis:
      endpoint: master.myredis-endpoint.use1.cache.amazonaws.com:6379
      expiration: 24h
      enable_tls: true

With this config loki connects to the remote redis and writes/reads keys.

I temporarily pulled fom loki master that uses github.com/cortexproject/cortex v1.3.1-0.20200923132904-22f2efdc1339 and no configuration of redis client seems able to connect.

level=error ts=2020-10-06T23:00:23.0679782Z caller=redis_cache.go:28 msg="error connecting to redis" name=store.index-cache-read.redis err="read tcp 172.17.0.2:33452->XX.XX.XX.XX:6379: i/o timeout"

Using the exact same application config but simply swapping versions I am able to reproduce this easily. The Loki project directly uses the Cortex redis client as far as I can tell, so the bug seems to originate here.

To Reproduce
Steps to reproduce the behavior:

1. configure cortex at 1.3.1-0.20200923132904-22f2efdc1339 to connect to a remote redis (5.0.6 on elasticache), preferably with tls enabled
2. observe that it cannot connect, with an error about timeout

Expected behavior
In the correct path, the cortex redis client establishes a connection and there is no error message, and I can see client connections and command activity on redis.

Environment:

• Infrastructure: AWS ECS Fargate and local docker for testing
• Deployment tool: ECS

Storage Engine

• [ X] Chunks - S3

Additional Context

level=info ts=2020-10-06T23:00:22.9636273Z caller=main.go:124 msg="Starting Loki" version="(version=master-76e73d7, branch=master, revision=76e73d7c)"
level=info ts=2020-10-06T23:00:22.964309Z caller=server.go:225 http=[::]:3100 grpc=[::]:9095 msg="server listening on addresses"
level=info ts=2020-10-06T23:00:22.9647101Z caller=modules.go:408 msg="RulerStorage is not configured in single binary mode and will not be started."
level=warn ts=2020-10-06T23:00:22.9669347Z caller=experimental.go:19 msg="experimental feature in use" feature="Redis cache"
level=info ts=2020-10-06T23:00:22.9670881Z caller=memberlist_client.go:349 msg="Using memberlist cluster node name" name=9bb852e8ddb0-a59d07a9
level=error ts=2020-10-06T23:00:23.0679782Z caller=redis_cache.go:28 msg="error connecting to redis" name=store.index-cache-read.redis err="read tcp 172.17.0.2:33452->XX.XX.XX.XX:6379: i/o timeout"
level=warn ts=2020-10-06T23:00:23.0694413Z caller=experimental.go:19 msg="experimental feature in use" feature="Redis cache"
level=error ts=2020-10-06T23:00:23.1719148Z caller=redis_cache.go:28 msg="error connecting to redis" name=chunksredis err="read tcp 172.17.0.2:33454->XX.XX.XX.XX:6379: i/o timeout"

[slim-bean]

Looking at changes, the first that catches my eye is #2961 which looks like it changed the underlying library to connect to redis. @dmitsh any thoughts here?

[slim-bean]

@zswanson and I tested out a few Loki versions and based on Loki vendoring it was working in cortex commit 97d13c1 and not working in cortex commit cbaf36e

[dmitsh]

@slim-bean , @zswanson , yes, we've switched to github.com/go-redis/redis underlying library to support Redis Cluster and Redis Sentinel.
I run it against different Redis topologies, and it worked well.
I also noticed that since my PR, there were a few releases of go-redis. Perhaps we can update the library to the latest.

I can submit a PR for that.

[zswanson]

My elasticache redis is using 5.0.6, and I tried connecting both with and without TLS using Loki w/ the updated cortex. Only able to get a connection establish when I revert to the Loki build using Cortex before the go-redis library change. Granted that redis 6.0 is the latest, 5.0 is only 2 years old (and still being supported) so it seems odd that it might not work with this library.

[dmitsh]

Hi @zswanson . It seems that the issue is with the underlying go-redis library. Would you be able to try and connect directly using go-redis client? If so, could you share the error you are seeing?

[zswanson]

@dmitsh my s/w team is telling me that we actually use the go-redis library in our own product, and our go apps all connect to the same version of elasticache-redis. We're not on the latest release of redis-go however.

[zswanson]

@dmitsh I ran the following code and this connects and returns a PONG output:

package main

import (
    "fmt"
    "context"
    "github.com/go-redis/redis/v8"
    "github.com/docker/go-connections/tlsconfig"
)

var ctx = context.Background()

func main() {
    rdb := redis.NewClient(&redis.Options{
        Addr:     "master.my-redis-elasticache-address.amazon.com:6379",
        Password: "", // no password set
        DB:       0,  // use default DB
        TLSConfig: tlsconfig.ClientDefault(),
    })

    pong, err := rdb.Ping(ctx).Result()
    fmt.Println(pong, err)
}

If I remove the tlsconfig though, I get an i/o timeout that looks a heck of a lot like the one I'm getting in cortext/loki, which makes me suspicious that the tls flag is getting ignored

[zswanson]

I also ran a small go app that lays out the redis client using the same format as the cortex redis_client.go and that connects ok as well. Tried with with go_redis at both 8.2.3 and the 8.0.0-beta that was used previously, both seem to work when ran independently.

[dmitsh]

@zswanson
We actually use redis.NewUniversalClient() instead of redis.NewClient(), but I don't think it makes the difference.
What is different is the TLSConfig itself.
You are using tlsconfig.ClientDefault(), and we simply use &tls.Config{}
(https://github.com/cortexproject/cortex/blob/master/pkg/chunk/cache/redis_client.go#L63)

The main difference with redigo might be that they use InsecureSkipVerify=true

[zswanson]

@dmitsh here's the hacky version of the cortec client that I pieced together, and I get a PONG response from.
go.mod was using github.com/go-redis/redis/v8 at v8.2.3, and I also tried it successfully with v8.0.0-beta.10.0.20200905143926-df7fe4e2ce72 which was the version before your last PR.
cortex_redis.txt

[dmitsh]

@zswanson, so it works if you explicitly specify the endpoint?

[zswanson]

@dmitsh its the 'master' endpoint for the cluster. When using TLS I can't set a cert on the AWS Elasticache, so I have to directly use their A record and not a 'pretty url' record because the cert won't validate against the domain name. (ie, I can't use cortex-redis.mydomain.com and alias that to the AWS endpoint for the cluster)

[dmitsh]

@zswanson, I don't have AWS account. Is there any way for me to reproduce it on a local machine?

[zswanson]

I was trying and unable to get a timeout to occur locally - I then out of sheer "what else could the problem" set the redis.timeout param to 500ms and the errors vanished. The default timeout is 100ms. With a value of >= 200ms, I'm getting connections visible in my redis metrics. Now, why 100ms wasn't enough inside the aws vpc I have no idea

I now have much shame. :(