pool.Get() takes a longer time to return connection.
sadiqOyo opened this issue · 11 comments
This is the code I have written to create redisPool at compile time.
var RedisPool *redis.Pool //set at compile time
func RedisSetup() {
RedisPool = newRedisPool(serverUrl, password)
c := RedisPool.Get()
defer c.Close()
pong, err := redis.String(c.Do("PING"))
if err != nil{
fmt.Println("error while connecting redis ", err)
}
fmt.Println("Redis Ping:", pong)
}
func newRedisPool(server, password string) *redis.Pool {
pool := &redis.Pool{
MaxIdle: 10,
MaxActive: 100,
IdleTimeout: 5 * time.Second,
Dial: func() (redis.Conn, error) {
c, err := redis.Dial("tcp", server, redis.DialUseTLS(true), redis.DialTLSSkipVerify(true))
if err != nil {
log.Printf("ERROR: fail initializing the redis pool: %s", err.Error())
fmt.Println("server conn err", err)
return nil, err
}
if password != "" {
if _, err := c.Do("AUTH", password); err != nil {
c.Close()
fmt.Println("auth err", err)
return nil, err
}
}
return c, err
},
TestOnBorrow: func(c redis.Conn, t time.Time) error {
_, err := c.Do("PING")
return err
},
}
return pool
}
Now, this is the function i am using for doing redis operations like set or get.
func GetCacheValue(ctx context.Context, key string) (string, error) {
startTime := time.Now()
span, ctx := apm.StartSpan(ctx, "get cache " + key, "request")
defer span.End()
conn := apmredigo.Wrap(getPool(ctx)).WithContext(ctx)
val, err := redis.String(conn.Do("GET", key))
if err != nil {
return "", err
}
redisPool.Close()
fmt.Println("\n redis get time : ", time.Since(startTime), "\n")
return val, nil
}
func getPool(ctx context.Context) redis.Conn {
startTime :=time.Now()
span, ctx := apm.StartSpan(ctx, "get connection ", "request")
defer span.End()
conn := RedisPool.Get()
fmt.Println("\nPool get time : ", time.Since(startTime), "\n")
return conn
}
This is the output i am getting, I have hit 3 request and got different different response time ,sometime it respond within 1ms or 2ms and sometime it takes around 100ms. Why so much difference? Can someone please help, is there anything I am missing?
Outputs
Likely to be something network related, like DNS lookup time.
To rule out DNS try passing server in as IP instead of a name.
Ok next step is to see how long Dial and TestOnBorrow are taking?
Hi @stevenh , I don't think issue is with Dial and TestOnBorrow, because these function run at compile time. And I am getting
delay at run time while calling.
RedisPool.Get()
They are called when needed, wrapping those with timing will help show if the delay is network based.
I did just notice that you have a few bugs, see the comments:
func GetCacheValue(ctx context.Context, key string) (string, error) {
startTime := time.Now()
span, ctx := apm.StartSpan(ctx, "get cache " + key, "request")
defer span.End()
conn := apmredigo.Wrap(getPool(ctx)).WithContext(ctx)
defer conn.Close() // missing conn close so you'll run the pool out of connections, which could block
val, err := redis.String(conn.Do("GET", key))
if err != nil {
return "", err
}
// redisPool.Close() // This looks invalid to me as there's no var with this case.
fmt.Println("\n redis get time : ", time.Since(startTime), "\n")
return val, nil
} Hi @stevenh , i already fixed the bug. Sorry i just forgot to mentioned it here.
Please find below the dial time and testOnBorrow time.
So looking like there's something strange on you network or with your redis instance.
I would trying tracing your connections with wireshark or tcpdump.
As this isn't a redigo issue going to close this.
Hi @stevenh , my redis instance is ssl true, but here we are passing redis.DialUseTLS(true) .
Do you think, this is the problem here ? Is there any way to pass ssl parameter as true ?
Nope shouldn't be, looks like they are one and the same: https://redis.io/topics/encryption