queue: honour poll timeout between handled internal ops (#5325) - #5538
Open
Tamir Suliman (allamiro) wants to merge 3 commits into
Open
queue: honour poll timeout between handled internal ops (#5325)#5538Tamir Suliman (allamiro) wants to merge 3 commits into
Tamir Suliman (allamiro) wants to merge 3 commits into
Conversation
…#5325) rd_kafka_q_pop_serve() only evaluated the timeout once the queue was found empty. After handling an internal op (RD_KAFKA_OP_RES_HANDLED or RD_KAFKA_OP_RES_KEEP, e.g. a log op) it jumped straight back to the `retry` label without re-checking the timeout. If internal ops are enqueued faster than the application thread drains them - for instance high-volume log ops with log.queue=true and debug logging enabled - the queue never empties, the timeout path is never reached, and poll()/consumer_poll() can block far longer than the requested timeout, up to indefinitely. A poll(0) intended to be non-blocking was observed blocking for over two hours in production. Re-check the timeout after each handled op so control is always returned to the application once the timeout has expired, while still guaranteeing forward progress of at least one op per call. Adds a deterministic regression unit test (q_pop_serve_starvation) that feeds the queue continuously during a NOWAIT poll and asserts the poll returns after a single handled op.
|
🎉 All Contributor License Agreements have been signed. Ready to merge. |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Fixes #5325.
Problem
rd_kafka_poll(0)/rd_kafka_consumer_poll(0)(and other queue poll variants) can block far longer than the requested timeout — up to indefinitely — when internal ops are enqueued faster than the application thread drains them. The reported trigger isdebug=all+log.queue=true(which routes log messages asRD_KAFKA_OP_LOGonto the polled queue), where broker threads flood the queue with log ops. The issue reporter observedconsumer_poll(0)blocking for over 2 hours in production.Root cause
In
rd_kafka_q_pop_serve0()the timeout is only evaluated once the queue is found empty (at thecnd_timedwait_abs()path). After handling an internal op (RD_KAFKA_OP_RES_HANDLED/RD_KAFKA_OP_RES_KEEP, e.g. a log op) the loop doesgoto retrywithout re-checking the timeout. If internal ops keep arriving the queue never empties, so the timeout path is never reached and the call is starved.Fix
Re-check the timeout after each handled op, before jumping back to
retry. At least one op is always handled per call, so forward progress is guaranteed, while control is returned to the application once the timeout has expired.This matches the fix proposed and verified in the issue, with one addition: the early return also calls
rd_kafka_app_polled()when the queue can contain fetched messages, consistent with every other return path afterrd_kafka_app_poll_start(). Omitting it (as in the issue snippet) would leave themax.poll.interval.msbookkeeping unbalanced.Behaviour note for reviewers
For an already-expired timeout (i.e.
poll(0)), the call now handles one internal op and returns, rather than draining all currently-queued internal ops in a single call. This is bounded and FIFO-safe (a returnable message behind buffered internal ops surfaces on a subsequent call; it is never lost or reordered), and is the same semantics as the verified fix in the issue. Polls with a non-zero timeout drain until the timeout elapses, as before.Test
Adds a deterministic regression unit test
q_pop_serve_starvation(src/rdkafka_queue.c, registered insrc/rdunittest.c) that continuously feeds the queue during anRD_POLL_NOWAITpoll and asserts the poll honours its timeout (handles exactly one op).make style-check-changedclean (clang-format 18).A
CHANGELOG.mdentry is included under Fixes.