Twitter topology running really slow on storm cluster

[Palak Shah <sp...@gmail.com>]

Hi,

I am trying to run the following example on my storm cluster -
https://github.com/davidkiss/storm-twitter-word-count

It runs perfectly on localcluster and displays the top 20 trending words
every 10 seconds. But when I submitted it to storm cluster, it only
processes about 20 words in 10 minutes. Does anyone know the reason for
this?

Below are the nimbus and supervisor logs at 12:19. The worker logs are
normal and show the spout reading tuples at the expected rate -

What is happening here? Why are the values I see in worker logs not
reflected in the UI?

Thanks,
Palak

--------------------------------------------------------------------------------------------------------------------------------------------------------
NIMBUS -
2014-10-28 12:19:05 b.s.d.nimbus [INFO] Delaying event :remove for 1 secs
for palak-2-1414478789
2014-10-28 12:19:05 b.s.d.nimbus [INFO] Updated palak-2-1414478789 with
status {:type :killed, :kill-time-secs 1}
2014-10-28 12:19:11 b.s.d.nimbus [INFO] Killing topology: palak-2-1414478789
2014-10-28 12:19:11 b.s.d.nimbus [INFO] Cleaning up palak-2-1414478789
2014-10-28 12:19:13 b.s.d.nimbus [INFO] Delaying event :remove for 1 secs
for palak1-3-1414478877
2014-10-28 12:19:13 b.s.d.nimbus [INFO] Updated palak1-3-1414478877 with
status {:type :killed, :kill-time-secs 1}
2014-10-28 12:19:21 b.s.d.nimbus [INFO] Killing topology:
palak1-3-1414478877
2014-10-28 12:19:21 b.s.d.nimbus [INFO] Cleaning up palak1-3-1414478877
2014-10-28 12:26:19 b.s.d.nimbus [INFO] Uploading file from client to
/tmp/stormtmp/nimbus/inbox/stormjar-59effea3-1946-49c3-8c7d-659f29488fa7.jar
2014-10-28 12:26:19 b.s.d.nimbus [INFO] Finished uploading file from
client:
/tmp/stormtmp/nimbus/inbox/stormjar-59effea3-1946-49c3-8c7d-659f29488fa7.jar
2014-10-28 12:26:19 b.s.d.nimbus [INFO] Received topology submission for
palak with conf {"topology.max.task.parallelism" nil,
"topology.acker.executors" nil, "topology.kryo.register" nil,
"topology.kryo.decorators" (), "topology.name" "palak", "storm.id"
"palak-4-1414479379", "topology.message.timeout.secs" 120}
2014-10-28 12:26:19 b.s.d.nimbus [INFO] Activating palak: palak-4-1414479379
2014-10-28 12:26:19 b.s.s.EvenScheduler [INFO] Available slots:
(["e2e7d69c-4be3-488e-8c4b-e18d402bbf52" 6703]
["e2e7d69c-4be3-488e-8c4b-e18d402bbf52" 6702]
["e2e7d69c-4be3-488e-8c4b-e18d402bbf52" 6701]
["e2e7d69c-4be3-488e-8c4b-e18d402bbf52" 6700]
["b80a7d21-2d5a-43e6-8fab-b27b61b66394" 6703]
["b80a7d21-2d5a-43e6-8fab-b27b61b66394" 6702]
["b80a7d21-2d5a-43e6-8fab-b27b61b66394" 6701]
["b80a7d21-2d5a-43e6-8fab-b27b61b66394" 6700]
["4d1a0969-d295-405f-bf2d-052fdc28c8b9" 6703]
["4d1a0969-d295-405f-bf2d-052fdc28c8b9" 6702]
["4d1a0969-d295-405f-bf2d-052fdc28c8b9" 6701]
["4d1a0969-d295-405f-bf2d-052fdc28c8b9" 6700])
2014-10-28 12:26:19 b.s.d.nimbus [INFO] Setting new assignment for topology
id palak-4-1414479379:
#backtype.storm.daemon.common.Assignment{:master-code-dir
"/tmp/stormtmp/nimbus/stormdist/palak-4-1414479379", :node->host
{"e2e7d69c-4be3-488e-8c4b-e18d402bbf52" "stormMaster"},
:executor->node+port {[3 3] ["e2e7d69c-4be3-488e-8c4b-e18d402bbf52" 6703],
[5 5] ["e2e7d69c-4be3-488e-8c4b-e18d402bbf52" 6703], [4 4]
["e2e7d69c-4be3-488e-8c4b-e18d402bbf52" 6703], [2 2]
["e2e7d69c-4be3-488e-8c4b-e18d402bbf52" 6703], [1 1]
["e2e7d69c-4be3-488e-8c4b-e18d402bbf52" 6703]}, :executor->start-time-secs
{[1 1] 1414479379, [2 2] 1414479379, [4 4] 1414479379, [5 5] 1414479379, [3
3] 1414479379}}
2014-10-28 13:01:26 b.s.d.nimbus [INFO] Cleaning inbox ... deleted:
stormjar-86d4f93f-6c24-4e2b-bee4-33daa590ac6f.jar
2014-10-28 13:21:26 b.s.d.nimbus [INFO] Cleaning inbox ... deleted:
stormjar-22e5e3ea-846a-4654-b520-fce89ebece73.jar
2014-10-28 13:21:26 b.s.d.nimbus [INFO] Cleaning inbox ... deleted:
stormjar-07f9c317-459c-41a1-835f-374ebf0b2e07.jar
2014-10-28 13:31:26 b.s.d.nimbus [INFO] Cleaning inbox ... deleted:
stormjar-59effea3-1946-49c3-8c7d-659f29488fa7.jar

--------------------------------------------------------------------------------------------------------------------------------------------------------
SUPERVISOR -
2014-10-28 12:17:58 b.s.d.supervisor [INFO]
1bd9c929-2b0f-4934-a45c-d682b6eaadee still hasn't started
2014-10-28 12:17:58 b.s.d.supervisor [INFO]
1bd9c929-2b0f-4934-a45c-d682b6eaadee still hasn't started
2014-10-28 12:17:59 b.s.d.supervisor [INFO]
1bd9c929-2b0f-4934-a45c-d682b6eaadee still hasn't started
2014-10-28 12:17:59 b.s.d.supervisor [INFO]
1bd9c929-2b0f-4934-a45c-d682b6eaadee still hasn't started
2014-10-28 12:18:00 b.s.d.supervisor [INFO]
1bd9c929-2b0f-4934-a45c-d682b6eaadee still hasn't started
2014-10-28 12:18:00 b.s.d.supervisor [INFO]
1bd9c929-2b0f-4934-a45c-d682b6eaadee still hasn't started
2014-10-28 12:18:01 b.s.d.supervisor [INFO]
1bd9c929-2b0f-4934-a45c-d682b6eaadee still hasn't started
2014-10-28 12:18:01 b.s.d.supervisor [INFO]
1bd9c929-2b0f-4934-a45c-d682b6eaadee still hasn't started
2014-10-28 12:18:02 b.s.d.supervisor [INFO]
1bd9c929-2b0f-4934-a45c-d682b6eaadee still hasn't started
2014-10-28 12:19:11 b.s.d.supervisor [INFO] Removing code for storm id
palak-2-1414478789
2014-10-28 12:19:11 b.s.d.supervisor [INFO] Shutting down and clearing
state for id 247985d8-9ae4-4d23-a8b6-182437ac3874. Current supervisor time:
1414478951. State: :disallowed, Heartbeat:
#backtype.storm.daemon.common.WorkerHeartbeat{:time-secs 1414478950,
:storm-id "palak-2-1414478789", :executors #{[2 2] [3 3] [4 4] [5 5] [-1
-1] [1 1]}, :port 6703}
2014-10-28 12:19:11 b.s.d.supervisor [INFO] Shutting down
e2e7d69c-4be3-488e-8c4b-e18d402bbf52:247985d8-9ae4-4d23-a8b6-182437ac3874
2014-10-28 12:19:11 b.s.d.supervisor [INFO] Shut down
e2e7d69c-4be3-488e-8c4b-e18d402bbf52:247985d8-9ae4-4d23-a8b6-182437ac3874
2014-10-28 12:19:21 b.s.d.supervisor [INFO] Removing code for storm id
palak1-3-1414478877
2014-10-28 12:19:21 b.s.d.supervisor [INFO] Shutting down and clearing
state for id 1bd9c929-2b0f-4934-a45c-d682b6eaadee. Current supervisor time:
1414478961. State: :disallowed, Heartbeat:
#backtype.storm.daemon.common.WorkerHeartbeat{:time-secs 1414478960,
:storm-id "palak1-3-1414478877", :executors #{[2 2] [3 3] [4 4] [5 5] [-1
-1] [1 1]}, :port 6702}
2014-10-28 12:19:21 b.s.d.supervisor [INFO] Shutting down
e2e7d69c-4be3-488e-8c4b-e18d402bbf52:1bd9c929-2b0f-4934-a45c-d682b6eaadee
2014-10-28 12:19:21 b.s.d.supervisor [INFO] Shut down
e2e7d69c-4be3-488e-8c4b-e18d402bbf52:1bd9c929-2b0f-4934-a45c-d682b6eaadee

