Return a CompletableFuture from API methods that checks whether… #2275

anuraaga · 2019-11-20T08:37:17Z

… blocking methods are called from an event loop or a non-blocking thread.

We have heard many stories of bad experiences because of blocking the event loop in an armeria server request. While we wouldn't be able to check all cases of this (e.g., calling JDBC from an event loop), it's fairly simple to check this for futures returned by Armeria methods and I think this covers a lot of cases. This changes to return a special implementation of CompletableFuture that logs from blocking methods with a stack trace.

Let me know any general feedback and then I'll apply to other methods (though I guess aggregate() is the most common way to get a future from Armeria).

codecov · 2019-11-20T08:58:19Z

Codecov Report

Merging #2275 into master will decrease coverage by 0.01%.
The diff coverage is 94.11%.

@@             Coverage Diff              @@
##             master    #2275      +/-   ##
============================================
- Coverage     73.67%   73.65%   -0.02%     
- Complexity    10168    10172       +4     
============================================
  Files           882      883       +1     
  Lines         38869    38891      +22     
  Branches       4813     4815       +2     
============================================
+ Hits          28637    28646       +9     
- Misses         7777     7790      +13     
  Partials       2455     2455

Impacted Files	Coverage Δ	Complexity Δ
...c/main/java/com/linecorp/armeria/common/Flags.java	`62.18% <100%> (+0.48%)`	`57 <1> (+1)`	⬆️
.../armeria/client/endpoint/DynamicEndpointGroup.java	`91.66% <100%> (ø)`	`18 <0> (ø)`	⬇️
...common/stream/AbstractStreamMessageDuplicator.java	`78.43% <100%> (ø)`	`11 <0> (ø)`	⬇️
...inecorp/armeria/server/file/StreamingHttpFile.java	`53.04% <100%> (ø)`	`14 <0> (ø)`	⬇️
.../java/com/linecorp/armeria/common/HttpRequest.java	`73.73% <100%> (ø)`	`26 <1> (ø)`	⬇️
...java/com/linecorp/armeria/common/HttpResponse.java	`88.77% <100%> (ø)`	`34 <2> (ø)`	⬇️
...rp/armeria/common/stream/StreamMessageDrainer.java	`78.26% <100%> (ø)`	`7 <1> (ø)`	⬇️
...dpoint/healthcheck/HealthCheckedEndpointGroup.java	`78.43% <100%> (ø)`	`14 <0> (ø)`	⬇️
...p/armeria/common/stream/AbstractStreamMessage.java	`83.84% <100%> (ø)`	`26 <0> (ø)`	⬇️
...ria/common/stream/PublisherBasedStreamMessage.java	`81.75% <100%> (ø)`	`24 <1> (ø)`	⬇️
... and 20 more

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 4c3dfa0...42f067e. Read the comment docs.

trustin · 2019-11-25T07:57:30Z

Maybe a user can just use BlockHound? https://github.com/reactor/BlockHound
Netty integration is coming soon: netty/netty#9687

anuraaga · 2019-11-25T08:12:39Z

BlockHound seems cool and could be a best practice when running an Armeria app to catch other things like JDBC. But I think registering an agent is tedious enough that it could still be worth having something out of the box. The cost / performance of manually instrumenting these three common methods seems pretty good to me. What do you think?

anuraaga · 2019-12-02T05:35:50Z

@trustin Any more thoughts on this? I notice there could be JDK version issues in the future with BlockHound - reactor/BlockHound#33. It's a very cool tool, but agents are so complex I think this is could be a small but effective improvement.

trustin · 2019-12-02T07:06:13Z

Sorry. Let me check soon. Didn't have a chance to check the code yet.

trustin

Looks good all in all.

core/src/main/java/com/linecorp/armeria/common/Flags.java

...rc/main/java/com/linecorp/armeria/internal/eventloop/EventLoopCheckingCompletableFuture.java

core/src/main/java/com/linecorp/armeria/internal/eventloop/EventLoopThread.java

...est/java/com/linecorp/armeria/internal/eventloop/EventLoopCheckingCompletableFutureTest.java

…ing methods are called from an event loop.

anuraaga · 2019-12-07T09:19:36Z

I have switched to EventLoopCheckingCompletableFuture where we return a future to users. Though it might be simpler to just use it everywhere, let me know.

core/src/main/java/com/linecorp/armeria/common/Flags.java

anuraaga · 2019-12-10T05:38:34Z

Hmm test doesn't seem to work well on Windows. Happen to have any ideas why that could be?

trustin · 2019-12-10T06:40:20Z

Maybe REPORTED_THREADS.add() returned false? How about using a different event loop for each test method?

anuraaga · 2019-12-10T06:41:54Z

Doh duh... thanks for finding it!

trustin · 2019-12-10T06:42:32Z

maybeLogIfOnEventLoop could be static by the way :-)

trustin

Thanks!

minwoox

This looks nice. Thanks!

ikhoon

I have left a humble opinion but mostly LGTM. Thanks a lot!

ikhoon · 2019-12-11T06:03:17Z

...rc/main/java/com/linecorp/armeria/internal/eventloop/EventLoopCheckingCompletableFuture.java

