Grpc throws deadline exceeded after negative number of seconds from now

Question

First calls usually successful, but then I have exception with message like those:

io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED: ClientCall started after deadline exceeded: -175.597476157s from now

Why is the number of seconds negative? How do I fix it?

My grpc config:

public class MyAppLibGrpcSenderConfig {

    @Value("${grpc.client.host:localhost}")
    private String host;
    @Value("${grpc.client.port:9090}")
    private int port;
    @Value("${grpc.client.negotiationType:PLAINTEXT}")
    private String negotiationType;
    @Value("${grpc.client.deadline:300000}")
    private long deadline;

    @Autowired
    private Tracer tracer;

    @Bean
    public ManagedChannel managedChannel() {
        ManagedChannelBuilder<?> builder = ManagedChannelBuilder.forAddress(host, port);
        if ("PLAINTEXT".equals(negotiationType)) {
            builder.usePlaintext();
        }
        return builder.build();
    }

    @Bean
    public TracingClientInterceptor tracingClientInterceptor(Tracer tracer) {
        return TracingClientInterceptor
                .newBuilder()
                .withTracer(this.tracer)
                .build();
    }

    @Bean
    public MyAppSenderServiceGrpc.MyAppSenderServiceBlockingStub myAppSenderServiceBlockingStub(
            TracingClientInterceptor tracingClientInterceptor,
            ManagedChannel managedChannel) {
        return MyAppSenderServiceGrpc
                .newBlockingStub(tracingClientInterceptor.intercept(managedChannel))
                .withDeadlineAfter(deadline, TimeUnit.MILLISECONDS);
    }

    @Bean
    public MyAppCodeLoaderServiceGrpc.MyAppCodeLoaderServiceBlockingStub myAppCodeLoaderServiceBlockingStub(
            TracingClientInterceptor tracingClientInterceptor,
            ManagedChannel managedChannel) {
        return MyAppCodeLoaderServiceGrpc
                .newBlockingStub(tracingClientInterceptor.intercept(managedChannel))
                .withDeadlineAfter(deadline, TimeUnit.MILLISECONDS);
    }
}

Client code:

@net.devh.boot.grpc.server.service.GrpcService
public class MyAppEventKafkaSender extends MyAppSenderServiceGrpc.MyAppSenderServiceImplBase {

    ...
    
    @SneakyThrows
    @Override
    public void sendMessage(ContextMyAppEventGrpc contextMyAppEventGrpc,
                            StreamObserver<Empty> responseObserver) {
        try {
            sendEvent(contextMyAppEventGrpc);
            Empty reply = Empty.newBuilder().build();
            responseObserver.onNext(reply);
            responseObserver.onCompleted();
        } catch (Exception e) {
            Status status = Status.INTERNAL.withDescription(e.getMessage());
            responseObserver.onError(status.asRuntimeException());
        }
    }
    
}

Varun Thakur · Accepted Answer · 2021-07-01T10:56:05.500

Deadline is an absolute point in time and is set immediately when you create your stub (and not necessarily when you execute it) - this is in contrast to timeouts which are relative to the start of the call.

So negative deadline means that it expired before your stub was executed.

To fix the issue, you should be setting deadline immediately before making a call.

var response = blockingStub.withDeadlineAfter(300000, TimeUnit.MILLISECONDS)
                           .yourRpcName();

Grpc throws deadline exceeded after negative number of seconds from now

1 Answers1