KAFKA-10185: Restoration info logging by vvcephei · Pull Request #8896 · apache/kafka

vvcephei · 2020-06-18T17:28:44Z

Committer Checklist (excluded from commit message)

Verify design and implementation
Verify test coverage and CI build status
Verify documentation (including upgrade notes)

vvcephei

Hey @guozhangwang , do you have a chance to look at this?

vvcephei · 2020-06-18T17:44:31Z

trivial cleanup

vvcephei · 2020-06-18T17:45:49Z

Added the exception itself as the "cause" of the warning. The actual message of the IOE is actually pretty good at explaining the root cause.

The exception message may not always contain the partitions() list, maybe we should still print that as part of warn log?

It is still there, on L424.

Ah got it, I'm still think about it as the string template and was overlooking that. SG.

vvcephei · 2020-06-18T17:46:06Z

Also added the cause to the thrown exception.

vvcephei · 2020-06-18T17:47:47Z

This is the main change. Once every ten seconds, we will log the progress for each active restoring changelog.

vvcephei · 2020-06-18T22:11:23Z

I've rolled back a bunch of accidental formatting changes, but left the ones that are actually code style compliance issues (like using brackets around conditional bodies).

vvcephei · 2020-06-18T22:15:17Z

This is moderately obnoxious... The addition of logging these values means that these tests will get a NullPointerException unless we mock this call, but the mock is irrelevant to the test outcome.

This comment seems worth adding to the code :)

I didn't think to do this... This might be equivocation, but it seems like if I wrote that in a code comment, it may or may not be true in the future. Looking at the tests, there are already like a dozen cryptic, redundant mocks, so I'm not sure justifying this one really makes a material impact on this test's readability, which is already approaching zero.

Adding a comment like "this is just to prevent the logger from throwing an NPE" carries the risk that it can quickly become untrue in two ways:

Maybe we remove or change the log so that it wouldn't need this mock; since it's a "nice" mock, we'll never know. In fact, I can't verify this call because the way the logger is configured only to print every ten seconds makes the NPE nondeterministic. Plus, it's not great to verify stuff that is beside the point of the test.

Maybe we change the implementation so that it actually does exercise this mocked behavior, then the comment will become untrue, but we may not even notice.

Typically, having this many specific and complex mocks in a test indicates that we shouldn't be using easymock, but instead configure the component with "dummy" state manager, etc. If we re-wrote this test to use that strategy, then we wouldn't need to make explicit expectations like this.

Anyway, that's why I'm sort of inclined on just declaring bankruptcy on the comprehensibility of this test.

guozhangwang

Some minor comments, please feel free to merge after addressing them

guozhangwang · 2020-06-19T16:11:32Z

The exception message may not always contain the partitions() list, maybe we should still print that as part of warn log?

guozhangwang · 2020-06-19T16:18:20Z

+                    final StringBuilder builder = new StringBuilder().append("Restoration in progress for ")
+                                                                     .append(topicPartitions.size())
+                                                                     .append(" partitions.");
+                    for (final TopicPartition partition : topicPartitions) {


nit: should we have a newline for each partition? Otherwise that ling maybe too long.

I thought about it; while it does make the logs easier to read, it makes them harder to search (as in grep, since the line that would match the query doesn't contain all the information.

We do have other places where we concatenate every topic-partition on a single line, eg in the StreamsPartitionAssignor, so I think if long lines were a problem, people would already be complaining.

Actually I do have complaints about the StreamsPartitionAssignor log entries haha :)

Anyways, I think grep a valid reason. My rationale was that when searching for this entry, most people would use "Restoration in progress for" and then manually check if the particular interested partition in the following line, but I guess I'm just biased because I'm not a heavy grep user.

It is a quite nit comment and I won't feel strong about it. Your call.

guozhangwang · 2020-06-19T16:19:38Z

This comment seems worth adding to the code :)

vvcephei · 2020-06-19T19:14:58Z

Unrelated failure:
org.apache.kafka.connect.mirror.MirrorConnectorsIntegrationTest.testReplication

Reviewers: Guozhang Wang <wangguoz@gmail.com>

* 'trunk' of github.com:apache/kafka: KAFKA-10168: fix StreamsConfig parameter name variable (apache#8865) MINOR: code cleanup for inconsistent naming (apache#8871) KAFKA-10138: Prefer --bootstrap-server for reassign_partitions command in ducktape tests (apache#8898) KAFKA-10185: Restoration info logging (apache#8896) KAFKA-9891: add integration tests for EOS and StandbyTask (apache#8890) MINOR: Reduce build time by gating test coverage plugins behind a flag (apache#8899) KAFKA-10141; Add more detail to log segment delete messages (apache#8850) KAFKA-10113; Specify fetch offsets correctly in `LogTruncationException` (apache#8822) KAFKA-10167: use the admin client to read end-offset (apache#8876) MINOR: Upgrade ducktape to 0.7.8 (apache#8879) KAFKA-10123; Fix incorrect value for AWAIT_RESET#hasPosition (apache#8841) KAFKA-9896: fix flaky StandbyTaskEOSIntegrationTest (apache#8883) MINOR: clean up unused checkstyle suppressions for Streams (apache#8861) MINOR: reuse toConfigObject(Map) to generate Config (apache#8889) MINOR: Upgrade jetty to 9.4.27.v20200227 and jersey to 2.31 (apache#8859) MINOR: Fix flaky HighAvailabilityTaskAssignorIntegrationTest (apache#8884) KAFKA-10147 MockAdminClient#describeConfigs(Collection<ConfigResource>) is unable to handle broker resource (apache#8853) KAFKA-10165: Remove Percentiles from e2e metrics (apache#8882) # Conflicts: # core/src/main/scala/kafka/log/Log.scala

Reviewers: Guozhang Wang <wangguoz@gmail.com>

vvcephei commented Jun 18, 2020

View reviewed changes

mjsax added the streams label Jun 18, 2020

vvcephei commented Jun 18, 2020

View reviewed changes

KAFKA-10185: Restoration info logging

6431b19

guozhangwang approved these changes Jun 19, 2020

View reviewed changes

vvcephei merged commit 68db063 into apache:trunk Jun 19, 2020

vvcephei deleted the kafka-10185-restore-logging branch June 19, 2020 19:18

vvcephei mentioned this pull request Jun 19, 2020

KAFKA-10185: Restoration info logging (#8896) #8904

Merged

3 tasks

vvcephei added a commit that referenced this pull request Jun 19, 2020

KAFKA-10185: Restoration info logging (#8896)

2f59188

Reviewers: Guozhang Wang <wangguoz@gmail.com>

vvcephei added a commit that referenced this pull request Jun 21, 2020

KAFKA-10185: Restoration info logging (#8896) (#8904)

9ba7137

Reviewers: Guozhang Wang <wangguoz@gmail.com>

Uh oh!

Conversation

vvcephei commented Jun 18, 2020

Committer Checklist (excluded from commit message)

Uh oh!

vvcephei left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

guozhangwang left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

vvcephei commented Jun 19, 2020

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants