Fix sequence change race condition #14805

panhongan · 2023-08-13T07:07:52Z

Fixes #XXXX.
org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner#maybePersistAndPublishSequences

Description

Exception: org.apache.druid.java.util.common.ISE: Attempting to publish with empty segment set, but total row count was not 0: [257963].

Context:
intermediateHandoffPeriod: PT20M

Case Analysis:

18:20 ingestion task started with sequence:

[
SequenceMetadata
{sequenceId=0, sequenceName='datasource.1_ec6e2d1b6806983_0', 
assignments=[162, 2, 82, 202, 42, 122], 
startOffsets={162=652113981, 82=652884857, 2=1235731042, 202=655877162, 122=660321166, 42=1231522559}, 
exclusiveStartPartitions=[], 
endOffsets={162=9223372036854775807, 2=9223372036854775807, 82=9223372036854775807, 202=9223372036854775807, 42=9223372036854775807, 122=9223372036854775807}, 
sentinel=false, 
checkpointed=true
}
]

===================================
18:40 1st hand-off succeed with sequence:

[
SequenceMetadata
{sequenceId=0, sequenceName='datasource.1_ec6e2d1b6806983_0', 
assignments=[162, 2, 82, 202, 42, 122], 
startOffsets={162=652113981, 82=652884857, 2=1235731042, 202=655877162, 122=660321166, 42=1231522559}, 
exclusiveStartPartitions=[], 
endOffsets={162=652421674, 2=1236043200, 82=653189675, 202=656183403, 42=1231829967, 122=660629209}, 
sentinel=false, 
checkpointed=true
}
]

2023-08-06T18:40:26,525 INFO [task-runner-0-priority-0] org.apache.druid.segment.realtime.appenderator.BaseAppenderatorDriver - Pushing [2] segments in background
2023-08-06T18:40:26,526 INFO [task-runner-0-priority-0] org.apache.druid.segment.realtime.appenderator.BaseAppenderatorDriver - Pushing segments: [
datasource.1_2023-08-06T18:15:00.000Z_2023-08-06T18:30:00.000Z_2023-08-06T17:27:23.279Z_91,
datasource.1_2023-08-06T18:30:00.000Z_2023-08-06T18:45:00.000Z_2023-08-06T17:17:58.416Z_12
]

===========================
19:00 2nd hand-off succeed with sequence:

[
SequenceMetadata
{sequenceId=1, sequenceName='datasource.1_ec6e2d1b6806983_1', 
assignments=[162, 2, 82, 202, 42, 122], 
startOffsets={162=652421674, 2=1236043200, 82=653189675, 202=656183403, 42=1231829967, 122=660629209}, 
exclusiveStartPartitions=[], 
endOffsets={162=652734796, 2=1236359960, 82=653501954, 202=656497034, 42=1232144385, 122=660942851}, 
sentinel=false, 
checkpointed=true
}
]

2023-08-06T19:00:26,069 INFO [task-runner-0-priority-0] org.apache.druid.segment.realtime.appenderator.BaseAppenderatorDriver - Pushing [3] segments in background
2023-08-06T19:00:26,070 INFO [task-runner-0-priority-0] org.apache.druid.segment.realtime.appenderator.BaseAppenderatorDriver - Pushing segments: [
datasource.1_2023-08-06T18:30:00.000Z_2023-08-06T18:45:00.000Z_2023-08-06T17:17:58.416Z_54,
datasource.1_2023-08-06T18:45:00.000Z_2023-08-06T19:00:00.000Z_2023-08-06T17:25:18.834Z_38,
datasource.1_2023-08-06T19:00:00.000Z_2023-08-06T19:15:00.000Z_2023-08-06T18:20:49.142Z_39
]

==============================
Go on running with 3rd sequence:

[
SequenceMetadata{
sequenceId=2, sequenceName='datasource.1_ec6e2d1b6806983_2', 
assignments=[162, 2, 82, 202, 42, 122], 
startOffsets={162=652734796, 2=1236359960, 82=653501954, 202=656497034, 42=1232144385, 122=660942851}, 
exclusiveStartPartitions=[], 
endOffsets={162=9223372036854775807, 2=9223372036854775807, 82=9223372036854775807, 202=9223372036854775807, 42=9223372036854775807, 122=9223372036854775807}, 
sentinel=false, 
checkpointed=false
}
]

