Status

Current state: Accepted

Discussion thread: here [Change the link from the KIP proposal email archive to your own email thread]

JIRA: 

Please keep the discussion on the mailing list rather than commenting on the wiki (wiki discussions get unwieldy fast).

Motivation

When debugging Kafka Streams application performance, it can be hard to isolate the problem to a bottleneck in Kafka Streams. The poll-ratio and processing-ratio metrics reported today are helpful, but limited in sample size: they tell you the proportion of time spent in poll or processing records for the last poll loop at an instant in time. They are also a bit too coarse-grained: poll wraps some computationally-significant work, like calls to consumer interceptors. Really, we just want to know the proportion of time the application was processing records vs blocked waiting on Kafka. This KIP proposes a new metric, called `blocked-time-total` that measures the total time a thread spent blocked since it was started. Users can sample this metric periodically and use the difference between samples to measure time blocked during an interval.

Public Interfaces

New Metrics

Kafka Streams

blocked-time-total
tags: thread-id
group: stream-thread-metrics
level: INFO. The proposed metrics should be collectible at INFO level without adding meaningful overhead. They require sampling the time twice during the corresponding API calls, which nowadays is very cheap.
description: the total time the Kafka Streams thread spent blocked on Kafka.

thread-start-time
tags: thread-id
group: stream-thread-metrics
level: INFO
description: the epoch time the Kafka Streams thread was started. This is useful for computing the processing ratio during the first interval after the thread starts. 

Producer

flush-time-total
tags: client-id
group: producer-metrics
level: INFO
description: the total time the Producer spent in `Producer.flush`

txn-init-time-total
tags: client-id
group: producer-metrics
level: INFO
description: the total time the Producer spent initializing transactions (for EOS).

txn-begin-time-total
tags: client-id
group: producer-metrics
level: INFO
description: the total time the Producer spent in beginTransaction (for EOS).

txn-send-offsets-time-total
tags: client-id
group: producer-metrics
level: INFO
description: the total time the Producer spent sending offsets to transactions (for EOS).

txn-commit-time-total
tags: client-id
group: producer-metrics
level: INFO
description: the total time the Producer spent committing transactions (for EOS).

txn-abort-time-total
tags: client-id
group: producer-metrics
level: INFO
description: the total time the Producer spent aborting transactions (for EOS).

Consumer

commited-time-total
tags: client-id
group: consumer-metrics
level: INFO
description: the total time the Consumer spent in committed.

commit-sync-time-total
tags: client-id
group: consumer-metrics
level: INFO
description: the total time the Consumer spent committing offsets (for AOS).

Proposed Changes

flush-time-total: this will be a Producer metric computed as the cumulative sum of time elapsed during calls to Producer.flush.

txn-init-time-total: this will be a Producer metric computed as the cumulative sum of time elapsed during calls to Producer.initTransactions.

txn-begin-time-total: this will be a Producer metric computed as the cumulative sum of time elapsed during calls to Producer.beginTransaction.

txn-send-offsets-time-total: this will be a Producer metric computed as the cumulative sum of time elapsed during calls to Producer.sendOffsetsToTransaction.

txn-commit-time-total: this will be a Producer metric computed as the cumulative sum of time elapsed during calls to Producer.commitTransaction.

txn-abort-time-total: this will be a Producer metric computed as the cumulative sum of time elapsed during calls to Producer.abortTransaction.

commited-time-total: this will be a Consumer metric computed as the cumulative sum of time elapsed during calls to Consumer.committed.

commit-sync-time-total: this will be a Consumer metric computed as the cumulative sum of time elapsed during calls to Consumer.commitSync.

blocked-time-total: this will be a Value that returns the sum of the following metrics:

• consumer’s io-waittime-total
• consumer’s iotime-total
• consumer’s committed-time-total
• consumer’s commit-sync-time-total
• restore consumer’s io-waittime-total
• restore consumer’s iotime-total
• admin client’s io-waittime-total
• admin client’s iotime-total
• producer’s bufferpool-wait-time-total
• producer's flush-time-total
• producer's txn-init-time-total
• producer's txn-begin-time-total
• producer's txn-send-offsets-time-total
• producer's txn-commit-time-total
• producer's txn-abort-time-total

Compatibility, Deprecation, and Migration Plan

We're not changing or removing existing metrics, so compatibility/migration is not a concern.

Rejected Alternatives

One alternative we considered was to compute a blocked-ratio at a fixed interval, or possibly a configurable interval. It seems more flexible to just expose the total blocked time and leave windowing to the user.