You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@storm.apache.org by "ryan.jin (JIRA)" <ji...@apache.org> on 2014/12/21 10:24:13 UTC
[jira] [Updated] (STORM-597) spout not receve the message acker
[ https://issues.apache.org/jira/browse/STORM-597?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
ryan.jin updated STORM-597:
---------------------------
Description:
I have one spout and one bolt.
The program always runs greate. But sometimes the spout do not receive the ack and at debug mode the bolt have do the ack correctly.
LOG:
###1 Normally the last line says the spout has received acker.
2014-12-21 02:46:15 c.s.b.s.b.s.BaseTaskScheduleSpout [INFO] check time begin at :2014-12-21 02:46:15 end
2014-12-21 02:46:15 b.s.d.task [INFO] Emitting: task-spout default [1419100920000, 1419100980000]
2014-12-21 02:46:15 b.s.d.task [INFO] Emitting: task-spout __ack_init [3492883688624743717 -7308083944080730032 10]
2014-12-21 02:46:15 b.s.d.executor [INFO] Processing received message source: task-spout:10, stream: default, id: {3492883688624743717=-7308083944080730032}, [1419100920000, 1419100980000]
2014-12-21 02:46:15 b.s.d.executor [INFO] Processing received message source: task-spout:10, stream: __ack_init, id: {}, [3492883688624743717 -7308083944080730032 10]
2014-12-21 02:46:15 c.s.b.s.b.b.HbaseTaskScheduleBolt [INFO] table prmt_user_tracer scan 0 cost 3 ms time 2014-12-21 02:42:00 to 2014-12-21 02:43:00 row null to null
2014-12-21 02:46:15 c.s.b.s.b.b.HbaseTaskScheduleBolt [INFO] table prmt_user_tracer run final success
2014-12-21 02:46:15 b.s.d.task [INFO] Emitting: task-bolt __ack_ack [3492883688624743717 -7308083944080730032]
2014-12-21 02:46:15 b.s.d.executor [INFO] Processing received message source: task-bolt:7, stream: __ack_ack, id: {}, [3492883688624743717 -7308083944080730032]
2014-12-21 02:46:15 b.s.d.task [INFO] Emitting direct: 10; __acker __ack_ack [3492883688624743717]
2014-12-21 02:46:15 b.s.d.executor [INFO] Processing received message source: __acker:1, stream: __ack_ack, id: {}, [3492883688624743717]
2014-12-21 02:46:15 b.s.d.executor [INFO] Acking message 1419100920000,1419100980000,60000,prmt_user_tracer,true,1419101175675,from:2014-12-21 02:42:00,to:2014-12-21 02:43:00,execute:2014-12-21 02:46:15
###2.bug case, the bolt ack is stopping at "Emitting direct: 10; __acker __ack_ack [-5576733886177167329]". And the spout will not receve the ack of that message.
2014-12-21 02:45:15 c.s.b.s.b.s.BaseTaskScheduleSpout [INFO] begin put task 1419100860000,1419100920000,60000,prmt_user_tracer,true,1419101115112,from:2014-12-21 02:41:00,to:2014-12-21 02:42:00,execute:2014-12-21 02:45:15
2014-12-21 02:45:15 c.s.b.s.b.s.BaseTaskScheduleSpout [INFO] check time begin at :2014-12-21 02:45:14 end
2014-12-21 02:45:15 b.s.d.task [INFO] Emitting: task-spout default [1419100860000, 1419100920000]
2014-12-21 02:45:15 b.s.d.task [INFO] Emitting: task-spout __ack_init [-5576733886177167329 6447998047515384780 10]
2014-12-21 02:45:15 b.s.d.executor [INFO] Processing received message source: task-spout:10, stream: default, id: {-5576733886177167329=6447998047515384780}, [1419100860000, 1419100920000]
2014-12-21 02:45:15 b.s.d.executor [INFO] Processing received message source: task-spout:10, stream: __ack_init, id: {}, [-5576733886177167329 6447998047515384780 10]
2014-12-21 02:45:15 c.s.b.s.b.b.HbaseTaskScheduleBolt [INFO] table prmt_user_tracer scan 0 cost 4 ms time 2014-12-21 02:41:00 to 2014-12-21 02:42:00 row null to null
2014-12-21 02:45:15 c.s.b.s.b.b.HbaseTaskScheduleBolt [INFO] table prmt_user_tracer run final success
2014-12-21 02:45:15 b.s.d.task [INFO] Emitting: task-bolt __ack_ack [-5576733886177167329 6447998047515384780]
2014-12-21 02:45:15 b.s.d.executor [INFO] Processing received message source: task-bolt:5, stream: __ack_ack, id: {}, [-5576733886177167329 6447998047515384780]
2014-12-21 02:45:15 b.s.d.task [INFO] Emitting direct: 10; __acker __ack_ack [-5576733886177167329]
was:
I have one spout and one bolt.
The program always runs greate. But sometimes the spout do not receive the ack and at debug mode the bolt have do the ack correctly.
LOG:
1 Normally the last line says the spout has received acker.
2014-12-21 02:46:15 c.s.b.s.b.s.BaseTaskScheduleSpout [INFO] check time begin at :2014-12-21 02:46:15 end
2014-12-21 02:46:15 b.s.d.task [INFO] Emitting: task-spout default [1419100920000, 1419100980000]
2014-12-21 02:46:15 b.s.d.task [INFO] Emitting: task-spout __ack_init [3492883688624743717 -7308083944080730032 10]
2014-12-21 02:46:15 b.s.d.executor [INFO] Processing received message source: task-spout:10, stream: default, id: {3492883688624743717=-7308083944080730032}, [1419100920000, 1419100980000]
2014-12-21 02:46:15 b.s.d.executor [INFO] Processing received message source: task-spout:10, stream: __ack_init, id: {}, [3492883688624743717 -7308083944080730032 10]
2014-12-21 02:46:15 c.s.b.s.b.b.HbaseTaskScheduleBolt [INFO] table prmt_user_tracer scan 0 cost 3 ms time 2014-12-21 02:42:00 to 2014-12-21 02:43:00 row null to null
2014-12-21 02:46:15 c.s.b.s.b.b.HbaseTaskScheduleBolt [INFO] table prmt_user_tracer run final success
2014-12-21 02:46:15 b.s.d.task [INFO] Emitting: task-bolt __ack_ack [3492883688624743717 -7308083944080730032]
2014-12-21 02:46:15 b.s.d.executor [INFO] Processing received message source: task-bolt:7, stream: __ack_ack, id: {}, [3492883688624743717 -7308083944080730032]
2014-12-21 02:46:15 b.s.d.task [INFO] Emitting direct: 10; __acker __ack_ack [3492883688624743717]
2014-12-21 02:46:15 b.s.d.executor [INFO] Processing received message source: __acker:1, stream: __ack_ack, id: {}, [3492883688624743717]
2014-12-21 02:46:15 b.s.d.executor [INFO] Acking message 1419100920000,1419100980000,60000,prmt_user_tracer,true,1419101175675,from:2014-12-21 02:42:00,to:2014-12-21 02:43:00,execute:2014-12-21 02:46:15
2.bug case, the bolt ack is stopping at "Emitting direct: 10; __acker __ack_ack [-5576733886177167329]"
2014-12-21 02:45:15 c.s.b.s.b.s.BaseTaskScheduleSpout [INFO] begin put task 1419100860000,1419100920000,60000,prmt_user_tracer,true,1419101115112,from:2014-12-21 02:41:00,to:2014-12-21 02:42:00,execute:2014-12-21 02:45:15
2014-12-21 02:45:15 c.s.b.s.b.s.BaseTaskScheduleSpout [INFO] check time begin at :2014-12-21 02:45:14 end
2014-12-21 02:45:15 b.s.d.task [INFO] Emitting: task-spout default [1419100860000, 1419100920000]
2014-12-21 02:45:15 b.s.d.task [INFO] Emitting: task-spout __ack_init [-5576733886177167329 6447998047515384780 10]
2014-12-21 02:45:15 b.s.d.executor [INFO] Processing received message source: task-spout:10, stream: default, id: {-5576733886177167329=6447998047515384780}, [1419100860000, 1419100920000]
2014-12-21 02:45:15 b.s.d.executor [INFO] Processing received message source: task-spout:10, stream: __ack_init, id: {}, [-5576733886177167329 6447998047515384780 10]
2014-12-21 02:45:15 c.s.b.s.b.b.HbaseTaskScheduleBolt [INFO] table prmt_user_tracer scan 0 cost 4 ms time 2014-12-21 02:41:00 to 2014-12-21 02:42:00 row null to null
2014-12-21 02:45:15 c.s.b.s.b.b.HbaseTaskScheduleBolt [INFO] table prmt_user_tracer run final success
2014-12-21 02:45:15 b.s.d.task [INFO] Emitting: task-bolt __ack_ack [-5576733886177167329 6447998047515384780]
2014-12-21 02:45:15 b.s.d.executor [INFO] Processing received message source: task-bolt:5, stream: __ack_ack, id: {}, [-5576733886177167329 6447998047515384780]
2014-12-21 02:45:15 b.s.d.task [INFO] Emitting direct: 10; __acker __ack_ack [-5576733886177167329]
> spout not receve the message acker
> ----------------------------------
>
> Key: STORM-597
> URL: https://issues.apache.org/jira/browse/STORM-597
> Project: Apache Storm
> Issue Type: Bug
> Reporter: ryan.jin
>
> I have one spout and one bolt.
> The program always runs greate. But sometimes the spout do not receive the ack and at debug mode the bolt have do the ack correctly.
> LOG:
> ###1 Normally the last line says the spout has received acker.
> 2014-12-21 02:46:15 c.s.b.s.b.s.BaseTaskScheduleSpout [INFO] check time begin at :2014-12-21 02:46:15 end
> 2014-12-21 02:46:15 b.s.d.task [INFO] Emitting: task-spout default [1419100920000, 1419100980000]
> 2014-12-21 02:46:15 b.s.d.task [INFO] Emitting: task-spout __ack_init [3492883688624743717 -7308083944080730032 10]
> 2014-12-21 02:46:15 b.s.d.executor [INFO] Processing received message source: task-spout:10, stream: default, id: {3492883688624743717=-7308083944080730032}, [1419100920000, 1419100980000]
> 2014-12-21 02:46:15 b.s.d.executor [INFO] Processing received message source: task-spout:10, stream: __ack_init, id: {}, [3492883688624743717 -7308083944080730032 10]
> 2014-12-21 02:46:15 c.s.b.s.b.b.HbaseTaskScheduleBolt [INFO] table prmt_user_tracer scan 0 cost 3 ms time 2014-12-21 02:42:00 to 2014-12-21 02:43:00 row null to null
> 2014-12-21 02:46:15 c.s.b.s.b.b.HbaseTaskScheduleBolt [INFO] table prmt_user_tracer run final success
> 2014-12-21 02:46:15 b.s.d.task [INFO] Emitting: task-bolt __ack_ack [3492883688624743717 -7308083944080730032]
> 2014-12-21 02:46:15 b.s.d.executor [INFO] Processing received message source: task-bolt:7, stream: __ack_ack, id: {}, [3492883688624743717 -7308083944080730032]
> 2014-12-21 02:46:15 b.s.d.task [INFO] Emitting direct: 10; __acker __ack_ack [3492883688624743717]
> 2014-12-21 02:46:15 b.s.d.executor [INFO] Processing received message source: __acker:1, stream: __ack_ack, id: {}, [3492883688624743717]
> 2014-12-21 02:46:15 b.s.d.executor [INFO] Acking message 1419100920000,1419100980000,60000,prmt_user_tracer,true,1419101175675,from:2014-12-21 02:42:00,to:2014-12-21 02:43:00,execute:2014-12-21 02:46:15
> ###2.bug case, the bolt ack is stopping at "Emitting direct: 10; __acker __ack_ack [-5576733886177167329]". And the spout will not receve the ack of that message.
> 2014-12-21 02:45:15 c.s.b.s.b.s.BaseTaskScheduleSpout [INFO] begin put task 1419100860000,1419100920000,60000,prmt_user_tracer,true,1419101115112,from:2014-12-21 02:41:00,to:2014-12-21 02:42:00,execute:2014-12-21 02:45:15
> 2014-12-21 02:45:15 c.s.b.s.b.s.BaseTaskScheduleSpout [INFO] check time begin at :2014-12-21 02:45:14 end
> 2014-12-21 02:45:15 b.s.d.task [INFO] Emitting: task-spout default [1419100860000, 1419100920000]
> 2014-12-21 02:45:15 b.s.d.task [INFO] Emitting: task-spout __ack_init [-5576733886177167329 6447998047515384780 10]
> 2014-12-21 02:45:15 b.s.d.executor [INFO] Processing received message source: task-spout:10, stream: default, id: {-5576733886177167329=6447998047515384780}, [1419100860000, 1419100920000]
> 2014-12-21 02:45:15 b.s.d.executor [INFO] Processing received message source: task-spout:10, stream: __ack_init, id: {}, [-5576733886177167329 6447998047515384780 10]
> 2014-12-21 02:45:15 c.s.b.s.b.b.HbaseTaskScheduleBolt [INFO] table prmt_user_tracer scan 0 cost 4 ms time 2014-12-21 02:41:00 to 2014-12-21 02:42:00 row null to null
> 2014-12-21 02:45:15 c.s.b.s.b.b.HbaseTaskScheduleBolt [INFO] table prmt_user_tracer run final success
> 2014-12-21 02:45:15 b.s.d.task [INFO] Emitting: task-bolt __ack_ack [-5576733886177167329 6447998047515384780]
> 2014-12-21 02:45:15 b.s.d.executor [INFO] Processing received message source: task-bolt:5, stream: __ack_ack, id: {}, [-5576733886177167329 6447998047515384780]
> 2014-12-21 02:45:15 b.s.d.task [INFO] Emitting direct: 10; __acker __ack_ack [-5576733886177167329]
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)