Error sink not called unless debugger is attached with breakpoints

[nyurik]

This code reproduces the issue fairly reliably on my Linux box with Rust 1.67. For debugging I used IntelliJ, but I don't know if the same behavior is on VS code.

Error Sink is not called when PostgreSQL reports a connection error on pool.get(), unless I run this code in a debugger with two breakpoints set. Instead of the actual PG error, it reports a timeout error without calling the error sink.

Make sure to run postgres in a docker container (see message in code). The two commented-out test lines work fine.

// [dependencies]
// bb8 = "0.8"
// bb8-postgres = "0.8"
// env_logger = "0.10"
// log = "0.4"
// postgres = "0.19"
// tokio = { version = "1", features = ["full"] }

use std::str::FromStr;

type PgConnManager = bb8_postgres::PostgresConnectionManager<postgres::NoTls>;
type PgPool = bb8::Pool<PgConnManager>;
type PgConnError = <PgConnManager as bb8::ManageConnection>::Error;

#[derive(Debug, Clone, Copy)]
struct PgErrorSink;

impl bb8::ErrorSink<PgConnError> for PgErrorSink {
    fn sink(&self, e: PgConnError) {
        println!("ErrorSink pg error: {e}");
    }

    fn boxed_clone(&self) -> Box<dyn bb8::ErrorSink<PgConnError>> {
        println!("Cloning ErrorSink");
        Box::new(*self)
    }
}

#[tokio::main]
async fn main() -> Result<(), bb8::RunError<postgres::Error>> {
    // Allow this type of invocation:   RUST_LOG=TRACE cargo run
    env_logger::Builder::from_env(env_logger::Env::default()).init();
    println!("Make sure this is running:");
    println!("  docker run --rm -it -e POSTGRES_PASSWORD=postgres -p 5401:5432 postgres");

    // test("postgres://postgres:[email protected]:5401/postgres").await?;
    // test("postgres://postgres:[email protected]:5401/postgres?sslmode=disable").await?;
    test("postgres://postgres:[email protected]:5401/postgres?sslmode=require").await?;
    Ok(())
}

async fn test(conn_str: &str) -> Result<(), bb8::RunError<postgres::Error>> {
    println!("\nConnecting to {conn_str}");
    let pg_cfg = bb8_postgres::tokio_postgres::config::Config::from_str(conn_str)?;

    let pool = PgPool::builder()
        .max_size(1)
        .connection_timeout(std::time::Duration::from_secs(5))
        .error_sink(Box::new(PgErrorSink))
        .build(PgConnManager::new(pg_cfg, postgres::NoTls))
        .await?;

    let query = "SELECT version();";
    let val = pool.get().await?.query_one(query, &[]).await?;
    println!("Version: {:?}", val.get::<_, String>(0));
    Ok(())
}

Running without debugger

The above code prints Error: TimedOut

Running with debugger

I was able to see the error sink error if I set two breakpoints in the debugger (I used IntelliJ) -- note that both breakpoints are required for this to work.

• https://github.com/sfackler/rust-postgres/blob/4bae134f501db5c08b8dd43a44474e515bbb39d3/tokio-postgres/src/connect.rs#L48

• bb8/bb8/src/inner.rs

  Line 67 in 5737736

  Err(e) => this.inner.statics.error_sink.sink(e),

Run the code and keep hitting F9 (Resume), and it prints this:

ErrorSink pg error: error performing TLS handshake: server does not support TLS
Error: TimedOut

[djc]

Sorry about that -- sounds like some kind of odd race condition is making it timing-dependent? I'm afraid I won't have much time to investigate, but happy to support you if you're able to dig in more.

I think this might be the same as #141?

[couchand]

Yes this looks very much the same as #141. It looks like the debugger's breakpoints allow the error to be dispatched to the sink before the main future completes, but this is unlikely to happen in the general case for the same reasons I describe there.