search

AirSage / Petrel

Tools for writing, submitting, debugging, and monitoring Storm topologies in pure Python
BSD 3-Clause "New" or "Revised" License
246 stars 70 forks source link

A problem with Wordcount sample #8

Closed SmartSun closed 11 years ago

SmartSun commented 11 years ago

Hi, when i run the wordcount sample, it outputs the following messages and i don't know where goes wrong:

0 [main] INFO backtype.storm.zookeeper - Starting inprocess zookeeper at port 2000 and dir /tmp/95a62e39-5f16-4a7c-9998-916e9dcbdcad 130 [main] INFO backtype.storm.daemon.nimbus - Starting Nimbus with conf {"dev.zookeeper.path" "/tmp/dev-storm-zookeeper", "topology.tick.tuple.freq.secs" nil, "topology.fall.back.on.java.serialization" true, "zmq.linger.millis" 0, "topology.skip.missing.kryo.registrations" true, "ui.childopts" "-Xmx768m", "storm.zookeeper.session.timeout" 20000, "nimbus.reassign" true, "nimbus.monitor.freq.secs" 10, "java.library.path" "/usr/local/lib:/opt/local/lib:/usr/lib", "topology.executor.send.buffer.size" 1024, "storm.local.dir" "/tmp/a34ae2d4-a585-438d-b196-2fc566b84b38", "supervisor.worker.start.timeout.secs" 120, "topology.enable.message.timeouts" true, "nimbus.cleanup.inbox.freq.secs" 600, "nimbus.inbox.jar.expiration.secs" 3600, "topology.worker.shared.thread.pool.size" 4, "nimbus.host" "localhost", "storm.zookeeper.port" 2000, "transactional.zookeeper.port" nil, "topology.executor.receive.buffer.size" 1024, "transactional.zookeeper.servers" nil, "storm.zookeeper.root" "/storm", "supervisor.enable" true, "storm.zookeeper.servers" ["localhost"], "transactional.zookeeper.root" "/transactional", "topology.acker.executors" 1, "topology.transfer.buffer.size" 1024, "topology.worker.childopts" nil, "worker.childopts" "-Xmx768m", "supervisor.heartbeat.frequency.secs" 5, "drpc.port" 3772, "supervisor.monitor.frequency.secs" 3, "topology.receiver.buffer.size" 8, "task.heartbeat.frequency.secs" 3, "topology.tasks" nil, "topology.spout.wait.strategy" "backtype.storm.spout.SleepSpoutWaitStrategy", "topology.max.spout.pending" nil, "storm.zookeeper.retry.interval" 1000, "topology.sleep.spout.wait.strategy.time.ms" 1, "supervisor.slots.ports" [6700 6701 6702 6703], "topology.debug" false, "nimbus.task.launch.secs" 120, "nimbus.supervisor.timeout.secs" 60, "topology.message.timeout.secs" 30, "task.refresh.poll.secs" 10, "topology.workers" 1, "supervisor.childopts" "-Xmx1024m", "nimbus.thrift.port" 6627, "topology.stats.sample.rate" 0.05, "worker.heartbeat.frequency.secs" 1, "topology.acker.tasks" nil, "topology.disruptor.wait.strategy" "com.lmax.disruptor.BlockingWaitStrategy", "nimbus.task.timeout.secs" 30, "storm.zookeeper.connection.timeout" 15000, "drpc.invocations.port" 3773, "zmq.threads" 1, "storm.zookeeper.retry.times" 5, "topology.state.synchronization.timeout.secs" 60, "supervisor.worker.timeout.secs" 30, "nimbus.file.copy.expiration.secs" 600, "drpc.request.timeout.secs" 600, "storm.local.mode.zmq" false, "ui.port" 8080, "nimbus.childopts" "-Xmx1024m", "storm.cluster.mode" "local", "topology.optimize" true, "topology.max.task.parallelism" nil} 134 [main] INFO backtype.storm.daemon.nimbus - Using default scheduler 159 [main] INFO com.netflix.curator.framework.imps.CuratorFrameworkImpl - Starting 182 [main-EventThread] INFO backtype.storm.zookeeper - Zookeeper state update: :connected:none 200 [main] INFO com.netflix.curator.framework.imps.CuratorFrameworkImpl - Starting 229 [main] INFO com.netflix.curator.framework.imps.CuratorFrameworkImpl - Starting 234 [main-EventThread] INFO backtype.storm.zookeeper - Zookeeper state update: :connected:none 237 [main] INFO com.netflix.curator.framework.imps.CuratorFrameworkImpl - Starting 239 [main] INFO com.netflix.curator.framework.imps.CuratorFrameworkImpl - Starting 241 [main-EventThread] INFO backtype.storm.zookeeper - Zookeeper state update: :connected:none 243 [main] INFO com.netflix.curator.framework.imps.CuratorFrameworkImpl - Starting 273 [main] INFO backtype.storm.daemon.supervisor - Starting Supervisor with conf {"dev.zookeeper.path" "/tmp/dev-storm-zookeeper", "topology.tick.tuple.freq.secs" nil, "topology.fall.back.on.java.serialization" true, "zmq.linger.millis" 0, "topology.skip.missing.kryo.registrations" true, "ui.childopts" "-Xmx768m", "storm.zookeeper.session.timeout" 20000, "nimbus.reassign" true, "nimbus.monitor.freq.secs" 10, "java.library.path" "/usr/local/lib:/opt/local/lib:/usr/lib", "topology.executor.send.buffer.size" 1024, "storm.local.dir" "/tmp/e330144f-c194-462b-9089-abfed77b3d8d", "supervisor.worker.start.timeout.secs" 120, "topology.enable.message.timeouts" true, "nimbus.cleanup.inbox.freq.secs" 600, "nimbus.inbox.jar.expiration.secs" 3600, "topology.worker.shared.thread.pool.size" 4, "nimbus.host" "localhost", "storm.zookeeper.port" 2000, "transactional.zookeeper.port" nil, "topology.executor.receive.buffer.size" 1024, "transactional.zookeeper.servers" nil, "storm.zookeeper.root" "/storm", "supervisor.enable" true, "storm.zookeeper.servers" ["localhost"], "transactional.zookeeper.root" "/transactional", "topology.acker.executors" 1, "topology.transfer.buffer.size" 1024, "topology.worker.childopts" nil, "worker.childopts" "-Xmx768m", "supervisor.heartbeat.frequency.secs" 5, "drpc.port" 3772, "supervisor.monitor.frequency.secs" 3, "topology.receiver.buffer.size" 8, "task.heartbeat.frequency.secs" 3, "topology.tasks" nil, "topology.spout.wait.strategy" "backtype.storm.spout.SleepSpoutWaitStrategy", "topology.max.spout.pending" nil, "storm.zookeeper.retry.interval" 1000, "topology.sleep.spout.wait.strategy.time.ms" 1, "supervisor.slots.ports" (1 2 3), "topology.debug" false, "nimbus.task.launch.secs" 120, "nimbus.supervisor.timeout.secs" 60, "topology.message.timeout.secs" 30, "task.refresh.poll.secs" 10, "topology.workers" 1, "supervisor.childopts" "-Xmx1024m", "nimbus.thrift.port" 6627, "topology.stats.sample.rate" 0.05, "worker.heartbeat.frequency.secs" 1, "topology.acker.tasks" nil, "topology.disruptor.wait.strategy" "com.lmax.disruptor.BlockingWaitStrategy", "nimbus.task.timeout.secs" 30, "storm.zookeeper.connection.timeout" 15000, "drpc.invocations.port" 3773, "zmq.threads" 1, "storm.zookeeper.retry.times" 5, "topology.state.synchronization.timeout.secs" 60, "supervisor.worker.timeout.secs" 30, "nimbus.file.copy.expiration.secs" 600, "drpc.request.timeout.secs" 600, "storm.local.mode.zmq" false, "ui.port" 8080, "nimbus.childopts" "-Xmx1024m", "storm.cluster.mode" "local", "topology.optimize" true, "topology.max.task.parallelism" nil} 283 [main] INFO com.netflix.curator.framework.imps.CuratorFrameworkImpl - Starting 293 [main-EventThread] INFO backtype.storm.zookeeper - Zookeeper state update: :connected:none 296 [main] INFO com.netflix.curator.framework.imps.CuratorFrameworkImpl - Starting 324 [main] INFO backtype.storm.daemon.supervisor - Starting supervisor with id 2107a707-c423-4430-a362-1ede09b844df at host storm_nimbus_fy1 329 [main] INFO backtype.storm.daemon.supervisor - Starting Supervisor with conf {"dev.zookeeper.path" "/tmp/dev-storm-zookeeper", "topology.tick.tuple.freq.secs" nil, "topology.fall.back.on.java.serialization" true, "zmq.linger.millis" 0, "topology.skip.missing.kryo.registrations" true, "ui.childopts" "-Xmx768m", "storm.zookeeper.session.timeout" 20000, "nimbus.reassign" true, "nimbus.monitor.freq.secs" 10, "java.library.path" "/usr/local/lib:/opt/local/lib:/usr/lib", "topology.executor.send.buffer.size" 1024, "storm.local.dir" "/tmp/efb95297-e2e4-4aee-8e87-0a62231676b4", "supervisor.worker.start.timeout.secs" 120, "topology.enable.message.timeouts" true, "nimbus.cleanup.inbox.freq.secs" 600, "nimbus.inbox.jar.expiration.secs" 3600, "topology.worker.shared.thread.pool.size" 4, "nimbus.host" "localhost", "storm.zookeeper.port" 2000, "transactional.zookeeper.port" nil, "topology.executor.receive.buffer.size" 1024, "transactional.zookeeper.servers" nil, "storm.zookeeper.root" "/storm", "supervisor.enable" true, "storm.zookeeper.servers" ["localhost"], "transactional.zookeeper.root" "/transactional", "topology.acker.executors" 1, "topology.transfer.buffer.size" 1024, "topology.worker.childopts" nil, "worker.childopts" "-Xmx768m", "supervisor.heartbeat.frequency.secs" 5, "drpc.port" 3772, "supervisor.monitor.frequency.secs" 3, "topology.receiver.buffer.size" 8, "task.heartbeat.frequency.secs" 3, "topology.tasks" nil, "topology.spout.wait.strategy" "backtype.storm.spout.SleepSpoutWaitStrategy", "topology.max.spout.pending" nil, "storm.zookeeper.retry.interval" 1000, "topology.sleep.spout.wait.strategy.time.ms" 1, "supervisor.slots.ports" (4 5 6), "topology.debug" false, "nimbus.task.launch.secs" 120, "nimbus.supervisor.timeout.secs" 60, "topology.message.timeout.secs" 30, "task.refresh.poll.secs" 10, "topology.workers" 1, "supervisor.childopts" "-Xmx1024m", "nimbus.thrift.port" 6627, "topology.stats.sample.rate" 0.05, "worker.heartbeat.frequency.secs" 1, "topology.acker.tasks" nil, "topology.disruptor.wait.strategy" "com.lmax.disruptor.BlockingWaitStrategy", "nimbus.task.timeout.secs" 30, "storm.zookeeper.connection.timeout" 15000, "drpc.invocations.port" 3773, "zmq.threads" 1, "storm.zookeeper.retry.times" 5, "topology.state.synchronization.timeout.secs" 60, "supervisor.worker.timeout.secs" 30, "nimbus.file.copy.expiration.secs" 600, "drpc.request.timeout.secs" 600, "storm.local.mode.zmq" false, "ui.port" 8080, "nimbus.childopts" "-Xmx1024m", "storm.cluster.mode" "local", "topology.optimize" true, "topology.max.task.parallelism" nil} 331 [main] INFO com.netflix.curator.framework.imps.CuratorFrameworkImpl - Starting 334 [main-EventThread] INFO backtype.storm.zookeeper - Zookeeper state update: :connected:none 336 [main] INFO com.netflix.curator.framework.imps.CuratorFrameworkImpl - Starting 345 [main] INFO backtype.storm.daemon.supervisor - Starting supervisor with id 12df2d3c-22f7-4a31-a7ae-1c81c94fbf61 at host storm_nimbus_fy1 381 [main] INFO backtype.storm.daemon.nimbus - Received topology submission for test topology with conf {"storm.id" "test topology-1-1357301828", "nimbus.host" "localhost", "topology.acker.executors" 1, "topology.kryo.decorators" (), "topology.name" "test topology", "topology.debug" true, "topology.kryo.register" nil, "topology.workers" 1, "supervisor.worker.timeout.secs" 60, "topology.max.task.parallelism" 1, "petrel.host" "storm_nimbus_fy1", "petrel.user" "root"} 401 [main] INFO backtype.storm.daemon.nimbus - Activating test topology: test topology-1-1357301828 501 [main] INFO backtype.storm.scheduler.EvenScheduler - Available slots: (["12df2d3c-22f7-4a31-a7ae-1c81c94fbf61" 4] ["12df2d3c-22f7-4a31-a7ae-1c81c94fbf61" 5] ["12df2d3c-22f7-4a31-a7ae-1c81c94fbf61" 6] ["2107a707-c423-4430-a362-1ede09b844df" 1] ["2107a707-c423-4430-a362-1ede09b844df" 2] ["2107a707-c423-4430-a362-1ede09b844df" 3]) 543 [main] INFO backtype.storm.daemon.nimbus - Setting new assignment for topology id test topology-1-1357301828: #backtype.storm.daemon.common.Assignment{:master-code-dir "/tmp/a34ae2d4-a585-438d-b196-2fc566b84b38/nimbus/stormdist/test topology-1-1357301828", :node->host {"12df2d3c-22f7-4a31-a7ae-1c81c94fbf61" "storm_nimbus_fy1"}, :executor->node+port {[3 3] ["12df2d3c-22f7-4a31-a7ae-1c81c94fbf61" 4], [2 2] ["12df2d3c-22f7-4a31-a7ae-1c81c94fbf61" 4], [1 1] ["12df2d3c-22f7-4a31-a7ae-1c81c94fbf61" 4], [4 4] ["12df2d3c-22f7-4a31-a7ae-1c81c94fbf61" 4]}, :executor->start-time-secs {[4 4] 1357301828, [1 1] 1357301828, [2 2] 1357301828, [3 3] 1357301828}} Topology is running. Press ^C to stop it. 1219 [Thread-2] INFO backtype.storm.daemon.nimbus - Setting new assignment for topology id test topology-1-1357301828: #backtype.storm.daemon.common.Assignment{:master-code-dir "/tmp/a34ae2d4-a585-438d-b196-2fc566b84b38/nimbus/stormdist/test topology-1-1357301828", :node->host {"12df2d3c-22f7-4a31-a7ae-1c81c94fbf61" "storm_nimbus_fy1"}, :executor->node+port {[3 3] ["12df2d3c-22f7-4a31-a7ae-1c81c94fbf61" 4], [4 4] ["12df2d3c-22f7-4a31-a7ae-1c81c94fbf61" 4], [2 2] ["12df2d3c-22f7-4a31-a7ae-1c81c94fbf61" 4], [1 1] ["12df2d3c-22f7-4a31-a7ae-1c81c94fbf61" 4]}, :executor->start-time-secs {[4 4] 1357301829, [1 1] 1357301829, [2 2] 1357301829, [3 3] 1357301829}} 1344 [Thread-8] INFO backtype.storm.daemon.supervisor - Downloading code for storm id test topology-1-1357301828 from /tmp/a34ae2d4-a585-438d-b196-2fc566b84b38/nimbus/stormdist/test topology-1-1357301828 1631 [Thread-8] INFO backtype.storm.daemon.supervisor - Extracting resources from jar at topology.jar to /tmp/efb95297-e2e4-4aee-8e87-0a62231676b4/supervisor/stormdist/test+topology-1-1357301828/resources 1641 [Thread-8] INFO backtype.storm.daemon.supervisor - Finished downloading code for storm id test topology-1-1357301828 from /tmp/a34ae2d4-a585-438d-b196-2fc566b84b38/nimbus/stormdist/test topology-1-1357301828 1664 [Thread-9] INFO backtype.storm.daemon.supervisor - Launching worker with assignment #backtype.storm.daemon.supervisor.LocalAssignment{:storm-id "test topology-1-1357301828", :executors ([3 3] [4 4] [2 2] [1 1])} for this supervisor 12df2d3c-22f7-4a31-a7ae-1c81c94fbf61 on port 4 with id 5fbe440b-311f-4d5e-893d-b528f77e3a7c 1668 [Thread-9] INFO backtype.storm.daemon.worker - Launching worker for test topology-1-1357301828 on 12df2d3c-22f7-4a31-a7ae-1c81c94fbf61:4 with id 5fbe440b-311f-4d5e-893d-b528f77e3a7c and conf {"dev.zookeeper.path" "/tmp/dev-storm-zookeeper", "topology.tick.tuple.freq.secs" nil, "topology.fall.back.on.java.serialization" true, "zmq.linger.millis" 0, "topology.skip.missing.kryo.registrations" true, "ui.childopts" "-Xmx768m", "storm.zookeeper.session.timeout" 20000, "nimbus.reassign" true, "nimbus.monitor.freq.secs" 10, "java.library.path" "/usr/local/lib:/opt/local/lib:/usr/lib", "topology.executor.send.buffer.size" 1024, "storm.local.dir" "/tmp/efb95297-e2e4-4aee-8e87-0a62231676b4", "supervisor.worker.start.timeout.secs" 120, "topology.enable.message.timeouts" true, "nimbus.cleanup.inbox.freq.secs" 600, "nimbus.inbox.jar.expiration.secs" 3600, "topology.worker.shared.thread.pool.size" 4, "nimbus.host" "localhost", "storm.zookeeper.port" 2000, "transactional.zookeeper.port" nil, "topology.executor.receive.buffer.size" 1024, "transactional.zookeeper.servers" nil, "storm.zookeeper.root" "/storm", "supervisor.enable" true, "storm.zookeeper.servers" ["localhost"], "transactional.zookeeper.root" "/transactional", "topology.acker.executors" 1, "topology.transfer.buffer.size" 1024, "topology.worker.childopts" nil, "worker.childopts" "-Xmx768m", "supervisor.heartbeat.frequency.secs" 5, "drpc.port" 3772, "supervisor.monitor.frequency.secs" 3, "topology.receiver.buffer.size" 8, "task.heartbeat.frequency.secs" 3, "topology.tasks" nil, "topology.spout.wait.strategy" "backtype.storm.spout.SleepSpoutWaitStrategy", "topology.max.spout.pending" nil, "storm.zookeeper.retry.interval" 1000, "topology.sleep.spout.wait.strategy.time.ms" 1, "supervisor.slots.ports" (4 5 6), "topology.debug" false, "nimbus.task.launch.secs" 120, "nimbus.supervisor.timeout.secs" 60, "topology.message.timeout.secs" 30, "task.refresh.poll.secs" 10, "topology.workers" 1, "supervisor.childopts" "-Xmx1024m", "nimbus.thrift.port" 6627, "topology.stats.sample.rate" 0.05, "worker.heartbeat.frequency.secs" 1, "topology.acker.tasks" nil, "topology.disruptor.wait.strategy" "com.lmax.disruptor.BlockingWaitStrategy", "nimbus.task.timeout.secs" 30, "storm.zookeeper.connection.timeout" 15000, "drpc.invocations.port" 3773, "zmq.threads" 1, "storm.zookeeper.retry.times" 5, "topology.state.synchronization.timeout.secs" 60, "supervisor.worker.timeout.secs" 30, "nimbus.file.copy.expiration.secs" 600, "drpc.request.timeout.secs" 600, "storm.local.mode.zmq" false, "ui.port" 8080, "nimbus.childopts" "-Xmx1024m", "storm.cluster.mode" "local", "topology.optimize" true, "topology.max.task.parallelism" nil} 1668 [Thread-9] INFO com.netflix.curator.framework.imps.CuratorFrameworkImpl - Starting 1671 [Thread-9-EventThread] INFO backtype.storm.zookeeper - Zookeeper state update: :connected:none 1673 [Thread-9] INFO com.netflix.curator.framework.imps.CuratorFrameworkImpl - Starting 1812 [Thread-9] INFO backtype.storm.daemon.executor - Loading executor count:[2 2] 1816 [Thread-9] INFO backtype.storm.daemon.task - Emitting: count __system ["startup"] 1817 [Thread-9] INFO backtype.storm.daemon.executor - Loaded executor tasks count:[2 2] 1826 [Thread-9] INFO backtype.storm.daemon.executor - Preparing bolt count:(2) 1870 [Thread-9] ERROR backtype.storm.daemon.executor - java.lang.RuntimeException: Pipe to subprocess seems to be broken! No output read. Shell Process Exception:

