Skip to content
Merged
Changes from 3 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -133,9 +133,15 @@ public void shouldApplyUpdatesToStandbyStore() throws Exception {
kafkaStreams1WasFirstActive = false;
}

final String unexpectedMsg = "We had an unexpected restore, current status is: \n"
+ "keyQueryMetadata: %s \n"
+ "kafkaStreams1 state: %s \n"
+ "kafkaStreams1 state: %s \n";

// Assert that no restore has occurred, ensures that when we check later that the restore
// notification actually came from after the rebalance.
assertThat(listener.startOffset, is(equalTo(0L)));
assertThat(String.format(unexpectedMsg, keyQueryMetadata, kafkaStreams1.state(), kafkaStreams2.state()),
listener.startOffset, is(equalTo(0L)));
assertThat(listener.totalNumRestored, is(equalTo(0L)));

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I am not sure if this is the right fix. Note that "restoring" and "standby task update" are two different things, and a standby task should. never use the "restore" code path what this assertion verifies.

What could explain a restore is the migration of the active task from one instance to the other. However, this should actually not happen either. Could you reproduce the issue locally? We recently worked on rebalancing so maybe the issue is with regard to that.

@showuon showuon May 21, 2020

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sorry @mjsax , I tried to trace the code to find out why that would happen, but I still can't figure it out. Do you have any suggestion for it? If not, I think we can at least have more clear message output when this assert failure happen again. I'm not sure if the info is enough if the error happened again. And not sure if you have any thoughts about it?

It'll look like this when assert failure.
image

Thanks.

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I am not 100% sure about the root cause of the issue... If you have a good suggestion for a better error message, that would be great. I have not idea how we could improve it atm.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think one possible explanation is that when we start the two instances, the rebalances took not just once but twice (once for the first instance, and another time for the second). In between the task may already be processed a bit on the first instance, and then after the second rebalance it was migrated and hence was restored a bit causing the listener to be triggered.

I'd agree with @showuon here that we do not need to strictly forbids restoration not happening when starting the first two instances, just making sure after closing one instance we can restore the other up to the first batch is enough (which is already validated). So I'm fine with removing this listener all together.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

BTW there's another report that line 159 can also fail:

java.lang.AssertionError: Expected: is <true> but: was <false> at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20) at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:6) at org.apache.kafka.streams.integration.OptimizedKTableIntegrationTest.shouldApplyUpdatesToStandbyStore(OptimizedKTableIntegrationTest.java:159)

Which is a bit mystery to me, since I cannot really think of a way how that could happen.

ANyways, for now removing that listener all together seems good to me.


// Assert that the current value in store reflects all messages being processed
Expand Down