runtime_error: log offset is outside the translation range #11403
Assignees
Labels
kind/bug
Something isn't working
Comments
|
Just reproduced it once again, it seems issue appears when I trying to publish something in the partition close or exact in the cleanup time. Then topic works normally |
|
Thanks for reporting this! Could you attempt to reproduce with trace logging for a few subsystems? You'd have to append the following to your redpanda invocation: Alternatively, you can use the admin api to enable them at run-time (in the example below the logs revert back to info level after 5 minutes): |
|
I failed to get them while reproducing (cuz it is not easy to reproduce), but here they are on continious fetching from client while issue is active (greped by problematic partition) |
|
thank you very much, this is very helpful |
mmaslankaprv
added a commit
to mmaslankaprv/redpanda
that referenced
this issue
Jun 15, 2023
When a segment is rolled due to the `segment.ms` property its base offset is set to the committed offset of last segment plus one. In a segment constructor all segment offset tracker offsets were set to the base offset passed as the constructor argument. This way an empty segment had exactly the same set of offsets as the segment containing single batch containing one record and base offset equal to the segment base offset. Incorrect offset accounting in empty segments lead to the situation in which eviction driven `log::truncate_prefix` was called with an incorrect offset, leading to the situation in which a log wasn't truncated at the segment boundary. This in the end resulted in the disconnection between the offset translator truncation point and first log segment start offset. For example: (we represent segment as `[base_offset,end_offset]`) In the case of log with segments: ``` [0,10][11,15] ``` After segment ms a new segment is created like this: ``` [0,10][11,15][16,16] ``` When eviction point is established the last offset is checked in this case if all the segments are to be evicted it will be equal to 16. `16` is a last offset that is going to be evicted (last included in raft snapshot). Hence the `log::truncate_prefix` is called with offset `17`. If some batches are appended to the rolled segment then the log will contain f.e. ``` [0,10][11,15][16,25] ``` Now if the log is prefix truncated at offset `17` it starts offset is updated to `17` but the underlying segment is kept. ``` [16,25] ``` Now when the reader start reading the log it will request to start from the log start offset which is `17` but it will have to skip over the batch starting at `16`. If a batch at `16` has more than one record it will still be returned to the reader and it will have to translate its base offset to kafka offset space. This is impossible as the offset_translator was already truncated to `16`. i.e. there is no information in the translator to correctly translate the offset. A fix is setting the empty segment dirty, committed and stable offset to its base_offset minus one. This way all the semantics of log operation holds as the offset returned is equal to previous segment last offset which would be the case if there would be no empty segment at the head of the log. Fixes: redpanda-data#11403 Signed-off-by: Michal Maslanka <[email protected]>
7 tasks
mmaslankaprv
added a commit
to mmaslankaprv/redpanda
that referenced
this issue
Jun 15, 2023
When a segment is rolled due to the `segment.ms` property its base offset is set to the committed offset of last segment plus one. In a segment constructor all segment offset tracker offsets were set to the base offset passed as the constructor argument. This way an empty segment had exactly the same set of offsets as the segment containing single batch containing one record and base offset equal to the segment base offset. Incorrect offset accounting in empty segments lead to the situation in which eviction driven `log::truncate_prefix` was called with an incorrect offset, leading to the situation in which a log wasn't truncated at the segment boundary. This in the end resulted in the disconnection between the offset translator truncation point and first log segment start offset. For example: (we represent segment as `[base_offset,end_offset]`) In the case of log with segments: ``` [0,10][11,15] ``` After segment ms a new segment is created like this: ``` [0,10][11,15][16,16] ``` When eviction point is established the last offset is checked in this case if all the segments are to be evicted it will be equal to 16. `16` is a last offset that is going to be evicted (last included in raft snapshot). Hence the `log::truncate_prefix` is called with offset `17`. If some batches are appended to the rolled segment then the log will contain f.e. ``` [0,10][11,15][16,25] ``` Now if the log is prefix truncated at offset `17` it starts offset is updated to `17` but the underlying segment is kept. ``` [16,25] ``` Now when the reader start reading the log it will request to start from the log start offset which is `17` but it will have to skip over the batch starting at `16`. If a batch at `16` has more than one record it will still be returned to the reader and it will have to translate its base offset to kafka offset space. This is impossible as the offset_translator was already truncated to `16`. i.e. there is no information in the translator to correctly translate the offset. A fix is setting the empty segment dirty, committed and stable offset to its base_offset minus one. This way all the semantics of log operation holds as the offset returned is equal to previous segment last offset which would be the case if there would be no empty segment at the head of the log. Fixes: redpanda-data#11403 Signed-off-by: Michal Maslanka <[email protected]>
vbotbuildovich
pushed a commit
to vbotbuildovich/redpanda
that referenced
this issue
Jun 19, 2023
When a segment is rolled due to the `segment.ms` property its base offset is set to the committed offset of last segment plus one. In a segment constructor all segment offset tracker offsets were set to the base offset passed as the constructor argument. This way an empty segment had exactly the same set of offsets as the segment containing single batch containing one record and base offset equal to the segment base offset. Incorrect offset accounting in empty segments lead to the situation in which eviction driven `log::truncate_prefix` was called with an incorrect offset, leading to the situation in which a log wasn't truncated at the segment boundary. This in the end resulted in the disconnection between the offset translator truncation point and first log segment start offset. For example: (we represent segment as `[base_offset,end_offset]`) In the case of log with segments: ``` [0,10][11,15] ``` After segment ms a new segment is created like this: ``` [0,10][11,15][16,16] ``` When eviction point is established the last offset is checked in this case if all the segments are to be evicted it will be equal to 16. `16` is a last offset that is going to be evicted (last included in raft snapshot). Hence the `log::truncate_prefix` is called with offset `17`. If some batches are appended to the rolled segment then the log will contain f.e. ``` [0,10][11,15][16,25] ``` Now if the log is prefix truncated at offset `17` it starts offset is updated to `17` but the underlying segment is kept. ``` [16,25] ``` Now when the reader start reading the log it will request to start from the log start offset which is `17` but it will have to skip over the batch starting at `16`. If a batch at `16` has more than one record it will still be returned to the reader and it will have to translate its base offset to kafka offset space. This is impossible as the offset_translator was already truncated to `16`. i.e. there is no information in the translator to correctly translate the offset. A fix is setting the empty segment dirty, committed and stable offset to its base_offset minus one. This way all the semantics of log operation holds as the offset returned is equal to previous segment last offset which would be the case if there would be no empty segment at the head of the log. Fixes: redpanda-data#11403 Signed-off-by: Michal Maslanka <[email protected]> (cherry picked from commit 76a9e6f)
|
Issue is still reproducable in redpanda Redpanda v23.2.1-rc4 - ec050f4 Here are logs right before first occurance after update |
7 tasks
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Version & Environment
Redpanda version: (use
rpk version):23.1.11
Running in docker on ubuntu 20.04
What went wrong?
I receive error in logs
And after this error consuming stops, including the other topics (not sure if it is not handled on client, or server does not provide data, we're using kgo golang library (https://github.com/twmb/franz-go)
What should have happened instead?
How to reproduce the issue?
Steps to reproduce a bit unclear, but for sure it is reproducadle on "delete" retention policy and to easily reproduce you can adjust retention time to smaller values (I had 5 min)
fetch offset out of range for {kafka/topic1/0}, requested offset: 19, partition start offset: 20, high watermark: 20, ec: { error_code: offset_out_of_range [1] }cuz retention cleaned old dataAdditional information
Logs : https://gist.github.com/kolayuk/04a6c7a776be3e8aaf42a40de06a48a6
The text was updated successfully, but these errors were encountered: