You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@storm.apache.org by Kevin Conaway <ke...@gmail.com> on 2016/04/20 02:41:05 UTC

Monitoring Max Spout Pending

In Storm 0.10, is there a way to monitor the _maxSpoutPending_ value?  I
don' see it exposed in any of the metrics that storm publishes but I'd like
to be able to see how much time each tuple spends waiting and how big the
pending queue size is for each spout task.  Is this possible?

Our topology has one spout and one bolt.  The average bolt execute latency
is ~20ms but the overall spout latency is ~60ms.  I'd like to know where
those other 40ms are being spent.

Thank you

-- 
Kevin Conaway
http://www.linkedin.com/pub/kevin-conaway/7/107/580/
https://github.com/kevinconaway

Re: Monitoring Max Spout Pending

Posted by Kevin Conaway <ke...@gmail.com>.
Thanks John.  I had tried profiling locally with yourkit but my
recollection was that almost all of the time was spent in
backtype.storm.timer sleep which didn't smell right to me.

On Tue, Apr 19, 2016 at 8:43 PM, <ho...@gmail.com> wrote:

> One thing you can do is profile a worker process with jvisualvm to see
> what time is spent where for each executor thread as well as the netty and
> lmax layers.
>
> --John
>
> Sent from my iPhone
>
> On Apr 19, 2016, at 8:41 PM, Kevin Conaway <ke...@gmail.com>
> wrote:
>
> In Storm 0.10, is there a way to monitor the _maxSpoutPending_ value?  I
> don' see it exposed in any of the metrics that storm publishes but I'd like
> to be able to see how much time each tuple spends waiting and how big the
> pending queue size is for each spout task.  Is this possible?
>
> Our topology has one spout and one bolt.  The average bolt execute latency
> is ~20ms but the overall spout latency is ~60ms.  I'd like to know where
> those other 40ms are being spent.
>
> Thank you
>
> --
> Kevin Conaway
> http://www.linkedin.com/pub/kevin-conaway/7/107/580/
> https://github.com/kevinconaway
>
>


-- 
Kevin Conaway
http://www.linkedin.com/pub/kevin-conaway/7/107/580/
https://github.com/kevinconaway

Re: Monitoring Max Spout Pending

Posted by ho...@gmail.com.
One thing you can do is profile a worker process with jvisualvm to see what time is spent where for each executor thread as well as the netty and lmax layers.

--John

Sent from my iPhone

> On Apr 19, 2016, at 8:41 PM, Kevin Conaway <ke...@gmail.com> wrote:
> 
> In Storm 0.10, is there a way to monitor the _maxSpoutPending_ value?  I don' see it exposed in any of the metrics that storm publishes but I'd like to be able to see how much time each tuple spends waiting and how big the pending queue size is for each spout task.  Is this possible?
> 
> Our topology has one spout and one bolt.  The average bolt execute latency is ~20ms but the overall spout latency is ~60ms.  I'd like to know where those other 40ms are being spent.
> 
> Thank you
> 
> -- 
> Kevin Conaway
> http://www.linkedin.com/pub/kevin-conaway/7/107/580/
> https://github.com/kevinconaway

Re: Monitoring Max Spout Pending