at backtype.storm.utils.ShellProcess.readString(ShellProcess.java:100)
at backtype.storm.utils.ShellProcess.readMessage(ShellProcess.java:62)
at backtype.storm.utils.ShellProcess.launch(ShellProcess.java:43)
at backtype.storm.task.ShellBolt.prepare(ShellBolt.java:79)
at backtype.storm.daemon.executor$fn__4036.invoke(executor.clj:531)
at clojure.lang.MultiFn.invoke(MultiFn.java:167)
at backtype.storm.daemon.executor$mk_executor$fn__3915.invoke(executor.clj:249)
at backtype.storm.daemon.executor$mk_executor.invoke(executor.clj:248)
at backtype.storm.daemon.worker$fn__4324$exec_fn__1207__auto____4325$iter__4330__4334$fn__4335.invoke(worker.clj:353)
at clojure.lang.LazySeq.sval(LazySeq.java:42)
at clojure.lang.LazySeq.seq(LazySeq.java:60)
at clojure.lang.RT.seq(RT.java:473)
at clojure.core$seq.invoke(core.clj:133)
at clojure.core$dorun.invoke(core.clj:2725)
at clojure.core$doall.invoke(core.clj:2741)
at backtype.storm.daemon.worker$fn__4324$exec_fn__1207__auto____4325.invoke(worker.clj:353)
at clojure.lang.AFn.applyToHelper(AFn.java:185)
at clojure.lang.AFn.applyTo(AFn.java:151)
at clojure.core$apply.invoke(core.clj:601)
at backtype.storm.daemon.worker$fn__4324$mk_worker__4380.doInvoke(worker.clj:322)
at clojure.lang.RestFn.invoke(RestFn.java:512)
at backtype.storm.daemon.supervisor$fn__4783.invoke(supervisor.clj:457)
at clojure.lang.MultiFn.invoke(MultiFn.java:177)
at backtype.storm.daemon.supervisor$sync_processes$iter__4660__4664$fn__4665.invoke(supervisor.clj:247)
at clojure.lang.LazySeq.sval(LazySeq.java:42)
at clojure.lang.LazySeq.seq(LazySeq.java:60)
at clojure.lang.RT.seq(RT.java:473)
at clojure.core$seq.invoke(core.clj:133)
at clojure.core$dorun.invoke(core.clj:2725)
at clojure.core$doall.invoke(core.clj:2741)
at backtype.storm.daemon.supervisor$sync_processes.invoke(supervisor.clj:235)
at clojure.lang.AFn.applyToHelper(AFn.java:161)
at clojure.lang.AFn.applyTo(AFn.java:151)
at clojure.core$apply.invoke(core.clj:603)
at clojure.core$partial$fn__4070.doInvoke(core.clj:2343)
at clojure.lang.RestFn.invoke(RestFn.java:397)
at backtype.storm.event$event_manager$fn__2484.invoke(event.clj:24)
at clojure.lang.AFn.run(AFn.java:24)
at java.lang.Thread.run(Thread.java:722)

1888 [Thread-9] INFO backtype.storm.util - Halting process: ("Worker died") Error on or near line 24; exiting with status 1

barrywhart commented 11 years ago

It looks like one or more of the Python processes crashed shortly after startup -- I don't see any output from the spout.

When a local topology run fails, search your log for this setting: "storm.local.dir". For the log you sent, this was:

"storm.local.dir" "/tmp/a34ae2d4-a585-438d-b196-2fc566b84b38"

Look in this directory and its subdirectories see if you can should find some Petrel log files. This may help you figure out the problem.

Petrel log file names have the following format:

petrel_.log

Let me know what you find. I have to go to a meeting in a few minutes but will be on email later today.

This makes me realize I should add some notes to the Petrel documentation about the directory structure of a running topology...

SmartSun commented 11 years ago

i reached storm.local.dir and found what happens: i don't install virtualenv