2023-08-06T19:02:58,507 INFO [task-runner-0-priority-0] org.apache.druid.segment.realtime.appenderator.BaseAppenderatorDriver - Pushing [0] segments in background
2023-08-06T19:02:58,507 INFO [task-runner-0-priority-0] org.apache.druid.segment.realtime.appenderator.StreamAppenderator - Persisted rows[0] and (estimated) bytes[0]
2023-08-06T19:02:58,509 Error while publishing segments for sequenceNumber
[
SequenceMetadata{
sequenceId=1, sequenceName='datasource.1_ec6e2d1b6806983_1',
assignments=[],
startOffsets={162=652421674, 2=1236043200, 82=653189675, 202=656183403, 42=1231829967, 122=660629209},
exclusiveStartPartitions=[],
endOffsets={162=652734796, 2=1236359960, 82=653501954, 202=656497034, 42=1232144385, 122=660942851},
sentinel=false, checkpointed=true
}
]

org.apache.druid.java.util.common.ISE: Attempting to publish with empty segment set, but total row count was not 0: [257963].

Question:

At 19:00, sequenceName='datasource.1_ec6e2d1b6806983_1' already finished with hand-off segment succeed. But why there was another segment pushing with number 0 ?
In the failed sequence metadata, why assignments is empty?

Related Source Code:
By checking the source code, found that there is an race condition issue:

Code Block A：maybePersistAndPublishSequences()

for (SequenceMetadata<PartitionIdType, SequenceOffsetType> sequenceMetadata : sequences) {
  sequenceMetadata.updateAssignments(currOffsets, this::isMoreToReadBeforeReadingRecord);
  if (!sequenceMetadata.isOpen() && !publishingSequences.contains(sequenceMetadata.getSequenceName())) {
    publishingSequences.add(sequenceMetadata.getSequenceName());
    try {
      final Object result = driver.persist(committerSupplier.get());
      log.debug(
                "Persist completed with metadata [%s], adding sequence [%s] to publish queue.",
                result,
                sequenceMetadata.getSequenceName()
      );
      publishAndRegisterHandoff(sequenceMetadata);
    }
    catch (InterruptedException e) {
      log.warn("Interrupted while persisting metadata for sequence [%s].", sequenceMetadata.getSequenceName());
      throw e;
    }
  }
}

Code Block B：After pushing segment metadata succeed

sequences.remove(sequenceMetadata);
publishingSequences.remove(sequenceMetadata.getSequenceName());

Fixed the bug ...

Renamed the class ...

Added a forbidden-apis entry ...

Release note

Key changed/added classes in this PR

org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner#maybePersistAndPublishSequences

This PR has:

merge new code

pranavbhole · 2023-08-13T18:12:01Z

@panhongan Thank you for PR, can you please elaborate the issue ?

Sync diff from master

sync apache/druid master

sync panhongan/druid master

abhishekagarwal87 · 2023-09-26T15:42:30Z

Is it same as #14995? cc @AmatyaAvadhanula

panhongan · 2023-10-05T16:51:50Z

Is it same as #14995? cc @AmatyaAvadhanula

Yes, that's the same issue. But there was race condition, need to safely handle that.
I tested my change in my personal druid cluster, and also for unit test.

...rc/test/java/org/apache/druid/indexing/seekablestream/SeekableStreamIndexTaskRunnerTest.java

panhongan · 2023-10-07T00:16:59Z

@pranavbhole @abhishekagarwal87 @kfaraz Can you help review and merge?

AmatyaAvadhanula · 2023-10-23T05:06:28Z

Hi @panhongan. It seems like the new tests pass with or without the changes. Could you please try adding more deterministic tests if possible?

…on' into fix-sequence-change-race-condition

panhongan · 2023-12-08T05:52:00Z

Hi @panhongan. It seems like the new tests pass with or without the changes. Could you please try adding more deterministic tests if possible?

