Unusually slow to give redis connections

[axos88]

From inside a tokio context:

    let manager = RedisConnectionManager::new("redis://127.0.0.1/3").expect("Could not create redis connection manager");
    let redis_pool = Pool::builder().min_idle(Some(5)).build(manager).await.expect("Could not create redis connection pool");

And then

  let start = Instant::now();
  redis.get().await;
  info!("GET executed in {:?}", start.elapsed());

Returns between 0.5-2.5seconds.

This seems abnormal, am I doing something wrong?

bb8 v0.8.0
redis v0.22.3

[djc]

It does seem abnormal. Here's what I get:

p50: 91.22625ms
p90: 92.520375ms
p99: 95.642375ms

However, that's from the Netherlands to a Redis running in Montréal, Canada. According to some website with global ping times, 90ms is an average amount of latency for connections from Amsterdam to Toronto, so it seems like bb8 + redis add very little overhead for me.

use std::time::Instant;

use bb8_redis::{bb8::Pool, RedisConnectionManager};

#[tokio::main]
async fn main() {
    let manager = RedisConnectionManager::new("redis://redis.strb.dev").unwrap();
    let pool = Pool::builder()
        .min_idle(Some(5))
        .build(manager)
        .await
        .unwrap();

    let mut latencies = Vec::new();
    for _ in 0..250 {
        let start = Instant::now();
        if let Err(err) = pool.get().await {
            println!("Error: {:?}", err);
        }
        let latency = start.elapsed();
        latencies.push(latency);
        println!("Time elapsed: {:?}", latency);
    }

    latencies.sort();
    println!("p50: {:?}", latencies[latencies.len() / 2]);
    println!(
        "p90: {:?}",
        latencies[(latencies.len() as f64 * 0.9) as usize]
    );
    println!(
        "p99: {:?}",
        latencies[(latencies.len() as f64 * 0.99) as usize]
    );
}

[djc]

Okay, I do have a server that's running a Redis server, connecting to localhost on that (very old) server:

p50: 79.257µs
p90: 92.662µs
p99: 164.004µs

[axos88]

Any idea how to debug this to get more insight on what's happening? - Also was it intentional that you closed the issue?

[djc]

You could run it with a profiler I suppose?

I did close it intentionally -- if this wasn't specific to your environment somehow I would be getting a lot of issues about it.

[axos88]

After some debugging I found that my pool size was too small.

[djc]

Glad you figured it out!

[axos88]

I wouldn't say that, I'm still a bit unsure why actix starts 16 redis connections in the background, but this is definately not something that would be bb8's plate :). Thanks for your help and your work!