--------------------------------------------------------------------------------------------------------------------------------------------------------
WORKER -
2014-10-28 12:26:24 b.s.d.worker [INFO] Worker
98586a21-a996-4b1d-8c2f-390c23a12359 for storm palak-4-1414479379 on
e2e7d69c-4be3-488e-8c4b-e18d402bbf52:6703 has finished loading
2014-10-28 12:26:55 t.TwitterStreamImpl [INFO] Connection established.
2014-10-28 12:26:55 t.TwitterStreamImpl [INFO] Receiving status stream.
2014-10-28 12:28:06 STDIO [INFO] In IgnoreWordsBolt : Word = berdiam lang =
id
2014-10-28 12:28:06 STDIO [INFO] In IgnoreWordsBolt : Word = pening lang =
id
2014-10-28 12:28:06 STDIO [INFO] In WordCounterBolt : Word = berdiam
2014-10-28 12:28:06 c.k.s.WordCounterBolt [INFO] Word count: 1
2014-10-28 12:28:06 STDIO [INFO] In IgnoreWordsBolt : Word = palak lang = id
2014-10-28 12:28:06 c.k.s.WordCounterBolt [INFO] top - berdiam>1
2014-10-28 12:28:06 STDIO [INFO] In WordCounterBolt : Word = pening
2014-10-28 12:28:06 STDIO [INFO] In IgnoreWordsBolt : Word = sakitny lang =
id
2014-10-28 12:28:06 STDIO [INFO] In WordCounterBolt : Word = palak
2014-10-28 12:28:06 STDIO [INFO] In IgnoreWordsBolt : Word = badan lang = id
2014-10-28 12:28:06 STDIO [INFO] In WordCounterBolt : Word = sakitny
2014-10-28 12:28:06 STDIO [INFO] In IgnoreWordsBolt : Word = gunting lang =
id
2014-10-28 12:28:06 STDIO [INFO] In WordCounterBolt : Word = badan
2014-10-28 12:28:06 STDIO [INFO] In IgnoreWordsBolt : Word = crtsewir7e
lang = id
2014-10-28 12:28:06 STDIO [INFO] In WordCounterBolt : Word = gunting
2014-10-28 12:28:06 STDIO [INFO] In WordCounterBolt : Word = crtsewir7e
2014-10-28 12:29:11 STDIO [INFO] In IgnoreWordsBolt : Word = ariirijal lang
= id
2014-10-28 12:29:11 STDIO [INFO] In IgnoreWordsBolt : Word = palak lang = id
2014-10-28 12:29:11 STDIO [INFO] In WordCounterBolt : Word = ariirijal
2014-10-28 12:29:11 c.k.s.WordCounterBolt [INFO] Word count: 8
2014-10-28 12:29:11 STDIO [INFO] In IgnoreWordsBolt : Word = maneh lang = id
2014-10-28 12:29:11 c.k.s.WordCounterBolt [INFO] top - berdiam>1
2014-10-28 12:29:11 STDIO [INFO] In WordCounterBolt : Word = palak
2014-10-28 12:29:11 STDIO [INFO] In IgnoreWordsBolt : Word = kelamin lang =
id
2014-10-28 12:29:11 STDIO [INFO] In WordCounterBolt : Word = maneh
2014-10-28 12:29:11 STDIO [INFO] In IgnoreWordsBolt : Word = jantan lang =
id
2014-10-28 12:29:11 STDIO [INFO] In WordCounterBolt : Word = kelamin
2014-10-28 12:29:11 STDIO [INFO] In WordCounterBolt : Word = jantan
2014-10-28 12:29:57 STDIO [INFO] In IgnoreWordsBolt : Word = fatinsyazaa
lang = en
2014-10-28 12:29:57 STDIO [INFO] In WordCounterBolt : Word = fatinsyazaa
2014-10-28 12:29:57 c.k.s.WordCounterBolt [INFO] Word count: 12
2014-10-28 12:29:57 STDIO [INFO] In IgnoreWordsBolt : Word = palak lang = en
2014-10-28 12:29:57 c.k.s.WordCounterBolt [INFO] top - berdiam>1
2014-10-28 12:29:57 c.k.s.WordCounterBolt [INFO] top - palak>2
2014-10-28 12:29:57 STDIO [INFO] In WordCounterBolt : Word = palak
2014-10-28 12:31:26 STDIO [INFO] In IgnoreWordsBolt : Word = panas2 lang =
id
2014-10-28 12:31:26 STDIO [INFO] In WordCounterBolt : Word = panas2
2014-10-28 12:31:26 c.k.s.WordCounterBolt [INFO] Word count: 13
2014-10-28 12:31:26 c.k.s.WordCounterBolt [INFO] top - badan>1
2014-10-28 12:31:26 STDIO [INFO] In IgnoreWordsBolt : Word = palak lang = id
2014-10-28 12:31:26 c.k.s.WordCounterBolt [INFO] top - palak>3
2014-10-28 12:31:26 STDIO [INFO] In IgnoreWordsBolt : Word = pening lang =
id
2014-10-28 12:31:26 STDIO [INFO] In WordCounterBolt : Word = palak
2014-10-28 12:31:26 STDIO [INFO] In WordCounterBolt : Word = pening
2014-10-28 12:31:26 STDIO [INFO] In IgnoreWordsBolt : Word = matrikulasix
lang = id
2014-10-28 12:31:26 STDIO [INFO] In WordCounterBolt : Word = matrikulasix
2014-10-28 12:32:20 STDIO [INFO] In IgnoreWordsBolt : Word = recipe lang =
en
2014-10-28 12:32:20 STDIO [INFO] In IgnoreWordsBolt : Word = paneer lang =
en
2014-10-28 12:32:20 STDIO [INFO] In WordCounterBolt : Word = recipe
2014-10-28 12:32:20 c.k.s.WordCounterBolt [INFO] Word count: 4
2014-10-28 12:32:20 STDIO [INFO] In IgnoreWordsBolt : Word = mushroom lang
= en
2014-10-28 12:32:20 c.k.s.WordCounterBolt [INFO] top - matrikulasix>1
2014-10-28 12:32:20 STDIO [INFO] In WordCounterBolt : Word = paneer
2014-10-28 12:32:20 STDIO [INFO] In IgnoreWordsBolt : Word = palak lang = en
2014-10-28 12:32:20 STDIO [INFO] In WordCounterBolt : Word = mushroom
2014-10-28 12:32:20 STDIO [INFO] In IgnoreWordsBolt : Word = gravy