MINOR: Ensure a reason is logged for all segment deletion operations#9110
Conversation
| // iteration remain valid and deterministic. | ||
| val toDelete = segments.toList | ||
| toDelete.foreach { segment => | ||
| info(s"${reason.reasonString(this, segment)}") |
There was a problem hiding this comment.
If we passed in the deletion reason further into the deleteSegmentFiles method, it seems we can print the reason string just once for a batch of segments being deleted. And within the reason string, we can provide the reason for deleting the batch:
https://github.com/confluentinc/ce-kafka/blob/master/core/src/main/scala/kafka/log/Log.scala#L2519
https://github.com/confluentinc/ce-kafka/blob/master/core/src/main/scala/kafka/log/Log.scala#L2526
ex: info("Deleting segments due to $reason: ${segments.mkString(",")}"
where $reason provides due to retention time 1200000ms breach.
The drawback is that sometimes we can not print segment-specific information since the error message is at a batch level. But generally it may be that segment-level deletion information could bloat our server logging, so it may be better to batch the logging instead.
What are your thoughts?
There was a problem hiding this comment.
While verbose, I think having the granularity of each segment is useful. This allows us to easily reason about why a particular segment was deleted. Note that we switched from a single log per batch to a log per segment in #8850.
There was a problem hiding this comment.
Can we think about cases where this could be an issue? Say delete records is used, causing a large number of segments to be deleted Could that trigger excessive logging?
There was a problem hiding this comment.
@ijuma We log one message per deleted segment. This could cause temporary increase in log volume when DeleteRecords is used or when retention is lowered, for example.
Overall, we have a few options with different tradeoffs:
- Log a common reason per batch being deleted, including base offsets of segments being deleted. eg.
Deleting segments due to retention time 999ms breach. BaseOffsets: (0,5,...).
- Log a common reason per batch being deleted, including base offsets and metadata of segments. eg.
Deleting segments due to retention time 999ms breach: LogSegment(baseOffset=0, size=360, lastModifiedTime=1596387738000, largestRecordTimestamp=Some(1596387737414)),LogSegment(baseOffset=5, size=360, lastModifiedTime=1596387738000, largestRecordTimestamp=Some(1596387737414)),...
- Log one message per segment being deleted. This is the current behavior. eg.
Segment with base offset 0 will be deleted due to retention time 999ms breach based on the largest record timestamp from the segment, which is ...
Segment with base offset 5 will be deleted due to retention time 999ms breach based on the largest record timestamp from the segment, which is ...
...
Doing (2) may be a reasonable tradeoff. It eliminates some of the redundancy at the cost of making it to glean per segment metadata. Let me know what you think.
There was a problem hiding this comment.
I think it is important to capture the segment level details. In the past, we have had trouble explaining precisely why a specific segment got deleted. For example, was it because of the last modified time or the record timestamp? When users are looking to understand why data is deleted, we should be able to provide a clear answer.
My personal preference is probably 3) because I hate dealing with lists of things in log messages. Simple grepping no longer work to extract the details. Big messages also messes up console scrolling and can choke downstream systems. For segments, I am not so worried about log noise because the rate of segment creation is not that high.
There was a problem hiding this comment.
I think this is reasonable. Logging a segment per line will make it easier for us to diagnose issues. I made the change to log a segment per line for retention-related deletions. We still batch all segments in a single line for all other deletion events, eg. log deletion, truncation, etc.
| // iteration remain valid and deterministic. | ||
| val toDelete = segments.toList | ||
| toDelete.foreach { segment => | ||
| info(s"${reason.reasonString(this, segment)}") |
dhruvilshah3
changed the title
|
Thanks for the reviews @kowshik, @hachikuji, @ijuma. I have addressed the comments. Let me know what you think. |
|
ok to test |
|
retest this please |
1 similar comment
|
retest this please |
| // removing the deleted segment, we should force materialization of the iterator here, so that results of the | ||
| // iteration remain valid and deterministic. | ||
| val toDelete = segments.toList | ||
| info(s"${reason.logReason(this, toDelete)}") |
There was a problem hiding this comment.
Don't we need to get rid of the call to info here?
There was a problem hiding this comment.
Thanks for catching. I fixed this.
|
retest this please |
3 similar comments
|
retest this please |
|
retest this please |
|
retest this please |
hachikuji
left a comment
hachikuji
left a comment
There was a problem hiding this comment.
LGTM. Thanks for the patch!
4 participants
This PR improves the logging for segment deletion to ensure that a reason is logged for segment deletions via all code paths. It also updates the logging so we can log a reason for an entire batch of deletions instead of logging one message per segment.
Sample log output: