>
> If we used "iterator-duration-max", for
> example, would it not be confusing that it includes Iterators that are
> still open, and therefore the duration is not yet known?
1. Ah, I think I understand your concern better now -- I totally agree that
a
"iterator-duration-max" metric would be confusing/misleading. I was
thinking about it a bit differently, something more akin to the
"last-rebalance-seconds-ago" consumer metric. As the name suggests,
that basically just tracks how long the consumer has gone without
rebalancing -- it doesn't purport to represent the actual duration between
rebalances, just the current time since the last one. The hard part is
really
in choosing a name that reflects this -- maybe you have some better ideas
but off the top of my head, perhaps something like "iterator-lifetime-max"?
2. I'm not quite sure how to interpret the "iterator-duration-total" metric
-- what exactly does it mean to add up all the iterator durations? For
some context, while this is not a hard-and-fast rule, in general you'll
find that Kafka/Streams metrics tend to come in pairs of avg/max or
rate/total. Something that you might measure the avg for usually is
also useful to measure the max, whereas a total metric is probably
also useful as a rate but not so much as an avg. I actually think this
is part of why it feels like it makes so much sense to include a "max"
version of this metric, as Lucas suggested, even if the name of
"iterator-duration-max" feels misleading. Ultimately the metric names
are up to you, but for this reason, I would personally advocate for
just going with an "iterator-duration-avg" and "iterator-duration-max"
I did see your example in which you mention one could monitor the
rate of change of the "-total" metric. While this does make sense to
me, if the only way to interpret a metric is by computing another
function over it, then why not just make that computation the metric
and cut out the middle man? And in this case, to me at least, it feels
much easier to understand a metric like "iterator-duration-max" vs
something like "iterator-duration-total-rate"
3. By the way, can you add another column to the table with the new metrics
that lists the recording level? My suggestion would be to put the
"number-open-iterators" at INFO and the other two at DEBUG. See
the following for my reasoning behind this recommendation
4. I would change the "Type" entry for the "number-open-iterators" from
"Value" to "Gauge". This helps justify the "INFO" level for this metric,
since unlike the other metrics which are "Measurables", the current
timestamp won't need to be retrieved on each recording
5. Can you list the tags that would be associated with each of these
metrics (either in the table, or separately above/below if they will be
the same for all)
6. Do you have a strong preference for the name "number-open-iterators"
or would you be alright in shortening this to "num-open-iterators"? The
latter is more in line with the naming scheme used elsewhere in Kafka
for similar kinds of metrics, and a shorter name is always nice.
7. With respect to the rocksdb cache metrics, those sound useful but
if it was me, I would probably save them for a separate KIP mainly just
because the KIP freeze deadline is in a few weeks, and I wouldn't want
to end up blocking all the new metrics just because there was ongoing
debate about a subset of them. That said, you do have 3 full weeks, so
I would hope that you could get both sets of metrics agreed upon in
that timeframe!
On Tue, Oct 24, 2023 at 6:35 AM Nick Telford <nick.telf...@gmail.com> wrote:
> I don't really have a problem with adding such a metric, I'm just not
> entirely sure how it would work. If we used "iterator-duration-max", for
> example, would it not be confusing that it includes Iterators that are
> still open, and therefore the duration is not yet known? When graphing that
> over time, I suspect it would be difficult to understand.
>
> 3.
> FWIW, this would still be picked up by "open-iterators", since that metric
> is only decremented when Iterator#close is called (via the
> ManagedKeyValueIterator#onClose hook).
>
> I'm actually considering expanding the scope of this KIP slightly to
> include improved Block Cache metrics, as my own memory leak investigations
> have trended in that direction. Do you think the following metrics should
> be included in this KIP, or should I create a new KIP?
>
> - block-cache-index-usage (number of bytes occupied by index blocks)
> - block-cache-filter-usage (number of bytes occupied by filter blocks)
>
> Regards,
> Nick
>
> On Tue, 24 Oct 2023 at 07:09, Sophie Blee-Goldman <sop...@responsive.dev>
> wrote:
>
> > I actually think we could implement Lucas' suggestion pretty easily and
> > without too much additional effort. We have full control over the
> iterator
> > that is returned by the various range queries, so it would be easy to
> > register a gauge metric for how long it has been since the iterator was
> > created. Then we just deregister the metric when the iterator is closed.
> >
> > With respect to how useful this metric would be, both Nick and Lucas have
> > made good points: I would agree that in general, leaking iterators would
> > mean an ever-increasing iterator count that should be possible to spot
> > without this. However, a few things to consider:
> >
> > 1. it's really easy to set up an alert based on some maximum threshold of
> > how long an iterator should remain open for. It's relatively more tricky
> to
> > set up alerts based on the current count of open iterators and how it
> > changes over time.
> > 2. As Lucas mentioned, it only takes a few iterators to wreak havoc in
> > extreme cases. Sometimes more advanced applications end up with just a
> few
> > leaking iterators despite closing the majority of them. I've seen this
> > happen just once personally, but it was driving everyone crazy until we
> > figured it out.
> > 3. A metric for how long the iterator has been open would help to
> identify
> > hanging iterators due to some logic where the iterator is properly closed
> > but for whatever reason just isn't being advanced to the end, and thus
> not
> > reached the iterator#close line of the user code. This case seems
> difficult
> > to spot without the specific metric for iterator lifetime
> > 4. Lastly, I think you could argue that all of the above are fairly
> > advanced use cases, but this seems like a fairly advanced feature
> already,
> > so it doesn't seem unreasonable to try and cover all the bases.
> >
> > All that said, my philosophy is that the KIP author gets the final word
> on
> > what to pull into scope as long as the proposal isn't harming anyone
> > without the extra feature/changes. So it's up to you Nick -- just wanted
> > to add some context on how it could work, and why it would be helpful
> >
> > Thanks for the KIP!
> >
> > On Wed, Oct 18, 2023 at 7:04 AM Lucas Brutschy
> > <lbruts...@confluent.io.invalid> wrote:
> >
> > > Hi Nick,
> > >
> > > I did not think in detail about how to implement it, just about what
> > > metrics would be nice to have. You are right, we'd have to
> > > register/deregister the iterators during open/close. This would be
> > > more complicated to implement than the other metrics, but I do not see
> > > a fundamental problem with it.
> > >
> > > As far as I understand, even a low number of leaked iterators can hurt
> > > RocksDB compaction significantly. So we may even want to detect if the
> > > iterators are opened by one-time / rare queries against the state
> > > store.
> > >
> > > But, as I said, that would be an addition and not a change of the
> > > current contents of the KIP, so I'd support the KIP moving forward
> > > even without this extension.
> > >
> > > Cheers, Lucas
> > >
> > >
> > >
> > > On Tue, Oct 17, 2023 at 3:45 PM Nick Telford <nick.telf...@gmail.com>
> > > wrote:
> > > >
> > > > Hi Lucas,
> > > >
> > > > Hmm, I'm not sure how we could reliably identify such leaked
> Iterators.
> > > If
> > > > we tried to include open iterators when calculating
> iterator-duration,
> > > we'd
> > > > need some kind of registry of all the open iterator creation
> > timestamps,
> > > > wouldn't we?
> > > >
> > > > In general, if you have a leaky Iterator, it should manifest as a
> > > > persistently climbing "open-iterators" metric, even on a busy node,
> > > because
> > > > each time that Iterator is used, it will leak another one. So even in
> > the
> > > > presence of many non-leaky Iterators on a busy instance, the metric
> > > should
> > > > still consistently climb.
> > > >
> > > > Regards,
> > > >
> > > > Nick
> > > >
> > > > On Mon, 16 Oct 2023 at 14:24, Lucas Brutschy <lbruts...@confluent.io
> > > .invalid>
> > > > wrote:
> > > >
> > > > > Hi Nick!
> > > > >
> > > > > thanks for the KIP! I think this could be quite useful, given the
> > > > > problems that we had with leaks due to RocksDB resources not being
> > > > > closed.
> > > > >
> > > > > I don't have any pressing issues why we can't accept it like it is,
> > > > > just one minor point for discussion: would it also make sense to
> make
> > > > > it possible to identify a few very long-running / leaked
> iterators? I
> > > > > can imagine on a busy node, it would be hard to spot that 1% of the
> > > > > iterators never close when looking only at closed iterator or the
> > > > > number of iterators. But it could still be good to identify those
> > > > > leaks early. One option would be to add `iterator-duration-max` and
> > > > > take open iterators into account when computing the metric.
> > > > >
> > > > > Cheers,
> > > > > Lucas
> > > > >
> > > > >
> > > > > On Thu, Oct 5, 2023 at 3:50 PM Nick Telford <
> nick.telf...@gmail.com>
> > > > > wrote:
> > > > > >
> > > > > > Hi Colt,
> > > > > >
> > > > > > I kept the details out of the KIP, because KIPs generally
> document
> > > > > > high-level design, but the way I'm doing it is like this:
> > > > > >
> > > > > > final ManagedKeyValueIterator<Bytes, byte[]>
> > > > > > rocksDbPrefixSeekIterator = cf.prefixScan(accessor, prefixBytes);
> > > > > > --> final long startedAt = System.nanoTime();
> > > > > > openIterators.add(rocksDbPrefixSeekIterator);
> > > > > > rocksDbPrefixSeekIterator.onClose(() -> {
> > > > > > -->
> > metricsRecorder.recordIteratorDuration(System.nanoTime()
> > > -
> > > > > > startedAt);
> > > > > > openIterators.remove(rocksDbPrefixSeekIterator);
> > > > > > });
> > > > > >
> > > > > > The lines with the arrow are the new code. This pattern is
> repeated
> > > > > > throughout RocksDBStore, wherever a new RocksDbIterator is
> created.
> > > > > >
> > > > > > Regards,
> > > > > > Nick
> > > > > >
> > > > > > On Thu, 5 Oct 2023 at 12:32, Colt McNealy <c...@littlehorse.io>
> > > wrote:
> > > > > >
> > > > > > > Thank you for the KIP, Nick!
> > > > > > >
> > > > > > > This would be highly useful for many reasons. Much more sane
> than
> > > > > checking
> > > > > > > for leaked iterators by profiling memory usage while running
> > 100's
> > > of
> > > > > > > thousands of range scans via interactive queries (:
> > > > > > >
> > > > > > > One small question:
> > > > > > >
> > > > > > > >The iterator-duration metrics will be updated whenever an
> > > Iterator's
> > > > > > > close() method is called
> > > > > > >
> > > > > > > Does the Iterator have its own "createdAt()" or equivalent
> field,
> > > or
> > > > > do we
> > > > > > > need to keep track of the Iterator's start time upon creation?
> > > > > > >
> > > > > > > Cheers,
> > > > > > > Colt McNealy
> > > > > > >
> > > > > > > *Founder, LittleHorse.dev*
> > > > > > >
> > > > > > >
> > > > > > > On Wed, Oct 4, 2023 at 9:07 AM Nick Telford <
> > > nick.telf...@gmail.com>
> > > > > > > wrote:
> > > > > > >
> > > > > > > > Hi everyone,
> > > > > > > >
> > > > > > > > KIP-989 is a small Kafka Streams KIP to add a few new metrics
> > > around
> > > > > the
> > > > > > > > creation and use of RocksDB Iterators, to aid users in
> > > identifying
> > > > > > > > "Iterator leaks" that could cause applications to leak native
> > > memory.
> > > > > > > >
> > > > > > > > Let me know what you think!
> > > > > > > >
> > > > > > > >
> > > > > > > >
> > > > > > >
> > > > >
> > >
> >
> https://cwiki.apache.org/confluence/display/KAFKA/KIP-989%3A+RocksDB+Iterator+Metrics
> > > > > > > >
> > > > > > > > P.S. I'm not too sure about the formatting of the "New
> Metrics"
> > > > > table,
> > > > > > > any
> > > > > > > > advice there would be appreciated.
> > > > > > > >
> > > > > > > > Regards,
> > > > > > > > Nick
> > > > > > > >
> > > > > > >
> > > > >
> > >
> >
>
