implement request timeout annotation

[mscheong01]

Motivation:

Provide a way to set a request timeout using annotation

Modifications:

• Add @interface RequestTimeout
• Add RequestTimeoutDecoratorFunction

Result:

• Closes Provide a way to set a request timeout using annotation #4463
• users can use RequestTimeout annotation to set request timeout to service methods

[mscheong01]

❔ Some questions along the way:
(tests are to come)

[CLAassistant]

All committers have signed the CLA.

[mscheong01]

Sorry for the late update 😅 🙏
I've made fixes based on the comments and added a test.
However, setRequestTimeout with TimeoutMode.SET_FROM_START doesn't seem to work as expected

private void setTimeoutNanosFromStart(long timeoutNanos) {
    checkArgument(timeoutNanos >= 0, "timeoutNanos: %s (expected: >= 0)", timeoutNanos);
    if (timeoutNanos == 0) {
        clearTimeout();
        return;
    }
    if (isInitialized()) {
        if (eventLoop.inEventLoop()) {
            setTimeoutNanosFromStart0(timeoutNanos);
        } else {
            eventLoop.execute(() -> setTimeoutNanosFromStart0(timeoutNanos));
        }
    } else {
        addPendingTimeoutNanos(timeoutNanos);
        addPendingTask(() -> setTimeoutNanosFromStart0(timeoutNanos));
    }
}

CancellationScheduler$setTimeoutNanosFromStart seems to do a saturated add with the default request timeout in addPendingTimeoutNanos(timeoutNanos); which results in the timeout being + 10000 (millisec) ed when annotating with @RequestTimeout 🤔

[ikhoon]

I forget noting grpc-timeout header which clears or appends the original timeout value.

armeria/grpc/src/main/java/com/linecorp/armeria/server/grpc/FramedGrpcService.java

Lines 228 to 246 in 49054ad

	if (useClientTimeoutHeader) {
	final String timeoutHeader = req.headers().get(GrpcHeaderNames.GRPC_TIMEOUT);
	if (timeoutHeader != null) {
	try {
	final long timeout = TimeoutHeaderUtil.fromHeaderValue(timeoutHeader);
	if (timeout == 0) {
	ctx.clearRequestTimeout();
	} else {
	ctx.setRequestTimeout(TimeoutMode.SET_FROM_NOW, Duration.ofNanos(timeout));
	}
	} catch (IllegalArgumentException e) {
	final Metadata metadata = new Metadata();
	return HttpResponse.of(
	(ResponseHeaders) AbstractServerCall.statusToTrailers(
	ctx, defaultHeaders.get(serializationFormat).toBuilder(),
	GrpcStatus.fromThrowable(statusFunction, ctx, e, metadata), metadata));
	}
	}
	}

It would not make sense if the timeout is updated by the client header after @RequestTimeout is applied. Should we avoid taking the grpc-timeout header when @RequestTimeout is run? It is a bit tricky to know whether @RequestTimeout is applied though.
We may need a specialized logic only for gRPC that uses reflection to know if @RequestTimeout is annotated to a gRPC stub method.

[ikhoon]

CancellationScheduler$setTimeoutNanosFromStart seems to do a saturated add with the default request timeout in addPendingTimeoutNanos(timeoutNanos);

It sounds like a bug. We should use setPendingTimeoutNanos(timeoutNanos) instead.

which results in the timeout being + 10000 (millisec) ed when annotating with @.RequestTimeout 🤔

In fact, pendingTimeoutNanos is a temporary value to return a scheduled timeout before a request or response is being subscribed. IIRC, the value stored in pendingTimeoutNanos field is discarded and addPendingTask(() -> setTimeoutNanosFromStart0(timeoutNanos)) actually affects the final timeout. So could you possibly double check if it really causes an unexpected result?

[codecov]

Codecov Report

Base: 74.08% // Head: 74.07% // Decreases project coverage by -0.00% ⚠️

Coverage data is based on head (9979739) compared to base (c34c6b5).
Patch coverage: 100.00% of modified lines in pull request are covered.

❗ Current head 9979739 differs from pull request most recent head 5f0f0e9. Consider uploading reports for the commit 5f0f0e9 to get more accurate results

Additional details and impacted files

@@             Coverage Diff              @@
##             master    #4499      +/-   ##
============================================
- Coverage     74.08%   74.07%   -0.01%     
+ Complexity    18185    18183       -2     
============================================
  Files          1537     1538       +1     
  Lines         67469    67475       +6     
  Branches       8537     8537              
============================================
- Hits          49987    49985       -2     
+ Misses        13419    13414       -5     
- Partials       4063     4076      +13     

Impacted Files	Coverage Δ
...ria/internal/common/BuiltInDependencyInjector.java	50.00% <ø> (ø)
...armeria/internal/common/CancellationScheduler.java	77.29% <100.00%> (ø)
...ion/decorator/RequestTimeoutDecoratorFunction.java	100.00% <100.00%> (ø)
...ria/internal/client/dns/DelegatingDnsResolver.java	81.25% <0.00%> (-18.75%)	⬇️
...armeria/internal/common/stream/SubscriberUtil.java	72.22% <0.00%> (-11.12%)	⬇️
...rmeria/internal/client/dns/CachingDnsResolver.java	78.37% <0.00%> (-8.11%)	⬇️
...a/internal/client/dns/SearchDomainDnsResolver.java	87.14% <0.00%> (-5.72%)	⬇️
...rp/armeria/common/stream/DefaultStreamMessage.java	87.36% <0.00%> (-3.16%)	⬇️
...inecorp/armeria/server/file/StreamingHttpFile.java	54.78% <0.00%> (-2.61%)	⬇️
...rmeria/common/stream/ConcatArrayStreamMessage.java	83.14% <0.00%> (-2.25%)	⬇️
... and 13 more

