[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18044358#comment-18044358
]
Matthias J. Sax commented on KAFKA-19678:
-
NP. Would you be able to build from the source, and test 4.2.0-SNAPSHOT or
4.1.2-SNAPSHOT to verify if it resolve the issue you are observing?
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Assignee: Bill Bejeck
>Priority: Major
> Fix For: 4.2.0, 4.1.2
>
> Attachments: image-2025-09-05-12-13-24-910.png,
> image-2025-10-20-13-36-54-857.png, image-2025-10-21-09-24-02-505.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18044197#comment-18044197
]
Steven Schlansker commented on KAFKA-19678:
---
Thanks all for your help!
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Assignee: Bill Bejeck
>Priority: Major
> Fix For: 4.2.0, 4.1.2
>
> Attachments: image-2025-09-05-12-13-24-910.png,
> image-2025-10-20-13-36-54-857.png, image-2025-10-21-09-24-02-505.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18044178#comment-18044178
]
Bill Bejeck commented on KAFKA-19678:
-
cherry-picked https://github.com/apache/kafka/pull/21091 to 4.2 and 4.1
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Assignee: Bill Bejeck
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png,
> image-2025-10-20-13-36-54-857.png, image-2025-10-21-09-24-02-505.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18043639#comment-18043639
]
Steven Schlansker commented on KAFKA-19678:
---
That's great news - since in normal operation, iterators should not be leaked,
it seems appropriate that this diagnostic is DEBUG level.
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Assignee: Bill Bejeck
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png,
> image-2025-10-20-13-36-54-857.png, image-2025-10-21-09-24-02-505.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18042324#comment-18042324
]
Matthias J. Sax commented on KAFKA-19678:
-
Great find [~bbejeck] --seems this makes our life much easier. If we just fix
the incorrect recording level, we should have a proper fix. +1 from my side.
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Assignee: Bill Bejeck
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png,
> image-2025-10-20-13-36-54-857.png, image-2025-10-21-09-24-02-505.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18042229#comment-18042229
]
Bill Bejeck commented on KAFKA-19678:
-
[~mjsax][~stevenschlansker] looking at the
[KIP-989|https://cwiki.apache.org/confluence/display/KAFKA/KIP-989%3A+Improved+StateStore+Iterator+metrics+for+detecting+leaks]
the `oldest-iterator-open-since-ms` is specified as DEBUG. So if we decide to
go down the path of only registering it when the recording level is DEBUG would
work.
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Assignee: Bill Bejeck
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png,
> image-2025-10-20-13-36-54-857.png, image-2025-10-21-09-24-02-505.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18031538#comment-18031538
]
Matthias J. Sax commented on KAFKA-19678:
-
{quote}ideally there would be a fix outside of each individual processor having
workarounds
{quote}
I never disagreed about this – just wanted to get you out of the ditch, until
we find a fix :)
Glad you figures out the memory/metric leak thing, and happy to hear that the
fix improves the situation... AK 4.1.1 should do out soon
Interesting idea about making it a DEBUG level metric – could be a good
solution in case we cannot figure out anything better. But would require a KIP
I assume? [~bbejeck] wanted to work on this ticket. Let's hear from him. –
Personally I would hope that we just find a good fix, even if I am not 100%
sure what it could be – maybe something a lazy/delayed removal of the metric,
that we would cancel if a new iterator comes in again?
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Assignee: Bill Bejeck
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png,
> image-2025-10-20-13-36-54-857.png, image-2025-10-21-09-24-02-505.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18031529#comment-18031529
]
Steven Schlansker commented on KAFKA-19678:
---
[~mjsax] , would it make sense to move the state store oldest open iterator
metric from current INFO to DEBUG level? That would resolve the issue as far as
we are concerned, we are happy to accept this kind of overhead when debugging
(now that the leak is fixed).
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png,
> image-2025-10-20-13-36-54-857.png, image-2025-10-21-09-24-02-505.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18031505#comment-18031505
]
Steven Schlansker commented on KAFKA-19678:
---
Re-picking the fix to KAFKA-19748 made the situation much, much better. But, I
am still seeing elevated levels of contention, with the leak fixed.
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png,
> image-2025-10-20-13-36-54-857.png, image-2025-10-21-09-24-02-505.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18031487#comment-18031487
]
Steven Schlansker commented on KAFKA-19678:
---
Ok, this might be an error on our end. I (too eagerly?) picked the fix to
KAFKA-19748 before it was finished, looks like the version I have is
incomplete, and thought the metrics leak was fixed. I will re-apply the final
version and hope it fixes the leak properly this time.
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png,
> image-2025-10-20-13-36-54-857.png, image-2025-10-21-09-24-02-505.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18031472#comment-18031472
]
Steven Schlansker commented on KAFKA-19678:
---
Ok, I think part of the reason why the monitor contention is so high, is
because we have a lot of metrics registered, and the storage is a LinkedList
inside a CHM. I'm not sure yet if 11M(!!) metrics is a leak or something we're
doing wrong...
!image-2025-10-21-09-23-16-855.png!
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png,
> image-2025-10-20-13-36-54-857.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18031253#comment-18031253
]
Steven Schlansker commented on KAFKA-19678:
---
I believe I can observe a similar performance bottleneck where the
`ForeinTableJoinProcessorSupplier$KTableKTableJoinProcessor` is less performant
than it could be due to repeated registering and unregistering metrics with
this lock, so while I am happy to test workaround on our custom processor, I
have increased confidence that ideally there would be a fix outside of each
individual processor having workarounds:
!image-2025-10-20-13-36-54-857.png!
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png,
> image-2025-10-20-13-36-54-857.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18029605#comment-18029605
]
Steven Schlansker commented on KAFKA-19678:
---
Thanks for the context, this does sound tricky :(
Unfortunately, some degenerate groups can have upwards of 0.5M entries (of at
least 16 bytes each), so I'm concerned the list approach would quickly run into
maximum-record-size problems, as well as expensive serialization and
deserialization costs.
For now, we run a patched kafka client which intentionally leaks these metrics,
which is far from a long term solution but at least keeps us running at the
moment.
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18028890#comment-18028890
]
Matthias J. Sax commented on KAFKA-19678:
-
Thanks for reporting this issue. – I am wondering what your application is
doing exactly, and if it might be possible to avoid creating an iterator per
record?
One hacky work-around I could think of, would be to create a "dummy iterator",
so you always have at least one-open iterators, and the metric won't be
removed/added over and over again?
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18029580#comment-18029580
]
Steven Schlansker commented on KAFKA-19678:
---
Thanks [~mjsax] for taking a look.
We have a product requirement to compute a streaming-min and streaming-max
operation over a grouped aggregate. For example, "earliest record due date for
each user" or "latest record created date for each user".
To do this, we take the input stream,
{code:java}
K1 = U1 V1
K2 = U1 V2
K3 = U2 V3
K4 = U2 V4 {code}
and reorganize the records so the group-key and value are the key prefix, like
{code:java}
U1 V1 K1 = K1
U1 V2 K2 = K2
U2 V3 K3 = K3
U2 V4 K4 = K4{code}
and put it in a state store. Then, to determine the minimum or maximum, we do a
prefix range scan to take the first or last record for the group U1 or U2.
It might be possible to reduce the number of range scans by caching the minimum
and maximum values by key, to know if the max or min possibly changed and skip
the iterator if not, but then we need a second state store duplicating the
winning record per user. We assumed the cost of opening an iterator is roughly
equal to the cost of a key lookup, but maybe this is not a good assumption.
Regardless, to me, the current semantics for this metric seems wrong. If the
store is open, with no iterators currently, the correct value for the metric is
explicitly "0" not "null / unregister". The current setup makes it difficult to
graph, since our dashboards will interpret "null" as "missing data" which is
distinct from a present 0.
I would expect the metric to be unregistered only when the state store is
closed or otherwise we are sure no new iterators will ever be created.
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18029618#comment-18029618
]
Matthias J. Sax commented on KAFKA-19678:
-
We did not observe any regression in our test/benchmark setup with regard to
throughput, and nobody reported anything about it yet... But yes, might be
worth to look into. It's not just FK join, but also session-windows,
sliding-windows, and stream-stream join that use range scans... (maybe also
others – would need to double check the code).
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18029608#comment-18029608
]
Matthias J. Sax commented on KAFKA-19678:
-
0.5M entries... yeah, that won't work with the list approach...
Did you consider the "dummy iterator" idea? Something like, create an `all()`
iterator at startup, and every X second, you first create a new all() iterator,
and close the old one? This way, you have at least one open iterator all the
time – you still want to close and replace it periodically, to not get an very
old open iterator. Could this work?
Leaking the metrics sounds like a bad idea, as it will consume a lot a
resources inside RocksDB...
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18029609#comment-18029609
]
Steven Schlansker commented on KAFKA-19678:
---
Yes, we can explore the dummy iterator approach. That said, is this not a
problem also for built in processors, like the ForeignTableJoinProcessor? It
also seems to use a range scan per record.
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
[jira] [Commented] (KAFKA-19678) Streams open iterator tracking has high contention on metrics lock
[
https://issues.apache.org/jira/browse/KAFKA-19678?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18029604#comment-18029604
]
Matthias J. Sax commented on KAFKA-19678:
-
This metric is a little bit tricky... (for context
[KIP-989|https://cwiki.apache.org/confluence/display/KAFKA/KIP-989%3A+Improved+StateStore+Iterator+metrics+for+detecting+leaks])
– if we would report `0` (or `-1`), the issue is, that if you setup an alert
that computes "currentTime minus metricValue" you get false-positives, as the
iterator open time computation would report a high value (many years). Your
alert would need to be conditional, what is a struggle as far as I know. While
a dashboard can render `0` it would blow out your "y-axis" on the dashboard to
a very high value, too, and it seems it would make it very hard to actually
read the dashboard?
We actually reported `null` originally, but this also caused issues:
https://issues.apache.org/jira/browse/KAFKA-17954 – so we decided to
de-register the metric when it becomes empty.
{quote} otherwise we are sure no new iterators will ever be created.
{quote}
Not sure what you mean by this?
For your use case: how many values per group do you get? Would it be possible
to do an `aggregation` per group, and compute a `List` over all values per
group? This would allow you to maintain this list with a key-lookup per update,
avoiding a range scan (of course, this only works if the list is small enough,
to avoid too large records...)
> Streams open iterator tracking has high contention on metrics lock
> --
>
> Key: KAFKA-19678
> URL: https://issues.apache.org/jira/browse/KAFKA-19678
> Project: Kafka
> Issue Type: Bug
> Components: streams
>Affects Versions: 4.1.0
>Reporter: Steven Schlansker
>Priority: Major
> Attachments: image-2025-09-05-12-13-24-910.png
>
>
> We run Kafka Streams 4.1.0 with custom processors that heavily use state
> store range iterators.
> While investigating disappointing performance, we found a surprising source
> of lock contention.
> Over the course of about a 1 minute profiler sample, the
> {{org.apache.kafka.common.metrics.Metrics}} lock is taken approximately
> 40,000 times and blocks threads for about 1 minute.
> This appears to be because our state stores generally have no iterators open,
> except when their processor is processing a record, in which case it opens an
> iterator (taking the lock through {{OpenIterators.add}} into
> {{{}Metrics.registerMetric{}}}), does a tiny bit of work, and then closes the
> iterator (again taking the lock through {{OpenIterators.remove}} into
> {{{}Metrics.removeMetric{}}}).
> So, stream processing threads takes a globally shared lock twice per record,
> for this subset of our data. I've attached a profiler thread state
> visualization with our findings - the red bar indicates the thread was
> blocked during the sample on this lock. As you can see, this lock seems to be
> severely hampering our performance.
>
> !image-2025-09-05-12-13-24-910.png!
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