+            return;
+        }
+        final Thread thread = Thread.currentThread();
+        if (thread instanceof NonBlocking && REPORTED_THREADS.add(thread)) {


IIUC this NonBlocking interface is created in the project reactor.

https://github.com/reactor/reactor-core/blob/628258f644bdddd095e72d1fc81c5d6ac0e3fa12/reactor-core/src/main/java/reactor/core/scheduler/ReactorThreadFactory.java#L92-L96

It seems an edge case but a non-eventloop thread might pass this condition and log this message. I am wondering if it is acceptable. Unless I suggest changing EventLoopCheckingCompletableFuture to NonBlockCheckingCompletableFuture and related message. 😀

Armeria EventLoopThread implements Nonblocking. 😄

I originally checked instanceof EventLoopThread but changed to NonBlocking I think to avoid moving a package-local EventLoopThread to public in internal package. @trustin Any thoughts? I lean towards it being small enough not to worry about

I know that :-) Just worried other non-event loop thread could implement NonBlocking.
But it seems too many worries. 😜

I think we can warn that as well because a thread which implements NonBlocking is doing blocking operation. 😄

Ah then it makes sense. 😄

So do we need to update the WARN log message?

I'm not completely sure it is worth to update the message.
If we do, then leave the original sentence and put extra information just in case. 😀

- Calling a blocking method on CompletableFuture from an event loop thread. + Calling a blocking method on CompletableFuture from an event loop thread or non-blocking thread.

@anuraaga Could you update the log message?

…ecking-future

…e#2275) … blocking methods are called from an event loop or a non-blocking thread. We have heard many stories of bad experiences because of blocking the event loop in an armeria server request. While we wouldn't be able to check all cases of this (e.g., calling JDBC from an event loop), it's fairly simple to check this for futures returned by Armeria methods and I think this covers a lot of cases. This changes to return a special implementation of `CompletableFuture` that logs from blocking methods with a stack trace.

trustin added the new feature label Dec 3, 2019

trustin reviewed Dec 3, 2019

View reviewed changes

Return a CompletableFuture from API methods that checks whether block…

aca8796

…ing methods are called from an event loop.

anuraaga force-pushed the checking-future branch from 1120dc7 to aca8796 Compare December 7, 2019 09:18

anuraaga marked this pull request as ready for review December 7, 2019 09:18

anuraaga requested review from ikhoon and minwoox as code owners December 7, 2019 09:18

Await for slower CIs

e754cb5

trustin reviewed Dec 10, 2019

View reviewed changes

core/src/main/java/com/linecorp/armeria/common/Flags.java Outdated Show resolved Hide resolved

core/src/main/java/com/linecorp/armeria/common/Flags.java Outdated Show resolved Hide resolved

Cleanup

1ba6243

Static and event loop per test

610e85f

trustin approved these changes Dec 11, 2019

View reviewed changes

trustin added this to the 0.98.0 milestone Dec 11, 2019

Merge branch 'master' into checking-future

c200807

minwoox approved these changes Dec 11, 2019

View reviewed changes

ikhoon approved these changes Dec 11, 2019

View reviewed changes

anuraaga added 2 commits December 11, 2019 16:49

Update log

c3453a3

Merge branch 'checking-future' of github.com:anuraaga/armeria into ch…

42f067e

…ecking-future

trustin changed the title ~~Return a CompletableFuture from API methods that checks whether block…~~ Return a CompletableFuture from API methods that checks whether… Dec 11, 2019

trustin merged commit 3b52ab6 into line:master Dec 11, 2019

ikhoon mentioned this pull request Jan 16, 2020

Schedulers.isInNonBlockingThread() should return true on EventLoop #2404

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Return a CompletableFuture from API methods that checks whether… #2275

Return a CompletableFuture from API methods that checks whether… #2275

anuraaga commented Nov 20, 2019 •

edited by trustin

Loading

codecov bot commented Nov 20, 2019 •

edited

Loading

trustin commented Nov 25, 2019

anuraaga commented Nov 25, 2019

anuraaga commented Dec 2, 2019

trustin commented Dec 2, 2019

trustin left a comment

anuraaga commented Dec 7, 2019

anuraaga commented Dec 10, 2019

trustin commented Dec 10, 2019

anuraaga commented Dec 10, 2019

trustin commented Dec 10, 2019

trustin left a comment

minwoox left a comment

ikhoon left a comment

ikhoon Dec 11, 2019

minwoox Dec 11, 2019

anuraaga Dec 11, 2019

ikhoon Dec 11, 2019

minwoox Dec 11, 2019

minwoox Dec 11, 2019

trustin Dec 11, 2019

ikhoon Dec 11, 2019

trustin Dec 11, 2019

anuraaga Dec 11, 2019

Return a CompletableFuture from API methods that checks whether… #2275

Return a CompletableFuture from API methods that checks whether… #2275

Conversation

anuraaga commented Nov 20, 2019 • edited by trustin Loading

codecov bot commented Nov 20, 2019 • edited Loading

Codecov Report

trustin commented Nov 25, 2019

anuraaga commented Nov 25, 2019

anuraaga commented Dec 2, 2019

trustin commented Dec 2, 2019

trustin left a comment

Choose a reason for hiding this comment

anuraaga commented Dec 7, 2019

anuraaga commented Dec 10, 2019

trustin commented Dec 10, 2019

anuraaga commented Dec 10, 2019

trustin commented Dec 10, 2019

trustin left a comment

Choose a reason for hiding this comment

minwoox left a comment

Choose a reason for hiding this comment

ikhoon left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

anuraaga commented Nov 20, 2019 •

edited by trustin

Loading

codecov bot commented Nov 20, 2019 •

edited

Loading