Rust in Everything
基于 sqlx 0.9.0

pool timed out while waiting for an open connection

主线位置:连接池主线的入口。&Pool 的每个 Executor 方法第一步都是 pool.acquire(),这句报错是 acquire 外面那层 acquire_timeout 到期时返回的。acquire 的完整循环见获取连接,本页只讲最常见的成因:等的那条连接就在自己手里。

flowchart TB
  hold["任务已占一条连接"] --> again["又用 &pool 查询"]
  again --> acq["acquire 等许可"]
  acq --> full{"池满了吗"}
  full -->|没满| ok["新建或复用"]
  full -->|满了| wait["等别人归还"]
  wait --> self{"占着的是自己"}
  self -->|是| pto["acquire_timeout 后报错"]
  self -->|否| ok

本页实验在 M2 Max、macOS、rustc 1.99.0、Postgres 16.14 上运行,依赖 sqlx = "=0.9.0",表建在自己的 schema 里。为了让现象立刻出现,池开得很小,acquire_timeout 设成 1 秒(默认 30 秒)。

现象

三种写法,src/bin/pool_timeout.rs:

async fn small_pool(max: u32) -> anyhow::Result<PgPool> {
  Ok(
    PgPoolOptions::new()
      .max_connections(max)
      .acquire_timeout(Duration::from_secs(1))
      .connect_with(exp_sqlx_pit1::opts())
      .await?,
  )
}

// A helper that takes the pool, called while the caller holds a transaction.
async fn item_count(pool: &PgPool) -> sqlx::Result<i64> {
  sqlx::query_scalar("select count(*) from item").fetch_one(pool).await
}

#[tokio::main]
async fn main() -> anyhow::Result<()> {
  // 1. transaction open, helper uses &pool
  let pool = small_pool(1).await?;
  let mut tx = pool.begin().await?;
  sqlx::query("update item set note = 'x' where id = 1").execute(&mut *tx).await?;
  let t = Instant::now();
  let r = item_count(&pool).await.map_err(|e| e.to_string());
  println!("1 tx + &pool:     {:?} after {:?}  size={} idle={}", r, t.elapsed(), pool.size(), pool.num_idle());
  tx.rollback().await?;

  // 2. stream not finished, second query on &pool inside the loop
  let mut rows = sqlx::query("select id from item order by id").fetch(&pool);
  let t = Instant::now();
  while let Some(row) = rows.try_next().await? {
    let id: i64 = row.get("id");
    let r = sqlx::query("update item set note = 'y' where id = $1").bind(id).execute(&pool).await.map_err(|e| e.to_string());
    println!("2 inside fetch:   id={id} {:?} after {:?}", r.map(|r| r.rows_affected()), t.elapsed());
    break;
  }
  drop(rows);

  // 3. max_connections(3), 3 tasks each hold a transaction and call the helper
  let pool = small_pool(3).await?;
  let t = Instant::now();
  let mut tasks = Vec::new();
  for i in 0..3 {
    let pool = pool.clone();
    tasks.push(tokio::spawn(async move {
      let tx = pool.begin().await?;
      tokio::time::sleep(Duration::from_millis(50)).await;
      let r = item_count(&pool).await.map_err(|e| e.to_string());
      drop(tx);
      Ok::<_, sqlx::Error>((i, r))
    }));
  }
  tokio::time::sleep(Duration::from_millis(500)).await;
  println!("3 while waiting:  size={} idle={}", pool.size(), pool.num_idle());
  for task in tasks {
    let (i, r) = task.await??;
    println!("3 task {i}:         {:?} after {:?}", r, t.elapsed());
  }
  Ok(())
}
1 tx + &pool:     Err("pool timed out while waiting for an open connection") after 1.001609459s  size=1 idle=0
2 inside fetch:   id=1 Err("pool timed out while waiting for an open connection") after 1.008053958s
3 while waiting:  size=3 idle=0
3 task 0:         Err("pool timed out while waiting for an open connection") after 1.053998083s
3 task 1:         Ok(3) after 1.060094667s
3 task 2:         Ok(3) after 1.061167208s
  • 1:事务占着池里唯一的连接,item_count(&pool) 要第二条。它等的是调用者自己手里那条,tx 要等 item_count 返回才会被 rollback,所以永远等不到。
  • 2:fetch(&pool) 返回的流在第一次 poll 时借走一条连接,一直拿到流被 drop。循环体里的 execute(&pool) 要第二条,同样等不到。
  • 3:池有 3 条,3 个任务各用 begin() 占一条,再各要一条。500 毫秒时 size=3 idle=0:池满了,没有人能往下走。1 秒后第一个任务超时,返回之前 drop 了自己的 tx,连接回到池里,另外两个任务才先后拿到连接,又过了不到 10 毫秒都做完了。池再大,只要并发的任务数达到 max_connections,同样的环就会出现,所以这种写法往往在压测或高峰时才暴露。

出处

报错的文字是 Error::PoolTimedOut 的 #[error]。它只在一个地方产生:PoolInner::acquire 把拿许可、弹空闲连接、新建连接的整个循环放进 crate::rt::timeout(self.options.acquire_timeout, ...),到期时 .map_err(|_| Error::PoolTimedOut)。错误里没有「谁占着连接」的信息,池也不记录这一点。

为什么拿 &pool 查询就会去 acquire:&Pool 的 Executor 实现每个方法都先借一条连接,再转给连接自己的实现:

    fn fetch_many<'e, 'q: 'e, E>(
        self,
        query: E,
    ) -> BoxStream<'e, Result<Either<DB::QueryResult, DB::Row>, Error>>
    where
        E: 'q + Execute<'q, Self::Database>,
    {
        let pool = self.clone();

        Box::pin(try_stream! {
            let mut conn = pool.acquire().await?;
            let mut s = conn.fetch_many(query);

            while let Some(v) = s.try_next().await? {
                r#yield!(v);
            }

            Ok(())
        })
    }

conn 是 try_stream! 里的局部变量,流活多久它就活多久;fetch、fetch_all、execute 都经过这里。fetch_optional(也就是 fetch_one)是 pool.acquire().await?.fetch_optional(query).await,查完立刻归还。第 2 种情况就是这个差别:fetch_all 读完才返回,fetch 把连接交给了调用者手里的流。

acquire_timeout 管的不只是排队。服务端连不上时,connect 在超时之内反复重试,最后报的也是这一句(重试和退避见获取连接的「connect:重试和退避」)。两种情况用 pool.size() 区分(src/bin/pool_timeout_down.rs,connect_lazy_with 到一个没有服务监听的端口):

server down: pool timed out while waiting for an open connection after 1.003259917s  size=0 idle=0

池满导致的超时是 size == max_connections 且 num_idle == 0;连不上库是 size == 0。服务端的连接数已经用完时,connect 把 53300 当成暂时错误一直重试,最后报的也是这一句,见 sorry, too many clients already。

📝NOTE
没有蠢问题

问: 把 acquire_timeout 或 max_connections 调大,是不是就好了?

答: 前两种情况不会好:等待者等的是自己手里那条连接,等多久都等不到,超时调大只是让请求卡得更久(默认 30 秒)。第 3 种情况调大 max_connections 只是把门槛往上挪:每个任务同时要两条连接,并发任务数一旦达到池的大小,所有任务都占着一条、等第二条,又是同一个环。超时是这个环唯一的出口,它让最早的那个任务失败、交出连接。真正的修法是让一个任务同时只要一条连接。

修法

让需要连接的代码用已经借到的那一条,或者读完再查。src/bin/pool_timeout_fix.rs:

// Takes any executor: the pool, a transaction, or a connection.
async fn item_count(conn: impl PgExecutor<'_>) -> sqlx::Result<i64> {
  sqlx::query_scalar("select count(*) from item").fetch_one(conn).await
}

#[tokio::main]
async fn main() -> anyhow::Result<()> {
  // 1. reuse the transaction's connection
  let pool = small_pool(1).await?;
  let mut tx = pool.begin().await?;
  sqlx::query("update item set note = 'x' where id = 1").execute(&mut *tx).await?;
  let t = Instant::now();
  let r = item_count(&mut *tx).await;
  println!("1 &mut *tx:       {:?} after {:?}", r, t.elapsed());
  tx.rollback().await?;

  // 2. read everything first, then write
  let t = Instant::now();
  let ids: Vec<i64> = sqlx::query_scalar("select id from item order by id").fetch_all(&pool).await?;
  for id in &ids {
    sqlx::query("update item set note = 'y' where id = $1").bind(id).execute(&pool).await?;
  }
  println!("2 fetch_all:      {} rows updated after {:?}", ids.len(), t.elapsed());

  // 3. three tasks, each passes its own transaction
  let pool = small_pool(3).await?;
  // ...
      let mut tx = pool.begin().await?;
      tokio::time::sleep(Duration::from_millis(50)).await;
      let r = item_count(&mut *tx).await;
      tx.commit().await?;
  // ...
}
1 &mut *tx:       Ok(3) after 1.048667ms
2 fetch_all:      3 rows updated after 8.511458ms
3 task 0:         Ok(3) after 57.47625ms
3 task 1:         Ok(3) after 89.657959ms
3 task 2:         Ok(3) after 89.664667ms
  • 只跑一条查询的辅助函数收 impl PgExecutor<'_>,调用方传 &pool、&mut *tx 或 &mut *conn 都行;要跑多条,收 Acquire。两种签名和 &mut *tx 的来历见 Executor 与 Acquire。
  • 第 1 种还有一层正确性问题:就算池够大、&pool 拿到了第二条连接,那条查询也不在事务里,看不到事务里还没提交的 update。传 &mut *tx 同时修好了这一点。
  • 流里边读边写,要么先 fetch_all 读完(结果集不大时),要么显式 pool.acquire() 借第二条连接、并保证池至少有两条,要么把写入改成一条 UPDATE ... WHERE id = ANY($1)。

怎么确认没中招

  • 搜参数类型是 &PgPool / &Pool<_> 的函数,看有没有在 begin() 和 commit() 之间被调用。
  • 搜 .fetch(&pool) / .fetch(pool),看循环体里有没有再用 pool。
  • 测试里把 max_connections 设成 1:上面第 1、2 种写法在这个设置下每次都会卡到超时,不用等高峰。
  • 线上看到这句报错时同时打出 pool.size() 和 pool.num_idle():size 等于上限、idle 为 0 是连接都被借走了(借了不还,或者上面的环);size 为 0 是连不上库。慢获取的 WARN 日志(sqlx::pool::acquire,默认超过 2 秒)在超时之前就会出现,见获取连接的「慢获取的日志」。

小结

  • 这句报错只表示 acquire 在 acquire_timeout(默认 30 秒)内没拿到连接,不说明原因;池满和连不上库都报它,用 size() 区分。
  • &Pool 的每个 Executor 方法都先 acquire;fetch 返回的流一直占着连接,直到被 drop。
  • 占着一条连接(事务、PoolConnection、没读完的流)再用 &pool 查询,在池满时等的是自己;N 个任务各要两条时,池多大都会在并发达到上限时卡住。
  • 修法:辅助函数收 impl PgExecutor 或 Acquire,事务里传 &mut *tx;流先读完再写。调大超时或池子不是修法。

💬 关联讨论

发起讨论
加载中...