Skip to content

MINOR: Improve confusing admin client shutdown logging#10107

Merged
hachikuji merged 2 commits intoapache:trunkfrom
hachikuji:minor-improve-shutdown-message
Feb 11, 2021
Merged

MINOR: Improve confusing admin client shutdown logging#10107
hachikuji merged 2 commits intoapache:trunkfrom
hachikuji:minor-improve-shutdown-message

Conversation

@hachikuji
Copy link
Copy Markdown
Contributor

@hachikuji hachikuji commented Feb 11, 2021

If the admin client is shutdown with some unfinished calls, we see messages such as the following in the log:

2021-02-09 11:08:05.964 DEBUG [AdminClient clientId=adminclient-1] Call(callName=fetchMetadata, deadlineMs=1612843805378) timed out at 9223372036854775807 after 1 attempt(s)

The problem is that we are using passing Long.MaxValue as the current time in Call.fail in order to ensure the call is timed out and we are discarding the original cause. The patch fixes the problem by setting aborted=true instead and preserving the original exception message.

Committer Checklist (excluded from commit message)

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

Copy link
Copy Markdown
Member

@chia7712 chia7712 left a comment

Choose a reason for hiding this comment

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

@hachikuji Thanks for this patch. I had seen this weird error message many times :)

one small question is left but it does not obstruct this patch from merging.

return curNode;
}

void abortAndFail(Throwable throwable) {
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.

How about changing the input type from Throwable to TimeoutException? The exception passed to this method should NOT be wrapped by TimeoutException. Using explicit type (TimeoutException) can prevent us from passing incorrect exception in the future.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Makes sense.

Copy link
Copy Markdown
Member

@dajac dajac left a comment

Choose a reason for hiding this comment

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

Left a minor comment. LGTM otherwise.

thread.join(waitTimeMs);
}
log.debug("Kafka admin client closed.");
log.info("Kafka admin client closed.");
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 wonder if changing this log level is really necessary. What's the rational behind it?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

I think it is helpful to get at least one log message at info level in shutdown. Really at the start of shutdown is best since it triggers logic which can be difficult to explain if you don't know shutdown is taking place. Anyway, let me remove this change here and I can open a separate patch so that we can do this consistently in all the clients.

Copy link
Copy Markdown
Member

@chia7712 chia7712 left a comment

Choose a reason for hiding this comment

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

+1 to latest commit

@hachikuji hachikuji merged commit 2caef07 into apache:trunk Feb 11, 2021
ijuma added a commit to ijuma/kafka that referenced this pull request Feb 14, 2021
…e-allocations-lz4

* apache-github/trunk: (118 commits)
  KAFKA-12327: Remove MethodHandle usage in CompressionType (apache#10123)
KAFKA-12297: Make MockProducer return RecordMetadata with values as
per contract
  MINOR: Update zstd and use classes with no finalizers (apache#10120)
KAFKA-12326: Corrected regresion in MirrorMaker 2 executable
introduced with KAFKA-10021 (apache#10122)
KAFKA-12321 the comparison function for uuid type should be 'equals'
rather than '==' (apache#10098)
  MINOR: Add FetchSnapshot API doc in KafkaRaftClient (apache#10097)
  MINOR: KIP-631 KafkaConfig fixes and improvements (apache#10114)
  KAFKA-12272: Fix commit-interval metrics (apache#10102)
  MINOR: Improve confusing admin client shutdown logging (apache#10107)
  MINOR: Add BrokerMetadataListener (apache#10111)
  MINOR: Support Raft-based metadata quorums in system tests (apache#10093)
MINOR: add the MetaLogListener, LocalLogManager, and Controller
interface. (apache#10106)
  MINOR: Introduce the KIP-500 Broker lifecycle manager (apache#10095)
MINOR: Remove always-passing validation in
TestRecordTest#testProducerRecord (apache#9930)
KAFKA-5235: GetOffsetShell: Support for multiple topics and consumer
configuration override (KIP-635) (apache#9430)
MINOR: Prevent creating partition.metadata until ID can be written
(apache#10041)
  MINOR: Add RaftReplicaManager (apache#10069)
MINOR: Add ClientQuotaMetadataManager for processing QuotaRecord
(apache#10101)
  MINOR: Rename DecommissionBrokers to UnregisterBrokers (apache#10084)
MINOR: KafkaBroker.brokerState should be volatile instead of
AtomicReference (apache#10080)
  ...

clients/src/main/java/org/apache/kafka/common/record/CompressionType.java
core/src/test/scala/unit/kafka/coordinator/group/GroupMetadataManagerTest.scala
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants