Armeria: io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED

[sunning9001]

env: JDK 1.8 os: windows armeria version: 0.52.0 data format: google protocal buffer

on the rpc client ,I set idleTimeout =50 second , and rpc server ,I set idleTimeout =50 secord ,requestTimeout =50 secord . but 10 second pass, the io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED occur.

I also know that only the default IDLE_TIMEOUT_MILLIS is ten second.

why the parameters I had set do not work ??

the rpc client code:

        ClientFactory factory=  new ClientFactoryBuilder().idleTimeout( Duration.ofSeconds(50)).build();

            ClientBuilder builder = new ClientBuilder("gproto+http://127.0.0.1:8080/")
                    .decorator(HttpRequest.class, HttpResponse.class, LoggingClient.newDecorator()).factory(factory);

            HelloServiceFutureStub helloService = builder.build(HelloServiceFutureStub.class);                                                                          // HelloServiceFutureStub.class

            HelloRequest request = HelloRequest.newBuilder().setName("Armerian World").build();
            ListenableFuture<HelloReply> reply = helloService.hello(request);
            reply.get();

the rpc server code:

    ServerBuilder sb = new ServerBuilder().idleTimeout( Duration.ofSeconds(50)).defaultRequestTimeout( Duration.ofSeconds(50));
    sb.port(8080, HTTP);
    sb.serviceUnder("/", new GrpcServiceBuilder().addService(new MyHelloService()).build());

    Server server = sb.build();
    server.start();

the exception code:
java.util.concurrent.ExecutionException: io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED
at com.google.common.util.concurrent.AbstractFuture.getDoneValue(AbstractFuture.java:503)
at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:482)
at GrpcClient.main(GrpcClient.java:40)
时间11
Caused by: io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED
at io.grpc.Status.asRuntimeException(Status.java:543)
at io.grpc.stub.ClientCalls$UnaryStreamToFuture.onClose(ClientCalls.java:442)
at com.linecorp.armeria.client.grpc.ArmeriaClientCall.transportReportStatus(ArmeriaClientCall.java:241)
at com.linecorp.armeria.internal.grpc.HttpStreamReader.onNext(HttpStreamReader.java:100)
at com.linecorp.armeria.internal.grpc.HttpStreamReader.onNext(HttpStreamReader.java:41)
at com.linecorp.armeria.common.stream.DefaultStreamMessage.notifySubscriberWithElements(DefaultStreamMessage.java:359)
at com.linecorp.armeria.common.stream.DefaultStreamMessage.notifySubscriber(DefaultStreamMessage.java:331)
at com.linecorp.armeria.common.stream.DefaultStreamMessage.lambda$notifySubscriber$2(DefaultStreamMessage.java:298)
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:403)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:462)
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
at java.lang.Thread.run(Thread.java:745)

[anuraaga]

Thanks for the report - can you try setting the client's response time out as well and see if it changes? The default client response time out is 15s I believe - not 10s but maybe it's what you are seeing? If setting the flag doesn't change anything will look more.

[minwoox]

@anuraaga client response timeout has been changed when #701 merged which is pretty recent. Armeria 0.52.0 has 10s for the default response time out. :-)

[sunning9001]

thanks @anuraaga @minwoox . now I know the reason. I set responseTimeoutMillis through ClientFactory. but I do not work. it also bulid options from default. I think it's bug.

a. ) I set client response timeout througth ClientFactory.

ClientFactory factory= new ClientFactoryBuilder().idleTimeout( Duration.ofSeconds(50)).build();

            ClientBuilder builder = new ClientBuilder("gproto+http://127.0.0.1:8080/")
                    .decorator(HttpRequest.class, HttpResponse.class, LoggingClient.newDecorator()).factory(**factory**);

b.) I build HelloServiceFutureStub througth build(Class clientType) API.

the build(Class clientType) API code below.

public T build(Class clientType) {
requireNonNull(clientType, "clientType");
return factory.newClient(uri, clientType, buildOptions());
}

the actual Options is from buildOptions() method, not from the ClientFactory.

c.) set DefaultClientBuilderParams from options. and then set ClientRequestContext from DefaultClientBuilderParams

in GrpcClientFactory.newClient(URI uri, Class clientType, ClientOptions options) method body.

ArmeriaChannel channel = new ArmeriaChannel(
            new DefaultClientBuilderParams(this, uri, clientType, options),
            httpClient,
            scheme.sessionProtocol(),
            newEndpoint(uri),
            serializationFormat,
            jsonMarshaller);


private ClientRequestContext newContext(HttpMethod method, HttpRequest req) {
    final ReleasableHolder<EventLoop> eventLoop = factory().acquireEventLoop(endpoint);
    final ClientRequestContext ctx = new DefaultClientRequestContext(
            eventLoop.get(),
            sessionProtocol,
            endpoint,
            method,
            uri().getRawPath(),
            uri().getRawQuery(),
            null,
            options(),
            req);
    ctx.log().addListener(log -> eventLoop.release(), RequestLogAvailability.COMPLETE);
    return ctx;
}

d.) here , ClientRequestContext responseTimeoutMillis is 10s.

@Override
public boolean invoke(ClientRequestContext ctx, HttpRequest req, DecodedHttpResponse res) {
    if (!res.isOpen()) {
        // The response has been closed even before its request is sent.
        req.abort();
        return true;
    }
    final long writeTimeoutMillis = ctx.writeTimeoutMillis();
    **final long responseTimeoutMillis = ctx.responseTimeoutMillis();**
    final long maxContentLength = ctx.maxResponseLength();

    final int numRequestsSent = ++this.numRequestsSent;
    final HttpResponseWrapper wrappedRes =
            responseDecoder.addResponse(numRequestsSent, req, res, ctx.logBuilder(),
                                        responseTimeoutMillis, maxContentLength);
    req.subscribe(
            new HttpRequestSubscriber(channel, requestEncoder,
                                      numRequestsSent, req, wrappedRes, ctx,
                                      writeTimeoutMillis),
            channel.eventLoop());

    if (numRequestsSent >= MAX_NUM_REQUESTS_SENT) {
        responseDecoder.disconnectWhenFinished();
        return false;
    } else {
        return true;
    }
}

[minwoox]

@sunning9001 That's not a bug.
You mentioned two timeouts which are responseTimeout and idleTimeout.
responseTimeout occurs after you send "a request" and there's no response.
On the other hand, idleTimeout is triggered when neither read nor write was performed for the specified period of time.
For more information about idleTimeout, please check out IdleStateHandler class in netty.

There's two way configuring parameters when you create a client: ClientFactoryBuilder and ClientOptions.
ClientFactoryBuilder is used to configure parameter for lower level like socket options, eventLoops, etc. Whereas, you are able to set the parameters more higher level with ClientOptions.
Since it's confusing you, I believe, you were not the only one confused, but everyone who is not familiar with this API does. I will find a way to figure out to give some more clarification.

[sunning9001]

@minwoox thank you reminding me. what you had said reminds to read the api docs detailly.
I focus too much on the ClientFactoryBuilder class.

now ,I set defaultResponseTimeout on the ClientBuilder. it works.

yes, I am not familiar with armeria api docs. but I am lee 's fan. I try to use armeria in my project .

[minwoox]

Glad to hear that you are using Armeria for your project. I'm a Lee's fan too :-). Please feel free to let us know if you have more issuses.

[sunning9001]

@minwoox thanks for your help.

[trustin]

Thanks everyone. Looking forward to your feed back on your experience with Armeria so far, @sunning9001 :-)

[perlun]

For reference, I added some notes about how to override the client timeouts in #1613.