Long time latency

[Min Zhou]

Hi all,

From the spouts stats, it informed that there's quite a long time latency, 62.930 ms in average, with my custom spouts and the number of Emitted/Transferred is much larger than the number of Acked. 

What's the "Complete latency(ms) " made up of? 

Thanks in advance,

Min

--
My research interests are distributed systems, parallel computing and bytecode based virtual machine.

My profile:
http://www.linkedin.com/in/coderplay
My blog:
http://coderplay.javaeye.com

[Nathan Marz]

The complete latency is the time from the spout emitting a tuple to that tuple being acked on the spout. So it tracks the time for the whole tuple tree to be processed.

If you dive into the spout component in the UI, you'll see that a lot of the emitted/transferred is on the __ack* stream. This is the spout communicating with the ackers which take care of tracking the tuple trees.

--
Twitter: @nathanmarz
http://nathanmarz.com

[Min Zhou]

Below is a instance of storm web ui.  It surprises me  the acked number of PrinterBolt is 594756340, and that number of  the total topology is 0. 

Can you explain it?

Topology stats

Window	Emitted	Transferred	Complete latency (ms)	Acked	Failed
10m 0s	1797746400	1280933240	0.000	0	0
3h 0m 0s	1964840900	1370085360	0.000	0	0
1d 0h 0m 0s	1964840900	1370085360	0.000	0	0
All time	1964840900	1370085360	0.000	0	0

Spouts (All time)

Id	Parallelism	Emitted	Transferred	Complete latency (ms)	Acked	Failed	Last error
word	50	1370084860	1370085360	0.000	0	0

Bolts (All time)

Id	Parallelism	Emitted	Transferred	Process latency (ms)	Acked	Failed	Last error
__acker	10	0	0	0.000	0	0
print	60	594756040	0	0.009	594756340	0

[Nathan Marz]

Are you using an unreliable spout? (a spout that doesn't tag emitted tuples with a message id) In that case, tuple trees won't be tracked and spouts will never have ack called on them. This explanation is consistent with the numbers in your screenshot.

[Min Zhou]

Is the acked number of topology stats the sum of acked numbers of all spouts and bolts?

[Nathan Marz]

No it's just the number acked on the spout. So if you're using an unreliable spout it will be 0.

[Min Zhou]

Thanks!

So under what kinds of conditions would cause a long latency of a spout? 

[songhe yang]

From the wiki, i see that "The first is to set Config.TOPOLOGY_ACKERS
to 0、In this case, Storm will call the ack method on the spout
immediately after the spout emits a tuple. ", it means that spout will
call the method ack, but it will not track the tuple tree.

On Dec 28, 5:23 pm, Nathan Marz <nathan.m...@gmail.com> wrote:
> Are you using an unreliable spout? (a spout that doesn't tag emitted tuples with a message id) In that case, tuple trees won't be tracked and spouts will never have ack called on them. This explanation is consistent with the numbers in your screenshot.
>

> On Dec 28, 2011, at 1:17 AM, Min Zhou <coderp...@gmail.com> wrote:
>
>
>
>
>
>
>
> > Below is a instance of storm web ui.  It surprises me  the acked number of PrinterBolt is 594756340, and that number of  the total topology is 0.
> > Can you explain it?
>
> > Topology stats
> > Window      Emitted         Transferred     Complete latency (ms)   Acked   Failed
> > 10m 0s      1797746400      1280933240      0.000   0       0
> > 3h 0m 0s    1964840900      1370085360      0.000   0       0
> > 1d 0h 0m 0s         1964840900      1370085360      0.000   0       0
> > All time    1964840900      1370085360      0.000   0       0
> > Spouts (All time)
> > Id  Parallelism     Emitted         Transferred     Complete latency (ms)   Acked   Failed  Last error
> > word        50      1370084860      1370085360      0.000   0       0
> > Bolts (All time)
> > Id  Parallelism     Emitted         Transferred     Process latency (ms)    Acked   Failed  Last error
> > __acker     10      0       0       0.000   0       0
> > print       60      594756040       0       0.009   594756340       0
>

> > On Wed, Dec 28, 2011 at 3:58 PM, Nathan Marz <nathan.m...@gmail.com> wrote:
> > The complete latency is the time from the spout emitting a tuple to that tuple being acked on the spout. So it tracks the time for the whole tuple tree to be processed.
>
> > If you dive into the spout component in the UI, you'll see that a lot of the emitted/transferred is on the __ack* stream. This is the spout communicating with the ackers which take care of tracking the tuple trees.
>

[Min Zhou]

Hi songhe ,

Actually, I set the acker number into 10. And however, you are right that spout will directly call ack-spout-msg if acker is 0.   I was using a unreliable spout as Nathan mentioned. 

The other question is under what kinds of conditions would cause a long latency of a spout? 

Thanks,

Min

[Nathan Marz]

Hi Min,

See my answer here: http://groups.google.com/group/storm-user/browse_thread/thread/2d801dd33c0c175b

-Nathan