@AmatyaAvadhanula @abhishekagarwal87 I improved the unit test. Also I see the #14995 was merged to fix the same issue. From my side, synchronized may be more straightforward to fix race condition issue.
Not sure is there any chance to merge my PR? Thanks.

kfaraz · 2023-12-16T05:09:12Z

@panhongan , do you still see the issue happening after #14995 was merged?
You could try updating this PR to just contain the tests that verify the fix that was done in #14995.

github-actions · 2024-02-19T00:17:25Z

This pull request has been marked as stale due to 60 days of inactivity.
It will be closed in 4 weeks if no further activity occurs. If you think
that's incorrect or this pull request should instead be reviewed, please simply
write any comment. Even if closed, you can still revive the PR at any time or
discuss it on the [email protected] list.
Thank you for your contributions.

panhongan added 2 commits August 10, 2023 11:18

Merge pull request #1 from apache/master

4f990d1

merge new code

fix race condition issue

870386f

panhongan added 4 commits August 29, 2023 11:10

Merge pull request #3 from apache/master

ca9af94

Sync diff from master

Merge pull request #5 from apache/master

c11aa45

sync apache/druid master

Merge pull request #6 from panhongan/master

48a3282

sync panhongan/druid master

improve publish sequence storage

e07e1f3

github-actions bot added the Area - Ingestion label Sep 15, 2023

panhongan marked this pull request as draft September 15, 2023 02:51

panhongan added 2 commits September 15, 2023 11:22

improve sync logic

30cf584

empty line

369c654

panhongan marked this pull request as ready for review September 15, 2023 07:39

correct to use sequencesSnapshot

715262c

add unit test

e49cc8b

github-actions bot added the Area - Dependencies label Oct 5, 2023

github-advanced-security bot found potential problems Oct 5, 2023

View reviewed changes

panhongan added 6 commits October 6, 2023 09:46

improve code style

bde7ce9

remove deprecated metho invoke

34a02cb

remove forbidden api

a75bf03

improve code style - 2

04a3cf4

remove joda-jsr310

f30ba4e

remove unused dependency

c6b8643

github-actions bot removed the Area - Dependencies label Oct 6, 2023

AmatyaAvadhanula requested a review from kfaraz October 30, 2023 07:09

panhongan added 2 commits December 7, 2023 14:22

improve unit test

b79f8d5

Merge branch 'master' into fix-sequence-change-race-condition

dbf8613

panhongan added 2 commits December 7, 2023 14:43

improve unit test

ddedd64

Merge remote-tracking branch 'origin/fix-sequence-change-race-conditi…

ea1cc43

…on' into fix-sequence-change-race-condition

github-actions bot added the stale label Feb 19, 2024

panhongan closed this Feb 23, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix sequence change race condition #14805

Fix sequence change race condition #14805

panhongan commented Aug 13, 2023 •

edited

Loading

pranavbhole commented Aug 13, 2023

abhishekagarwal87 commented Sep 26, 2023

panhongan commented Oct 5, 2023 •

edited

Loading

panhongan commented Oct 7, 2023 •

edited

Loading

AmatyaAvadhanula commented Oct 23, 2023

panhongan commented Dec 8, 2023

kfaraz commented Dec 16, 2023

github-actions bot commented Feb 19, 2024

Fix sequence change race condition #14805

Fix sequence change race condition #14805

Conversation

panhongan commented Aug 13, 2023 • edited Loading

Description

Case Analysis:

Fixed the bug ...

Renamed the class ...

Added a forbidden-apis entry ...

Release note

Key changed/added classes in this PR

pranavbhole commented Aug 13, 2023

abhishekagarwal87 commented Sep 26, 2023

panhongan commented Oct 5, 2023 • edited Loading

panhongan commented Oct 7, 2023 • edited Loading

AmatyaAvadhanula commented Oct 23, 2023

panhongan commented Dec 8, 2023

kfaraz commented Dec 16, 2023

github-actions bot commented Feb 19, 2024

panhongan commented Aug 13, 2023 •

edited

Loading

panhongan commented Oct 5, 2023 •

edited

Loading

panhongan commented Oct 7, 2023 •

edited

Loading