Log at error level when the kafka spout gives up on a tuple; document max-retry give-up semantics - #9093
Log at error level when the kafka spout gives up on a tuple; document max-retry give-up semantics#9093L1nq0 wants to merge 2 commits into
Conversation
… max-retry give-up semantics
|
The level change itself is fine. A few points before it goes in. The message text is hardcoded to "Reached maximum number of retries", but the contract of
A custom retry service that declines a message for some other reason now emits an ERROR stating the wrong reason. That was tolerable at debug level, at error level it is not. Please reword so it holds for any implementation, e.g. "The retry service will not retry message [{}]: the tuple will be acked and ...". Second, this logs once per given-up tuple. With the default Third, the javadoc you added to Minor: |
…x-retry ack ordering KafkaSpoutRetryService#schedule may decline a message for reasons other than reaching the retry limit, so the give-up log no longer names the reason. KafkaSpoutRetryLimitTest now verifies that onMaxRetryReached runs before the tuple is acked, matching the documented contract.
|
@rzo1 Thanks for the review. Commit 971c768 addresses the points. On the message text: agreed, the schedule contract is broader than the retry limit, so the log no longer names a reason. It now reads: On rate limiting: I considered it and agree a plain ERROR is right here. With the default maxRetries the branch never runs, and a finite limit means the user opted into the loss. Each line also corresponds to a distinct lost record, which is exactly what an operator needs to see when records are being given up on; users who need suppression have the onMaxRetryReached hook and their logging configuration. On the ordering: testFailingTupleCompletesAckAfterRetryLimitIsMet now installs a listener mock and verifies with InOrder, for each given-up tuple, that onMaxRetryReached runs before the tuple is acked. The spout reports the ack through the listener's onAck, so the pair pins the documented contract. I left the debug line in KafkaSpoutRetryExponentialBackoff#schedule as is, per your note. |
2 participants
What this changes
When a tuple emitted by the kafka spout reaches the retry limit, KafkaSpout.fail() acked it and logged the event at debug level. The event is now logged at error level and states the consequence:
The message id carries the topic, partition and offset, so the log line identifies the record.
The same semantics are documented at the two places a user configures or reacts to them. The KafkaSpoutRetryExponentialBackoff constructor javadoc now states that a finite maxRetries also stops endless retries of tuples that fail every time they are emitted, e.g. tuples the receiving worker drops because they cannot be deserialized, and that such tuples are reported to KafkaTupleListener.onMaxRetryReached. The onMaxRetryReached javadoc now states that the tuple is acked right after the callback, that commits can then move past its offset, and that the callback is the last point at which the record can be retained, with the msgId identifying the record by topic, partition and offset.
Motivation
Issue #9078: with the default retry service, a record whose tuples always fail keeps the spout from committing any offset past it, and the only signal that the retry limit was reached was a debug-level line that most deployments never see. Raising the give-up event to error level makes the give-up visible to operators exactly where the guarantee is lost.
Scope
The retry mechanism, the ack and commit behavior and onMaxRetryReached itself are unchanged. Questions on how give-up records should be retained by default, e.g. dead letter handling or a listener capture example in the docs, are left open in the issue. The storm-kafka-client test suite passes with no changes (107/107); no existing test asserts the old log wording.
Relates to #9078