When a task will be abort in tonic？

[wqshr12345]

Bug Report

Version

0.8.3

Platform

Linux myname 5.15.0-82-generic #91-Ubuntu SMP Mon Aug 14 14:14:14 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

Description

Hi, I encountered an issue while using Tonic, which might be caused by an aborted Tokio task. Let me briefly describe the problem I'm facing and I'm hoping to receive your response.

Here's the code I'm using, which is generated using the protocol:

pub mod server {
    #![allow(unused_variables, dead_code, missing_docs, clippy::let_unit_value)]
    use tonic::codegen::*;
    /// Generated trait containing gRPC methods that should be implemented for use with MdsServer.
    #[async_trait]
    pub trait Mds: Send + Sync + 'static {
        async fn look(
            &self,
            request: tonic::Request<super::LookRequest>,
        ) -> Result<tonic::Response<super::LookResponse>, tonic::Status>;
    }
}

This is the specific logic I've implemented for the look function.

#[tonic::async_trait]
impl server::Mds for MyMds {
    async fn look(
        &self, req: Request<LookRequest>,
    ) -> Result<Response<LookResponse>, Status> {
        mutex.lock().await; // This is a global lock
        // Do something
        info!("start functionA");
        functionA().await.unwrap();
        info!("end functionA");
    }
}

However, I've noticed through logs that the service doesn't behave as expected. The logs show a pattern where the execution logic seems to repeat:

start functionA
end functionA
start functionA
end functionA
start functionA
end functionA
...
start functionA
start functionA
start functionA
...

It appears that the tasks are being discarded after reaching functionA().await, allowing new tasks to acquire the lock and execute the logic. I'm wondering under what circumstances Tonic might discard a task handling RPC server logic?

[wqshr12345]

I conducted some additional tests, and I found a line in my log that looks like this now. The log is roughly like this.

INFO start functionA
INFO end functionA
INFO start functionA
INFO end functionA
INFO start functionA
INFO end functionA
INFO start functionA
DEBUG server_handshake:Connection:poll:FramedRead::poll_next: /root/.cargo/registry/src/rsproxy.cn-8f6827c7555bfaf8/h2-0.3.18/src/codec/framed_read.rs:354: received frame=Reset { stream_id: StreamId(13495), error_code: CANCEL } peer=Server
INFO start functionA

I lack a contextual understanding of Tonic. Could you please explain under what circumstances this issue arises? I look forward to your response.

[LucioFranco]

@wqshr12345 is the client cancelling the request halfway through? If so tonic will drop the task when the client does that.

[wqshr12345]

@wqshr12345 is the client cancelling the request halfway through? If so tonic will drop the task when the client does that.

I think this may be the reason. When will the tonic client cancel the request? By default, does it wait for some timeout? For example, if the client waits for 10 seconds and still does not receive a response, will it send a reset?