Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix #6227 Async timeout dispatch race #6228

Merged
merged 2 commits into from May 4, 2021

Conversation

gregw
Copy link
Contributor

@gregw gregw commented Apr 30, 2021

Fix #6227 Only allow the thread calling onTimeout to call dispatch and complete once timeout has expired.

Signed-off-by: Greg Wilkins gregw@webtide.com

Only allow the thread calling onTimeout to call dispatch and complete once timeout has expired.

Signed-off-by: Greg Wilkins <gregw@webtide.com>
@gregw gregw requested a review from sbordet April 30, 2021 05:16
@gregw
Copy link
Contributor Author

gregw commented Apr 30, 2021

@sbordet @joakime any idea how to write a unit test for this? Can we try this branch in the wild with the known reproduction?

Copy link
Contributor

@sbordet sbordet left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The change looks right.

However, I think that in sendError() there should be checks similar to what has been added to dispatch() and complete().
I think these are the only 3 methods that can be called from an async listener, right?

@joakime
Copy link
Contributor

joakime commented Apr 30, 2021

Do we want to fix the QoSFilter to set AsyncContext.setTimeout(0) if the suspendMs is set to 0? (or negative)
Not allowing the default AsyncContext timeout in those scenarios?

@joakime
Copy link
Contributor

joakime commented Apr 30, 2021

See issue #6227 for link to reproduction projects.

I was able to test this branch, and the onTimeout WARNings are no longer happening.
However, the finally block in QoSFilter.doFilter is still triggering a WARN ...

16:56:33.207 [server-95] WARN  org.eclipse.jetty.servlets.QoSFilter - 
java.lang.IllegalStateException: s=HANDLING rs=EXPIRING os=OPEN is=IDLE awp=false se=false i=false al=1
	at org.eclipse.jetty.server.HttpChannelState.dispatch(HttpChannelState.java:589)
	at org.eclipse.jetty.server.AsyncContextState.dispatch(AsyncContextState.java:94)
	at org.eclipse.jetty.servlets.QoSFilter.doFilter(QoSFilter.java:233)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:548)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1435)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1350)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at org.eclipse.jetty.server.Server.handle(Server.java:516)
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:383)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:882)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036)
	at java.base/java.lang.Thread.run(Thread.java:834)

Is this one we can squelch too?

@gregw
Copy link
Contributor Author

gregw commented Apr 30, 2021

I'm not so sure about sendError needing the same logic. It is somewhat more like an output method like getOutputStream().write(....) which we will not check against a timeout state.
I think we should keep the logic in the async lifecycle state machine: startAsync->timeout|dispatch|complete. A write or a sendError can happen anywhere in that cycle.

More over, this change gives precedence to a onTimeout listener that may call sendError over an above a race with the application calling dispatch which may result in other writes etc. So I think the case is covered.

squelch exception

Signed-off-by: Greg Wilkins <gregw@webtide.com>
@gregw
Copy link
Contributor Author

gregw commented Apr 30, 2021

@joakime squelched

@gregw gregw marked this pull request as ready for review April 30, 2021 22:22
@gregw gregw requested a review from sbordet April 30, 2021 22:22
@gregw
Copy link
Contributor Author

gregw commented May 3, 2021

I think we should go ahead with this, even though there is a spec conversation underway.
@sbordet @joakime if you are OK with that, I'll merge later today and prepare a PR for 10

@gregw gregw merged commit ad6d23f into jetty-9.4.x May 4, 2021
gregw added a commit that referenced this pull request May 4, 2021
Fix #6227 Async timeout dispatch race
Only allow the thread calling onTimeout to call dispatch and complete once timeout has expired.
Signed-off-by: Greg Wilkins <gregw@webtide.com>
@gregw gregw deleted the jetty-9.4.x-6227-async-timeout-race branch May 4, 2021 04:42
gregw added a commit that referenced this pull request May 5, 2021
Fix #6227 Async timeout dispatch race
Only allow the thread calling onTimeout to call dispatch and complete once timeout has expired.
Signed-off-by: Greg Wilkins <gregw@webtide.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Better resolve race between AsyncListener.onTimeout and AsyncContext.dispatch
3 participants