poll_ready must be called first:没就绪就 call
主线位置:就绪主线和请求主线的交接处。
poll_ready在服务实例身上占了一样东西(许可、通道位置、本窗口的次数、一条连接),call要从同一个实例身上把它取出来。没占就call,或者占的是 A、call的是 B,就会走到这一页的 panic。
flowchart TB rdy["ready().await"] --> held["self.inner 占到许可"] held --> callreq["call(req)"] callreq --> c1["clone 一份再 call"] callreq --> c2["clone 一份再 oneshot"] callreq --> c3["mem::replace 换出来"] c1 --> p1["副本没有许可:panic"] c2 --> p2["副本等原件的许可:卡死"] c3 --> p3["就绪的那个进 future:正常"]
Service trait 里说过:没拿到 Ready(Ok) 就 call,实现方可以 panic(call 的文档)。这一页讲这条规则在实际代码里怎么被踩到,以及 panic 信息长什么样。
四种 panic 信息
每个服务新建出来不 poll_ready,直接 call:
tower = { version = "=0.5.3", features = ["limit", "buffer", "reconnect", "util"] }
tokio = { version = "=1.54.1", features = ["full"] }
use std::panic::{AssertUnwindSafe, catch_unwind};
use std::time::Duration;
use tower::buffer::Buffer;
use tower::limit::{ConcurrencyLimit, RateLimit, rate::Rate};
use tower::reconnect::Reconnect;
use tower::{BoxError, Service, service_fn};
fn echo() -> impl Service<u32, Response = u32, Error = BoxError, Future: Send> + Send + 'static {
service_fn(|x: u32| async move { Ok::<_, BoxError>(x) })
}
// Call `f` and print the panic message (or "no panic").
fn try_call(name: &str, f: impl FnOnce()) {
match catch_unwind(AssertUnwindSafe(f)) {
Ok(()) => println!("{name}: no panic"),
Err(p) => {
let msg = p
.downcast_ref::<&str>()
.map(|s| s.to_string())
.or_else(|| p.downcast_ref::<String>().cloned())
.unwrap();
println!("{name}: {msg}");
}
}
}
#[tokio::main(flavor = "current_thread")]
async fn main() {
let mut cl = ConcurrencyLimit::new(echo(), 4);
try_call("ConcurrencyLimit", || drop(cl.call(1)));
let mut rl = RateLimit::new(echo(), Rate::new(1, Duration::from_secs(1)));
try_call("RateLimit, 1st call", || drop(rl.call(1)));
try_call("RateLimit, 2nd call", || drop(rl.call(2)));
let mk = service_fn(|_: ()| std::future::ready(Ok::<_, BoxError>(echo())));
let mut rc = Reconnect::new(mk, ());
try_call("Reconnect", || drop(Service::<u32>::call(&mut rc, 1)));
let mut bf = Buffer::new(echo(), 4);
try_call("Buffer", || drop(bf.call(1)));
}
M2 Max、rustc 1.99.0、--release,连跑 3 次,除了线程编号以外输出相同(thread 'main' ... panicked at 那几行是默认 panic hook 打到 stderr 的):
thread 'main' (124641) panicked at ~/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tower-0.5.3/src/limit/concurrency/service.rs:86:14:
max requests in-flight; poll_ready must be called first
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
ConcurrencyLimit: max requests in-flight; poll_ready must be called first
RateLimit, 1st call: no panic
thread 'main' (124641) panicked at ~/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tower-0.5.3/src/limit/rate/service.rs:115:31:
service not ready; poll_ready must be called first
RateLimit, 2nd call: service not ready; poll_ready must be called first
thread 'main' (124641) panicked at ~/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tower-0.5.3/src/reconnect/mod.rs:149:18:
service not ready; poll_ready must be called first
Reconnect: service not ready; poll_ready must be called first
thread 'main' (124641) panicked at ~/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tower-0.5.3/src/buffer/service.rs:122:23:
`send_item` called without first calling `poll_reserve`
Buffer: `send_item` called without first calling `poll_reserve`
| 中间件 | 什么时候 panic | 信息 | 出处 |
|---|---|---|---|
ConcurrencyLimit | 手里没有许可就 call,一定 panic | max requests in-flight; poll_ready must be called first | call 里对 self.permit.take() 的 expect |
RateLimit | 只在 State::Limited 时;窗口里还有次数,不 poll_ready 也能 call | service not ready; poll_ready must be called first | call 的 State::Limited 分支 |
Reconnect | 状态不是 Connected,而且没有存着的连接错误 | service not ready; poll_ready must be called first | call 的兜底分支 |
Buffer | 句柄没有预留通道位置 | `send_item` called without first calling `poll_reserve` | call 调 self.tx.send_item,panic 在 tokio-util 的 PollSender::send_item 里 |
几点:
- RateLimit 的这个坑测不出来。上面
Rate::new(1, ...)第一次call不 panic,第二次才 panic。窗口次数设得大一点,单元测试里发几个请求永远不会触发,上线后流量一过阈值才 panic。原因见 RateLimit:只有扣掉最后一次的那个call会把状态切到Limited。 - Buffer 的信息里没有
poll_ready。按poll_ready must be called first搜日志,搜不到Buffer的这一条。send_item标了#[track_caller],所以 panic 的位置报的是 tower 的buffer/service.rs:122,不是 tokio-util 的文件。 Timeout、Filter、LoadShed、SpawnReady(服务还在手里时)不 panic,见 单服务中间件 的对照表。不 panic 不等于用对了:LoadShed会直接返回Overloaded。
真实的样子:在 call 里 clone 内层
很少有人真的不调 poll_ready 就 call。常见的是:poll_ready 问的是 self.inner,call 用的却是 self.inner.clone()。手写中间件要把内层服务移进一个 async 块时,最顺手的写法就是这样。
下面的 Log 中间件有三种 call 写法,分别套在 ConcurrencyLimit(1) 和 Buffer(1) 外面,每种发两个请求:
tower = { version = "=0.5.3", features = ["limit", "buffer", "util"] }
tokio = { version = "=1.54.1", features = ["full", "test-util"] }
use std::future::Future;
use std::pin::Pin;
use std::task::{Context, Poll};
use std::time::Duration;
use tower::{BoxError, Service, ServiceBuilder, ServiceExt, service_fn};
#[derive(Clone, Copy, Debug)]
enum Mode {
CloneThenCall,
CloneThenOneshot,
Replace,
}
// A hand-written middleware whose call moves the inner service into a boxed future.
#[derive(Clone)]
struct Log<S> {
inner: S,
mode: Mode,
}
impl<S> Service<u32> for Log<S>
where
S: Service<u32, Response = u32, Error = BoxError> + Clone + Send + 'static,
S::Future: Send,
{
type Response = u32;
type Error = BoxError;
type Future = Pin<Box<dyn Future<Output = Result<u32, BoxError>> + Send>>;
fn poll_ready(&mut self, cx: &mut Context<'_>) -> Poll<Result<(), BoxError>> {
self.inner.poll_ready(cx)
}
fn call(&mut self, req: u32) -> Self::Future {
match self.mode {
Mode::CloneThenCall => {
let mut inner = self.inner.clone();
Box::pin(async move { inner.call(req).await })
}
Mode::CloneThenOneshot => {
let inner = self.inner.clone();
Box::pin(async move { inner.oneshot(req).await })
}
Mode::Replace => {
let clone = self.inner.clone();
let mut inner = std::mem::replace(&mut self.inner, clone);
Box::pin(async move { inner.call(req).await })
}
}
}
}
async fn run<S>(label: &str, inner: S, mode: Mode)
where
S: Service<u32, Response = u32, Error = BoxError> + Clone + Send + 'static,
S::Future: Send,
{
let mut svc = Log { inner, mode };
let task = tokio::spawn(async move {
let mut out = Vec::new();
for i in 1..=2 {
out.push(svc.ready().await?.call(i).await?);
}
Ok::<_, BoxError>(out)
});
let result = match tokio::time::timeout(Duration::from_secs(5), task).await {
Err(_) => "still waiting after 5s".to_string(),
Ok(Ok(r)) => format!("{:?}", r.map_err(|e| e.to_string())),
Ok(Err(e)) => {
let p = e.into_panic();
let msg = p
.downcast_ref::<&str>()
.map(|s| s.to_string())
.or_else(|| p.downcast_ref::<String>().cloned())
.unwrap();
format!("panic: {msg}")
}
};
println!("{label:<10} {:<17} -> {result}", format!("{mode:?}"));
}
fn echo() -> impl Service<u32, Response = u32, Error = BoxError, Future: Send> + Clone + Send + 'static {
service_fn(|x: u32| async move { Ok::<_, BoxError>(x) })
}
#[tokio::main(flavor = "current_thread", start_paused = true)]
async fn main() {
std::panic::set_hook(Box::new(|_| {})); // keep the default hook quiet
for mode in [Mode::CloneThenCall, Mode::CloneThenOneshot, Mode::Replace] {
run("limit(1)", ServiceBuilder::new().concurrency_limit(1).service(echo()), mode).await;
run("buffer(1)", ServiceBuilder::new().buffer(1).service(echo()), mode).await;
}
}
时钟是暂停的(start_paused,需要 tokio 的 test-util),「5 秒」不用真等。连跑 3 次输出相同:
limit(1) CloneThenCall -> panic: max requests in-flight; poll_ready must be called first
buffer(1) CloneThenCall -> panic: `send_item` called without first calling `poll_reserve`
limit(1) CloneThenOneshot -> still waiting after 5s
buffer(1) CloneThenOneshot -> still waiting after 5s
limit(1) Replace -> Ok([1, 2])
buffer(1) Replace -> Ok([1, 2])
- clone 后 call:panic。
ConcurrencyLimit和Buffer的Clone都故意不复制就绪状态:ConcurrencyLimit的副本permit: None(Clone),Buffer的副本是一个新的PollSender,没有预留位置(Clone)。就绪的是self.inner,被call的是副本。 - clone 后 oneshot:不 panic,但永远等下去。 这是最容易想到的「修法」:既然副本没就绪,就在 future 里让它自己等就绪。可是唯一的许可(或唯一的通道位置)还在
self.inner手里。按规则 2,self.inner在下一次call之前会一直拿着它;而下一次call要等这个请求完成。上限大于 1 时不会卡死,但每个在途请求背后,self.inner都额外压着一份许可或位置,直到下一次call才用掉:另跑一个上限为 2 的同样写法,只发一个请求,请求进行中信号量剩 0 个许可,请求结束后剩 1 个(连跑 3 次相同)。 - mem::replace:正常。 把就绪的那个换出来移进 future,把副本留在
self.inner。副本没就绪没关系,下一个请求之前调用方本来就会再poll_ready。这就是Service文档里给的写法。
RateLimit 不会以这种方式出错:它没有 Clone,self.inner.clone() 编译不过。它在需要 Clone 的地方带来的是另一种错误,见 Clone is not satisfied。
issue #547(2021 年 1 月)的标题是「Combining a tower Service with a tonic client panics」。报告者升级到 tower 0.4.4 后,自己写的服务在 call 里 let mut inner = self.0.clone(); 再 inner.call(req),得到 panicked at 'buffer full; poll_ready must be called first',并且强调「Can confirm that poll_ready was in fact called」。这条信息是 0.4 的 Buffer 发出的,也就是说 tonic 的 Channel 背后有一个 Buffer。维护者的回复:「This subtly breaks the contract. The service is driven to ready and then cloned before it is invoked. The original service is ready, but the clone is not necessarily ready.」并给出了 mem::replace 的写法。
随后 PR #548「service: Clarify subtly around cloning and readiness」在 Service 文档里加了「Be careful when cloning inner services」一节,第一个包含它的发布是 tower-service 0.3.2。
那时 Buffer 的 panic 信息还是 tower 自己写的 buffer full; poll_ready must be called first(0.4.13 的 call 里对信号量许可的 expect)。0.5.0 的 #635 把 Buffer 改成直接用有界 mpsc(「This branch changes the buffer to use only a single bounded MPSC, rather than an unbounded MPSC and a semaphore」),许可由 PollSender 保管,信息就变成了上面表里 tokio-util 的那一句。用 0.4.13 跑同样的「不 ready 就 call」,得到的是:
thread 'main' (129379) panicked at ~/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tower-0.4.13/src/buffer/service.rs:146:14:
buffer full; poll_ready must be called first
排查顺序
看到这几条 panic 之一时:
- 找到 panic 的那次
call,确认它的接收者和前面poll_ready的接收者是同一个实例。clone()、Layer::layer新造的实例、Arc<Mutex<S>>里取出来的另一份,都不算同一个。 - 自己写的中间件,
call里要把内层移进 future 时用mem::replace;不需要移进 future 时直接self.inner.call(req),把返回的 future 包起来。 - 不要在 future 里让副本自己
ready():同一个实例上的poll_ready占着的资源不会被释放。
小结
ConcurrencyLimit没许可就call一定 panic;RateLimit只在窗口次数用完后 panic,测试里不容易暴露;Reconnect未连接时 panic;Buffer的 panic 来自 tokio-util,信息是`send_item` called without first calling `poll_reserve`。- 常见原因是
poll_ready问的是原件、call用的是clone()出来的副本;这几个中间件的Clone都不复制就绪状态。 - 在 future 里让副本自己
oneshot不 panic,但原件手里的许可或通道位置不放,上限为 1 时直接卡死。 - 正确写法是
mem::replace换出已经就绪的那个。