Posted by Kevin Conaway <ke...@gmail.com>.
Yes it appears that the skipped-max-spout metric is only in 1.0.0 as part
of the automatic back pressure fixes (
https://issues.apache.org/jira/browse/STORM-886)

On Tue, Apr 19, 2016 at 9:21 PM, Kevin Conaway <ke...@gmail.com>
wrote:

> We are already sending our metrics to graphite but I don't see
> __skipped-max-spout being logged.  Was that added after 0.10?  I don't even
> see a reference to it in the codebase.
>
> We are capturing the queue metrics for each component (send_queue and
> receive_queue) and the population for each is very low, like 0.01% of
>  capacity (< 10 entries at any given time) so I'm not sure that items are
> sitting in those particular disruptor queues
>
> On Tue, Apr 19, 2016 at 8:54 PM, Jungtaek Lim <ka...@gmail.com> wrote:
>
>> Hi Kevin,
>>
>> You can attach metrics consumer to log additional informations for that
>> topology like disruptor queue metrics, __skipped-max-spout for spout, and
>> etc.
>> Please refer
>> https://github.com/apache/storm/blob/master/storm-core/src/jvm/org/apache/storm/metric/LoggingMetricsConsumer.java to
>> how to set up.
>>
>> Please note that it may affect whole throughput (I guess it would be
>> relatively small) so you may want to attach when only testing / debugging
>> performance issue.
>>
>> Thanks,
>> Jungtaek Lim (HeartSaVioR)
>>
>>
>> 2016년 4월 20일 (수) 오전 9:41, Kevin Conaway <ke...@gmail.com>님이 작성:
>>
>>> In Storm 0.10, is there a way to monitor the _maxSpoutPending_ value?  I
>>> don' see it exposed in any of the metrics that storm publishes but I'd like
>>> to be able to see how much time each tuple spends waiting and how big the
>>> pending queue size is for each spout task.  Is this possible?
>>>
>>> Our topology has one spout and one bolt.  The average bolt execute
>>> latency is ~20ms but the overall spout latency is ~60ms.  I'd like to know
>>> where those other 40ms are being spent.
>>>
>>> Thank you
>>>
>>>
>>> --
>>> Kevin Conaway
>>> http://www.linkedin.com/pub/kevin-conaway/7/107/580/
>>> https://github.com/kevinconaway
>>>
>>
>
>
> --
> Kevin Conaway
> http://www.linkedin.com/pub/kevin-conaway/7/107/580/
> https://github.com/kevinconaway
>



-- 
Kevin Conaway
http://www.linkedin.com/pub/kevin-conaway/7/107/580/
https://github.com/kevinconaway

Re: Monitoring Max Spout Pending

Posted by Jungtaek Lim <ka...@gmail.com>.
No I just would like to say it's not strange.
What you need to know about is that there could be some additional latency
when your Spout spends some moments in nextTuple(), ack(), fail(). KafkaSpout
reads the data from Kafka so I assume there's execution time in nextTuple()
on KafkaSpout.

Apache Storm is planing to merge JStorm which has separate threads between
nextTuple() and ack() & fail(). I guess it should help for the situation
like this.

Hope this helps.

2016년 4월 20일 (수) 오전 10:36, Kevin Conaway <ke...@gmail.com>님이 작성:

> We're using the out of the box kafka spout, are there any issues related
> to that here?
>
> > One thing you would like to check is, event handler on Spout is single
> thread, which means that same thread calls nextTuple() and ack() and
> fail().
>
> I'm not following you here.  What would I be checking here?
>
> On Tue, Apr 19, 2016 at 9:32 PM, Jungtaek Lim <ka...@gmail.com> wrote:
>
>> Oh right sorry it's introduced at Storm 1.0.0.
>>
>> And max-spout-pending controls the call of nextTuple() so tuple latency
>> shouldn't be affected.
>> One thing you would like to check is, event handler on Spout is single
>> thread, which means that same thread calls nextTuple() and ack() and
>> fail().
>>
>> http://storm.apache.org/releases/1.0.0/Concepts.html
>> "It is imperative that nextTuple does not block for any spout
>> implementation, because Storm calls all the spout methods on the same
>> thread."
>>
>> So if your topology spends non-ignorable time on nextTuple(), that could
>> be affected to tuple latency.
>>
>> Hope this helps.
>>
>> Thanks,
>> Jungtaek Lim (HeartSaVioR)
>>
>> 2016년 4월 20일 (수) 오전 10:21, Kevin Conaway <ke...@gmail.com>님이
>> 작성:
>>
>>> We are already sending our metrics to graphite but I don't see
>>> __skipped-max-spout being logged.  Was that added after 0.10?  I don't even
>>> see a reference to it in the codebase.
>>>
>>> We are capturing the queue metrics for each component (send_queue and
>>> receive_queue) and the population for each is very low, like 0.01% of
>>>  capacity (< 10 entries at any given time) so I'm not sure that items are
>>> sitting in those particular disruptor queues
>>>
>>> On Tue, Apr 19, 2016 at 8:54 PM, Jungtaek Lim <ka...@gmail.com> wrote:
>>>
>>>> Hi Kevin,
>>>>
>>>> You can attach metrics consumer to log additional informations for that
>>>> topology like disruptor queue metrics, __skipped-max-spout for spout, and
>>>> etc.
>>>> Please refer
>>>> https://github.com/apache/storm/blob/master/storm-core/src/jvm/org/apache/storm/metric/LoggingMetricsConsumer.java to
>>>> how to set up.
>>>>
>>>> Please note that it may affect whole throughput (I guess it would be
>>>> relatively small) so you may want to attach when only testing / debugging
>>>> performance issue.
>>>>
>>>> Thanks,
>>>> Jungtaek Lim (HeartSaVioR)
>>>>
>>>>
>>>> 2016년 4월 20일 (수) 오전 9:41, Kevin Conaway <ke...@gmail.com>님이
>>>> 작성:
>>>>
>>>>> In Storm 0.10, is there a way to monitor the _maxSpoutPending_ value?
>>>>> I don' see it exposed in any of the metrics that storm publishes but I'd
>>>>> like to be able to see how much time each tuple spends waiting and how big
>>>>> the pending queue size is for each spout task.  Is this possible?
>>>>>
>>>>> Our topology has one spout and one bolt.  The average bolt execute
>>>>> latency is ~20ms but the overall spout latency is ~60ms.  I'd like to know
>>>>> where those other 40ms are being spent.
>>>>>
>>>>> Thank you
>>>>>
>>>>>
>>>>> --
>>>>> Kevin Conaway
>>>>> http://www.linkedin.com/pub/kevin-conaway/7/107/580/
>>>>> https://github.com/kevinconaway
>>>>>
>>>>
>>>
>>>
>>> --
>>> Kevin Conaway
>>> http://www.linkedin.com/pub/kevin-conaway/7/107/580/
>>> https://github.com/kevinconaway
>>>
>>
>
>
> --
> Kevin Conaway
> http://www.linkedin.com/pub/kevin-conaway/7/107/580/
> https://github.com/kevinconaway
>

Re: Monitoring Max Spout Pending

Posted by Kevin Conaway <ke...@gmail.com>.
We're using the out of the box kafka spout, are there any issues related to
that here?

> One thing you would like to check is, event handler on Spout is single
thread, which means that same thread calls nextTuple() and ack() and
fail().

I'm not following you here.  What would I be checking here?

On Tue, Apr 19, 2016 at 9:32 PM, Jungtaek Lim <ka...@gmail.com> wrote:

> Oh right sorry it's introduced at Storm 1.0.0.
>
> And max-spout-pending controls the call of nextTuple() so tuple latency
> shouldn't be affected.
> One thing you would like to check is, event handler on Spout is single
> thread, which means that same thread calls nextTuple() and ack() and
> fail().
>
> http://storm.apache.org/releases/1.0.0/Concepts.html
> "It is imperative that nextTuple does not block for any spout
> implementation, because Storm calls all the spout methods on the same
> thread."
>
> So if your topology spends non-ignorable time on nextTuple(), that could
> be affected to tuple latency.
>
> Hope this helps.
>
> Thanks,
> Jungtaek Lim (HeartSaVioR)
>
> 2016년 4월 20일 (수) 오전 10:21, Kevin Conaway <ke...@gmail.com>님이 작성:
>
>> We are already sending our metrics to graphite but I don't see
>> __skipped-max-spout being logged.  Was that added after 0.10?  I don't even
>> see a reference to it in the codebase.
>>
>> We are capturing the queue metrics for each component (send_queue and
>> receive_queue) and the population for each is very low, like 0.01% of
>>  capacity (< 10 entries at any given time) so I'm not sure that items are
>> sitting in those particular disruptor queues
>>
>> On Tue, Apr 19, 2016 at 8:54 PM, Jungtaek Lim <ka...@gmail.com> wrote:
>>
>>> Hi Kevin,
>>>
>>> You can attach metrics consumer to log additional informations for that
>>> topology like disruptor queue metrics, __skipped-max-spout for spout, and
>>> etc.
>>> Please refer
>>> https://github.com/apache/storm/blob/master/storm-core/src/jvm/org/apache/storm/metric/LoggingMetricsConsumer.java to
>>> how to set up.
>>>
>>> Please note that it may affect whole throughput (I guess it would be
>>> relatively small) so you may want to attach when only testing / debugging
>>> performance issue.
>>>
>>> Thanks,
>>> Jungtaek Lim (HeartSaVioR)
>>>
>>>
>>> 2016년 4월 20일 (수) 오전 9:41, Kevin Conaway <ke...@gmail.com>님이
>>> 작성:
>>>
>>>> In Storm 0.10, is there a way to monitor the _maxSpoutPending_ value?
>>>> I don' see it exposed in any of the metrics that storm publishes but I'd
>>>> like to be able to see how much time each tuple spends waiting and how big
>>>> the pending queue size is for each spout task.  Is this possible?
>>>>
>>>> Our topology has one spout and one bolt.  The average bolt execute
>>>> latency is ~20ms but the overall spout latency is ~60ms.  I'd like to know
>>>> where those other 40ms are being spent.
>>>>
>>>> Thank you
>>>>
>>>>
>>>> --
>>>> Kevin Conaway
>>>> http://www.linkedin.com/pub/kevin-conaway/7/107/580/
>>>> https://github.com/kevinconaway
>>>>
>>>
>>
>>
>> --
>> Kevin Conaway
>> http://www.linkedin.com/pub/kevin-conaway/7/107/580/
>> https://github.com/kevinconaway
>>
>


-- 
Kevin Conaway
http://www.linkedin.com/pub/kevin-conaway/7/107/580/
https://github.com/kevinconaway

Re: Monitoring Max Spout Pending

Posted by Jungtaek Lim <ka...@gmail.com>.
Oh right sorry it's introduced at Storm 1.0.0.

And max-spout-pending controls the call of nextTuple() so tuple latency
shouldn't be affected.
One thing you would like to check is, event handler on Spout is single
thread, which means that same thread calls nextTuple() and ack() and
fail().

http://storm.apache.org/releases/1.0.0/Concepts.html
"It is imperative that nextTuple does not block for any spout
implementation, because Storm calls all the spout methods on the same
thread."

So if your topology spends non-ignorable time on nextTuple(), that could be
affected to tuple latency.

Hope this helps.

Thanks,
Jungtaek Lim (HeartSaVioR)

2016년 4월 20일 (수) 오전 10:21, Kevin Conaway <ke...@gmail.com>님이 작성:

> We are already sending our metrics to graphite but I don't see
> __skipped-max-spout being logged.  Was that added after 0.10?  I don't even
> see a reference to it in the codebase.
>
> We are capturing the queue metrics for each component (send_queue and
> receive_queue) and the population for each is very low, like 0.01% of
>  capacity (< 10 entries at any given time) so I'm not sure that items are
> sitting in those particular disruptor queues
>
> On Tue, Apr 19, 2016 at 8:54 PM, Jungtaek Lim <ka...@gmail.com> wrote:
>
>> Hi Kevin,
>>
>> You can attach metrics consumer to log additional informations for that
>> topology like disruptor queue metrics, __skipped-max-spout for spout, and
>> etc.
>> Please refer
>> https://github.com/apache/storm/blob/master/storm-core/src/jvm/org/apache/storm/metric/LoggingMetricsConsumer.java to
>> how to set up.
>>
>> Please note that it may affect whole throughput (I guess it would be
>> relatively small) so you may want to attach when only testing / debugging
>> performance issue.
>>
>> Thanks,
>> Jungtaek Lim (HeartSaVioR)
>>
>>
>> 2016년 4월 20일 (수) 오전 9:41, Kevin Conaway <ke...@gmail.com>님이 작성:
>>
>>> In Storm 0.10, is there a way to monitor the _maxSpoutPending_ value?  I
>>> don' see it exposed in any of the metrics that storm publishes but I'd like
>>> to be able to see how much time each tuple spends waiting and how big the
>>> pending queue size is for each spout task.  Is this possible?
>>>
>>> Our topology has one spout and one bolt.  The average bolt execute
>>> latency is ~20ms but the overall spout latency is ~60ms.  I'd like to know
>>> where those other 40ms are being spent.
>>>
>>> Thank you
>>>
>>>
>>> --
>>> Kevin Conaway
>>> http://www.linkedin.com/pub/kevin-conaway/7/107/580/
>>> https://github.com/kevinconaway
>>>
>>
>
>
> --
> Kevin Conaway
> http://www.linkedin.com/pub/kevin-conaway/7/107/580/
> https://github.com/kevinconaway
>

Re: Monitoring Max Spout Pending

Posted by Kevin Conaway <ke...@gmail.com>.
We are already sending our metrics to graphite but I don't see
__skipped-max-spout being logged.  Was that added after 0.10?  I don't even
see a reference to it in the codebase.

We are capturing the queue metrics for each component (send_queue and
receive_queue) and the population for each is very low, like 0.01% of
 capacity (< 10 entries at any given time) so I'm not sure that items are
sitting in those particular disruptor queues

On Tue, Apr 19, 2016 at 8:54 PM, Jungtaek Lim <ka...@gmail.com> wrote:

> Hi Kevin,
>
> You can attach metrics consumer to log additional informations for that
> topology like disruptor queue metrics, __skipped-max-spout for spout, and
> etc.
> Please refer
> https://github.com/apache/storm/blob/master/storm-core/src/jvm/org/apache/storm/metric/LoggingMetricsConsumer.java to
> how to set up.
>
> Please note that it may affect whole throughput (I guess it would be
> relatively small) so you may want to attach when only testing / debugging
> performance issue.
>
> Thanks,
> Jungtaek Lim (HeartSaVioR)
>
>
> 2016년 4월 20일 (수) 오전 9:41, Kevin Conaway <ke...@gmail.com>님이 작성:
>
>> In Storm 0.10, is there a way to monitor the _maxSpoutPending_ value?  I
>> don' see it exposed in any of the metrics that storm publishes but I'd like
>> to be able to see how much time each tuple spends waiting and how big the
>> pending queue size is for each spout task.  Is this possible?
>>
>> Our topology has one spout and one bolt.  The average bolt execute
>> latency is ~20ms but the overall spout latency is ~60ms.  I'd like to know
>> where those other 40ms are being spent.
>>
>> Thank you
>>
>>
>> --
>> Kevin Conaway
>> http://www.linkedin.com/pub/kevin-conaway/7/107/580/
>> https://github.com/kevinconaway
>>
>


-- 
Kevin Conaway
http://www.linkedin.com/pub/kevin-conaway/7/107/580/
https://github.com/kevinconaway

Re: Monitoring Max Spout Pending

Posted by Jungtaek Lim <ka...@gmail.com>.
Hi Kevin,

You can attach metrics consumer to log additional informations for that
topology like disruptor queue metrics, __skipped-max-spout for spout, and
etc.
Please refer
https://github.com/apache/storm/blob/master/storm-core/src/jvm/org/apache/storm/metric/LoggingMetricsConsumer.java
to
how to set up.

Please note that it may affect whole throughput (I guess it would be
relatively small) so you may want to attach when only testing / debugging
performance issue.

Thanks,
Jungtaek Lim (HeartSaVioR)


2016년 4월 20일 (수) 오전 9:41, Kevin Conaway <ke...@gmail.com>님이 작성:

> In Storm 0.10, is there a way to monitor the _maxSpoutPending_ value?  I
> don' see it exposed in any of the metrics that storm publishes but I'd like
> to be able to see how much time each tuple spends waiting and how big the
> pending queue size is for each spout task.  Is this possible?
>
> Our topology has one spout and one bolt.  The average bolt execute latency
> is ~20ms but the overall spout latency is ~60ms.  I'd like to know where
> those other 40ms are being spent.
>
> Thank you
>
>
> --
> Kevin Conaway
> http://www.linkedin.com/pub/kevin-conaway/7/107/580/
> https://github.com/kevinconaway
>