[CONSVC-2052] feat: add timeout handling for query tasks

[ncloudioj]

This adds a query handling timeout for the suggest endpoint. The rationale is that since Firefox uses a timeout (currently 200ms) for each query request to Merino, Merino should do the same to ensure slow providers would not prevent Merino from serving suggestions from other providers. When timeout occurs, Merino will cancel all ongoing query tasks and log/record metrics accordingly.

Note that:

• this works at the request-level rather than the provider-level, meaning that once the timeout gets triggered, all the unfinished query tasks will be cancelled and optionally processed by the timeout callback. It does what Merino needs for now. We can extend this to be provider-evel timeout if needed in the future.
• asyncio.gather() also supports timeout, but it doesn't provide fine-grained control on timeout handling. Therefore, I ended up using the asyncio wait primitives. The benchmark shows that the overhead is negligible compared to asyncio.gather()

This fixes CONSVC-2052.

[quiiver]

meaning that once the timeout gets triggered, all the unfinished query tasks will be cancelled and optionally processed by the timeout callback. It does what Merino needs for now. We can extend this to be provider-evel timeout if needed in the future.

I haven't read the code yet but does this mean that completed providers will be returned in the response?

[ncloudioj]

I haven't read the code yet but does this mean that completed providers will be returned in the response?

Correct.

[quiiver]

So technically we are cancelling this task when we cancel the pending tasks upon timeout. does task cancellation propagate?

[ncloudioj]

When the wait timeout occurs, we're cancelling all the pending tasks (one per each provider) one-by-one here. So there will no cancellation propagation involved here.

[quiiver]

Ok makes sense, I have another couple questions.

1. the aiodogstatsd library uses a done_callback to record the timing of the underyling coroutine. does the done callback get called when a task is cancelled?
2. according to the Task docs calling Task.cancel should throw a CancelledError exception but i'm not seeing any exception catching. Whats going on there?

[ncloudioj]

the aiodogstatsd library uses a done_callback to record the timing of the underyling coroutine. does the done callback get called when a task is cancelled?

Yes, it will be called as usual, meaning that it will time a cancelled task in this case. I thought about clearing the done_callback before it gets cancelled, but then figured we might want to keep it for completeness. I am open to other options, too.

according to the Task docs calling Task.cancel should throw a CancelledError exception but i'm not seeing any exception catching. Whats going on there?

We only call cancel on those pending tasks, which should be fine and no CancelledError will be raised. Are you concerning about calling cancel but somehow the task is completed at that point? In that case, it might raise I think we can add a check for that.

[quiiver]

Are you concerning about calling cancel but somehow the task is completed at that point?

Not particularly, the docs just make it seem like CancelledErrors are automatically thrown when you call cancel on a Task instance regardless of its completion status.

https://docs.python.org/3.11/library/asyncio-task.html#asyncio.Task.cancel

This arranges for a CancelledError exception to be thrown into the wrapped coroutine on the next cycle of the event loop.

[ncloudioj]

Ah, I see what you mean. I think it will raise a CancelledError if you await it or call task.result() once it gets cancelled, but neither is the case here as it just cancels them and returns them as a separate task list along with the done tasks. If the consumer decides to use them regardless, the yeah CancelledError will be thrown.

Does that make sense?

[quiiver]

Yes thanks 😅

[Trinaa]

@ncloudioj I've merged #106, I apologize for the conflicts this creates. I'll note two things:

1. Please move the tests/unit/test_task_runner.py module to tests/unit/util/test_task_runner.py. Perhaps propagate the util to utils directory name change to the unit test directory.

2. (Optional) The test_with_timedout_provider could be included in the test_suggest.py, since it's a generalized suggest endpoint behaviour.

[ncloudioj]

Please move the tests/unit/test_task_runner.py module to tests/unit/util/test_task_runner.py. Perhaps propagate the util to utils directory name change to the unit test directory.

Yep, sounds good, will do.

The test_with_timedout_provider could be included in the test_suggest.py, since it's a generalized suggest endpoint behaviour.

If you don't strongly disagree, I'd like to keep it in a separate test file as I am almost certain that we will add more related functionalities and test cases in the future, which might mess up those generic tests in test_suggest.py.

[Trinaa]

Things LGTM on the test side.