Timeout not honored

[drcrallen]

Currently If I specify a timeout query context when querying a broker, that timeout is not honored. It is entirely possible to set a timeout of 90s and have the broker hog resources for the query for 15m while it tries to complete the request.

The expected behavior is that the broker terminates the returning data stream once timeout has expired, and also that it cancels any outstanding query efforts on the historicals related to the query.

The current state of timeouts seems to be enforced on a per-segment basis, and not a per-query basis. Meaning that if historical nodes take an abnormally long time on queries, the overall query can take a very long time compared to the timeout.

This stems from 2 things:

1. Lack of checking in QueryResource for commands taking too long. (see Add basic timeout functionality to QueryResource #1416 )
2. Lack of ability to interrupt streaming results properly.

Part of this comes from the assumption stated in io.druid.query.AsyncQueryRunner::run

            //Note: this is assumed that baseRunner does most of the work eagerly on call to the
            //run() method and resulting sequence accumulate/yield is fast.

because the a lot of the query workload is actually lazily done in yield.

[drcrallen]

query-context.md specifies:

Query timeout in milliseconds, beyond which unfinished queries will be cancelled

[xvrl]

Can we clarify under which conditions and at what level the timeout is not honored?

Can you describe the bug that you are seeing in more detail?

[gianm]

GroupByMergingQueryRunnerV2 has two things that could time out: merge buffer acquisition in the request thread, and processing in the processing threads. It handles that by computing a timeoutAt value (absolute time) and using that to calculate all future timeouts.

I guess we could extend this to the broker, and have timeoutAt be something that gets set very early in query processing and respected throughout the stack.

[himanshug]

copied from #4181

if all historicals (and peon) respond within the query timeout specified and it is broker spending time doing the merge (usually in the case of merging lots of sketches) then timeout wouldn't be honored irrespective of however long broker takes to merge things.

on the client side, clients typically use the same timeout to close the connection... so broker doing all the work is eventually wasted.

i think its most problematic with query types that don't do streaming merge at broker.

one possibly simple (maybe crude) fix is that broker puts query processing startTime in query context and all things taking time to process the query continuously watch the time spent and fail if it exceeds. I'm imagining probably in QueryToolChest.mergeResults(..) impl and may be in the QueryResource where it is streaming the results to response.

another alternative to startTime would be to do query processing in a thread pool and cancel the future on query timeout .... druid code that takes time in processing the query would continuously check if the thread is interrupted.

[himanshug]

@gianm timeoutAt sounds similar to setting the startTime , either sound good to me.
on broker, i believe there are only two places where most of the time is spent ... either in MergeSequence created by CachingClusteredClient or QueryToolChest.mergeResults(..) impls

[vogievetsky]

Looks like #4287 partially addressed this. What else needs to be done?