Help us with your feedback. Take ten seconds to tell us how you rate us. Have a feature suggestion? Share it here.

☔ View full report at Codecov.
📢 Do you have feedback about the report comment? Let us know in this issue.

[mscheong01]

I've looked in to more of armeria's requestTimeout implementation, and confirmed that service.serve() before requestCancellationScheduler.init() is called. scheduler initialization occurs on AggregatedHttpResponseHandler construction, which happens at the end of HttpServerHandler$handleRequest.
This is why when ServiceRequestContext$requestTimeoutMillis() is called inside the service, there is a possibility that the pendingTimeout of ServiceRequestContext is returned (because armeria uses hot datasources).
I've added three commits:

1. fix the bug where wrong pending timeout is set (656a866) -> this fixes the previously failing testRequestTimeoutSet
2. variable name change suggestion: because they shadow the class variable, and seems to cause confusuion (9979739)
3. additional test for the CancellationScheduler initialization issue which fails with current implementation (53ed701)

[mscheong01]

It would not make sense if the timeout is updated by the client header after @RequestTimeout is applied. Should we avoid taking the grpc-timeout header when @RequestTimeout is run? It is a bit tricky to know whether @RequestTimeout is applied though.
We may need a specialized logic only for gRPC that uses reflection to know if @RequestTimeout is annotated to a gRPC stub method.

as for this issue, it seems somehow wrong that the client could override the request timeout causing the call to last longer than the time set on the server-side, not just for @RequestTimeout, but for any timeout set by the server.
How about making request timeout change by grpc-timeout header only possible if the given timout value of the header is shorter than the requestTimeout set to the current context?

[minwoox]

https://github.com/line/armeria/actions/runs/3525487381/jobs/5912289404#step:7:1181
Oops, it seems like we have a failing test. 😆

[mscheong01]

additional test for the CancellationScheduler initialization issue which fails with current implementation (53ed701)

@minwoox You're right, it's a testcase to show that there's an issue with the current request timeout implementation. How would you suggest to fix it?

in HttpServerHandler$handleRequest service.serve() is called before requestCancellationScheduler.init()

this seems to be the cause of the issue

[minwoox]

it's a testcase to show that there's an issue with the current request timeout implementation.

Do you mean testCancellationSchedulerInit() test?
Could you explain more about the test?
I think I don't get the purpose of the test. 😓
The response.contentUtf8() is 1230 and you want to convert it to a Boolean value?

How about making request timeout change by grpc-timeout header only possible if the given timout value of the header is shorter than the requestTimeout set to the current context?

That is fair enough. 👍

[mscheong01]

@minwoox
Oops, I fixed the testcase as intended: prove that RequestCancellationScheduler is not initialized when service code is run

[minwoox]

prove that RequestCancellationScheduler is not initialized when service code is run

Thanks! Now I got it. 😄
I don't exactly remember the reason, but calling init() method later was what we intended so that the HttpResponse from the service layer is correctly cancelled with the timeout.
Do you have any reason you want to change the current behavior?

[ikhoon]

How about making request timeout change by grpc-timeout header only possible

It makes sense. The contract of useClientTimeoutHeader() already mentioned that request timeout is only respected when useClientTimeoutHeader() is set to false. I was wondering why this option is an opt-out though. It would be worth noting in the Javadoc of @RequestTimeout that if the annotation is used for gRPC services, the timeout value is only valid when useClientTimeoutHeader is disabled.

armeria/grpc/src/main/java/com/linecorp/armeria/server/grpc/GrpcServiceBuilder.java

Lines 789 to 796 in c888c86

	* Sets whether to use a {@code grpc-timeout} header sent by the client to control the timeout for request
	* processing. If disabled, the request timeout will be the one configured for the Armeria server, e.g.,
	* using {@link ServerBuilder#requestTimeout(Duration)}.
	*
	* <p>It is recommended to disable this when clients are not trusted code, e.g., for gRPC-Web clients that
	* can come from arbitrary browsers.
	*/
	public GrpcServiceBuilder useClientTimeoutHeader(boolean useClientTimeoutHeader) {

if the given timout value of the header is shorter than the requestTimeout set to the current context?

For simplicity, I prefer to apply either grpc-timeout or @RequestTimeout. So I don't think it is a good idea to select a shorter value between grpc-timeout and @RequestTimeout.

[mscheong01]

@minwoox

Thanks! Now I got it. 😄
I don't exactly remember the reason, but calling init() method later was what we intended so that the HttpResponse from the service layer is correctly cancelled with the timeout.
Do you have any reason you want to change the current behavior?

Ah, I see. I though't that if the servicecode is run before timeout is initialized, the actual timeout applied could be longer than desired. But if that was intended, we could ignore it. I'll remove the failing testcase
@ikhoon

For simplicity, I prefer to apply either grpc-timeout or @RequestTimeout. So I don't think it is a good idea to select a shorter value between grpc-timeout and @RequestTimeout.

I'll revert changes in 71aeac2 and add the additional documentation to @RequestTimeout thanks!

[minwoox]

I completely forgot that we have useClientTimeoutHeader. 😄

But if that was intended, we could ignore it. I'll remove the failing testcase

Yes, it was. 😄 Thanks!

[ikhoon]

Thanks, @j-min5u! 💯❤️

[minwoox]

👍 👍 👍

[minwoox]

Thaaaaanks again. 😄