nathanmarz/storm — Issue #107: LocalCluster.shutdown seems to return before all services are completely stopped
Author: tomdz
Created: 2012-01-23 04:50:46+00:00
State: open

The tests for [storm-esper](https://github.com/tomdz/storm-esper) create a new local cluster in the `setUp` method and shut it down (with `killTopology` followed by `shutdown`) in the `tearDown` method. Unfortunately, when the `shutdown` method returns it seems as if not everything is stopped yet (e.g. zookeeper), and so the next tests interact with the still-running services and fail because they are in the process of shutting down (sorry for the long stacktrace, this is with debug enabled):

```
INFO 2012-01-23 04:45:22,573 main backtype.storm.zookeeper Starting inprocess zookeeper at port 2181 and dir /var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//6ddda619-0f31-4624-8842-556ecdb128e1
INFO 2012-01-23 04:45:22,584 main org.apache.zookeeper.server.ZooKeeperServer Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T/6ddda619-0f31-4624-8842-556ecdb128e1/version-2 snapdir /var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T/6ddda619-0f31-4624-8842-556ecdb128e1/version-2
INFO 2012-01-23 04:45:22,598 main org.apache.zookeeper.server.NIOServerCnxn binding to port 0.0.0.0/0.0.0.0:2181
INFO 2012-01-23 04:45:22,607 main org.apache.zookeeper.server.persistence.FileTxnSnapLog Snapshotting: 0
INFO 2012-01-23 04:45:22,757 main backtype.storm.daemon.nimbus Starting Nimbus with conf {"topology.fall.back.on.java.serialization" true, "zmq.linger.millis" 0, "topology.skip.missing.kryo.registrations" true, "storm.zookeeper.session.timeout" 20000, "nimbus.reassign" true, "nimbus.monitor.freq.secs" 10, "java.library.path" "/usr/local/lib:/opt/local/lib:/usr/lib", "storm.local.dir" "/var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//e4d62f55-b330-4689-9b86-bc0f6c1e6277", "supervisor.worker.start.timeout.secs" 240, "nimbus.cleanup.inbox.freq.secs" 600, "nimbus.inbox.jar.expiration.secs" 3600, "storm.zookeeper.port" 2181, "storm.zookeeper.root" "/storm", "supervisor.enable" true, "topology.worker.childopts" nil, "worker.childopts" "-Xmx768m", "supervisor.heartbeat.frequency.secs" 5, "drpc.port" 3772, "supervisor.monitor.frequency.secs" 3, "task.heartbeat.frequency.secs" 3, "topology.max.spout.pending" nil, "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, "nimbus.task.timeout.secs" 30, "drpc.invocations.port" 3773, "zmq.threads" 1, "topology.state.synchronization.timeout.secs" 60, "supervisor.worker.timeout.secs" 30, "nimbus.file.copy.expiration.secs" 600, "storm.local.mode.zmq" false, "ui.port" 8080, "nimbus.childopts" "-Xmx1024m", "topology.ackers" 1, "storm.cluster.mode" "local", "topology.optimize" true, "topology.max.task.parallelism" nil}
INFO 2012-01-23 04:45:22,792 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:22,794 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/ sessionTimeout=10000 watcher=com.netflix.curator.ConnectionState@77bdbf9d
INFO 2012-01-23 04:45:22,805 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:22,808 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:22,812 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60772
INFO 2012-01-23 04:45:22,815 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60772
INFO 2012-01-23 04:45:22,817 SyncThread:0 org.apache.zookeeper.server.persistence.FileTxnLog Creating new log file: log.1
INFO 2012-01-23 04:45:22,835 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e1fd480000 with negotiated timeout 10000 for client /127.0.0.1:60772
INFO 2012-01-23 04:45:22,835 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e1fd480000, negotiated timeout = 10000
INFO 2012-01-23 04:45:22,838 main-EventThread backtype.storm.zookeeper Zookeeper state update: :connected:none
INFO 2012-01-23 04:45:22,857 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e1fd480000
INFO 2012-01-23 04:45:22,858 main-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
INFO 2012-01-23 04:45:22,858 main org.apache.zookeeper.ZooKeeper Session: 0x13508e1fd480000 closed
INFO 2012-01-23 04:45:22,859 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60772 which had sessionid 0x13508e1fd480000
INFO 2012-01-23 04:45:22,860 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:22,860 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/storm sessionTimeout=20000 watcher=com.netflix.curator.ConnectionState@9ad5d46
INFO 2012-01-23 04:45:22,861 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:22,861 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60773
INFO 2012-01-23 04:45:22,861 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:22,861 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60773
INFO 2012-01-23 04:45:22,862 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e1fd480001 with negotiated timeout 20000 for client /127.0.0.1:60773
INFO 2012-01-23 04:45:22,862 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e1fd480001, negotiated timeout = 20000
INFO 2012-01-23 04:45:22,898 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:22,898 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/ sessionTimeout=10000 watcher=com.netflix.curator.ConnectionState@313816e0
INFO 2012-01-23 04:45:22,898 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:22,899 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:22,899 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60774
INFO 2012-01-23 04:45:22,899 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60774
INFO 2012-01-23 04:45:22,900 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e1fd480002 with negotiated timeout 10000 for client /127.0.0.1:60774
INFO 2012-01-23 04:45:22,900 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e1fd480002, negotiated timeout = 10000
INFO 2012-01-23 04:45:22,900 main-EventThread backtype.storm.zookeeper Zookeeper state update: :connected:none
INFO 2012-01-23 04:45:22,902 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e1fd480002
INFO 2012-01-23 04:45:22,903 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60774 which had sessionid 0x13508e1fd480002
INFO 2012-01-23 04:45:22,903 main-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
INFO 2012-01-23 04:45:22,904 main org.apache.zookeeper.ZooKeeper Session: 0x13508e1fd480002 closed
INFO 2012-01-23 04:45:22,904 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:22,904 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/storm sessionTimeout=20000 watcher=com.netflix.curator.ConnectionState@252a78ee
INFO 2012-01-23 04:45:22,905 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:22,905 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:22,905 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60775
INFO 2012-01-23 04:45:22,905 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60775
INFO 2012-01-23 04:45:22,906 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e1fd480003 with negotiated timeout 20000 for client /127.0.0.1:60775
INFO 2012-01-23 04:45:22,906 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e1fd480003, negotiated timeout = 20000
INFO 2012-01-23 04:45:22,907 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:22,907 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/ sessionTimeout=10000 watcher=com.netflix.curator.ConnectionState@4eb64f2e
INFO 2012-01-23 04:45:22,908 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:22,908 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:22,908 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60776
INFO 2012-01-23 04:45:22,908 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60776
INFO 2012-01-23 04:45:22,909 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e1fd480004 with negotiated timeout 10000 for client /127.0.0.1:60776
INFO 2012-01-23 04:45:22,909 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e1fd480004, negotiated timeout = 10000
INFO 2012-01-23 04:45:22,910 main-EventThread backtype.storm.zookeeper Zookeeper state update: :connected:none
INFO 2012-01-23 04:45:22,912 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e1fd480004
INFO 2012-01-23 04:45:22,917 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60776 which had sessionid 0x13508e1fd480004
INFO 2012-01-23 04:45:22,917 main-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
INFO 2012-01-23 04:45:22,917 main org.apache.zookeeper.ZooKeeper Session: 0x13508e1fd480004 closed
INFO 2012-01-23 04:45:22,918 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:22,926 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/storm sessionTimeout=20000 watcher=com.netflix.curator.ConnectionState@1ae2b9e5
INFO 2012-01-23 04:45:22,927 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:22,928 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60777
INFO 2012-01-23 04:45:22,928 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:22,928 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60777
INFO 2012-01-23 04:45:22,929 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e1fd480005, negotiated timeout = 20000
INFO 2012-01-23 04:45:22,929 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e1fd480005 with negotiated timeout 20000 for client /127.0.0.1:60777
INFO 2012-01-23 04:45:22,958 main backtype.storm.daemon.supervisor Starting Supervisor with conf {"topology.fall.back.on.java.serialization" true, "zmq.linger.millis" 0, "topology.skip.missing.kryo.registrations" true, "storm.zookeeper.session.timeout" 20000, "nimbus.reassign" true, "nimbus.monitor.freq.secs" 10, "java.library.path" "/usr/local/lib:/opt/local/lib:/usr/lib", "storm.local.dir" "/var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//4572a18b-d469-4172-9d48-32ae6d44244e", "supervisor.worker.start.timeout.secs" 240, "nimbus.cleanup.inbox.freq.secs" 600, "nimbus.inbox.jar.expiration.secs" 3600, "storm.zookeeper.port" 2181, "storm.zookeeper.root" "/storm", "supervisor.enable" true, "topology.worker.childopts" nil, "worker.childopts" "-Xmx768m", "supervisor.heartbeat.frequency.secs" 5, "drpc.port" 3772, "supervisor.monitor.frequency.secs" 3, "task.heartbeat.frequency.secs" 3, "topology.max.spout.pending" nil, "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, "nimbus.task.timeout.secs" 30, "drpc.invocations.port" 3773, "zmq.threads" 1, "topology.state.synchronization.timeout.secs" 60, "supervisor.worker.timeout.secs" 30, "nimbus.file.copy.expiration.secs" 600, "storm.local.mode.zmq" false, "ui.port" 8080, "nimbus.childopts" "-Xmx1024m", "topology.ackers" 1, "storm.cluster.mode" "local", "topology.optimize" true, "topology.max.task.parallelism" nil}
INFO 2012-01-23 04:45:22,963 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:22,975 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/ sessionTimeout=10000 watcher=com.netflix.curator.ConnectionState@7570b819
INFO 2012-01-23 04:45:22,976 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:22,976 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60778
INFO 2012-01-23 04:45:22,976 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:22,977 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60778
INFO 2012-01-23 04:45:22,978 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e1fd480006, negotiated timeout = 10000
INFO 2012-01-23 04:45:22,979 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e1fd480006 with negotiated timeout 10000 for client /127.0.0.1:60778
INFO 2012-01-23 04:45:22,979 main-EventThread backtype.storm.zookeeper Zookeeper state update: :connected:none
INFO 2012-01-23 04:45:22,981 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e1fd480006
INFO 2012-01-23 04:45:22,986 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60778 which had sessionid 0x13508e1fd480006
INFO 2012-01-23 04:45:22,986 main-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
INFO 2012-01-23 04:45:22,987 main org.apache.zookeeper.ZooKeeper Session: 0x13508e1fd480006 closed
INFO 2012-01-23 04:45:22,987 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:22,987 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/storm sessionTimeout=20000 watcher=com.netflix.curator.ConnectionState@2d9b4fac
INFO 2012-01-23 04:45:22,988 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:22,989 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60779
INFO 2012-01-23 04:45:22,989 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:22,989 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60779
INFO 2012-01-23 04:45:22,990 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e1fd480007 with negotiated timeout 20000 for client /127.0.0.1:60779
INFO 2012-01-23 04:45:22,990 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e1fd480007, negotiated timeout = 20000
INFO 2012-01-23 04:45:23,065 main backtype.storm.daemon.supervisor Starting supervisor with id 61741bfd-39bb-443a-8eff-1c8fbb6975b8 at host 10.1.10.15
INFO 2012-01-23 04:45:23,096 main backtype.storm.daemon.supervisor Starting Supervisor with conf {"topology.fall.back.on.java.serialization" true, "zmq.linger.millis" 0, "topology.skip.missing.kryo.registrations" true, "storm.zookeeper.session.timeout" 20000, "nimbus.reassign" true, "nimbus.monitor.freq.secs" 10, "java.library.path" "/usr/local/lib:/opt/local/lib:/usr/lib", "storm.local.dir" "/var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//135d7f01-8d0a-457a-a2d3-ff7714c1b16c", "supervisor.worker.start.timeout.secs" 240, "nimbus.cleanup.inbox.freq.secs" 600, "nimbus.inbox.jar.expiration.secs" 3600, "storm.zookeeper.port" 2181, "storm.zookeeper.root" "/storm", "supervisor.enable" true, "topology.worker.childopts" nil, "worker.childopts" "-Xmx768m", "supervisor.heartbeat.frequency.secs" 5, "drpc.port" 3772, "supervisor.monitor.frequency.secs" 3, "task.heartbeat.frequency.secs" 3, "topology.max.spout.pending" nil, "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, "nimbus.task.timeout.secs" 30, "drpc.invocations.port" 3773, "zmq.threads" 1, "topology.state.synchronization.timeout.secs" 60, "supervisor.worker.timeout.secs" 30, "nimbus.file.copy.expiration.secs" 600, "storm.local.mode.zmq" false, "ui.port" 8080, "nimbus.childopts" "-Xmx1024m", "topology.ackers" 1, "storm.cluster.mode" "local", "topology.optimize" true, "topology.max.task.parallelism" nil}
INFO 2012-01-23 04:45:23,114 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:23,114 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/ sessionTimeout=10000 watcher=com.netflix.curator.ConnectionState@7a6dd8e1
INFO 2012-01-23 04:45:23,115 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:23,116 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60780
INFO 2012-01-23 04:45:23,116 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:23,117 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60780
INFO 2012-01-23 04:45:23,118 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e1fd480008 with negotiated timeout 10000 for client /127.0.0.1:60780
INFO 2012-01-23 04:45:23,118 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e1fd480008, negotiated timeout = 10000
INFO 2012-01-23 04:45:23,118 main-EventThread backtype.storm.zookeeper Zookeeper state update: :connected:none
INFO 2012-01-23 04:45:23,121 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e1fd480008
INFO 2012-01-23 04:45:23,125 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60780 which had sessionid 0x13508e1fd480008
INFO 2012-01-23 04:45:23,126 main-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
INFO 2012-01-23 04:45:23,126 main org.apache.zookeeper.ZooKeeper Session: 0x13508e1fd480008 closed
INFO 2012-01-23 04:45:23,126 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:23,127 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/storm sessionTimeout=20000 watcher=com.netflix.curator.ConnectionState@3eb8f71
INFO 2012-01-23 04:45:23,127 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:23,128 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60781
INFO 2012-01-23 04:45:23,128 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:23,128 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60781
INFO 2012-01-23 04:45:23,129 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e1fd480009 with negotiated timeout 20000 for client /127.0.0.1:60781
INFO 2012-01-23 04:45:23,130 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e1fd480009, negotiated timeout = 20000
INFO 2012-01-23 04:45:23,159 main backtype.storm.daemon.supervisor Starting supervisor with id f78f3bac-f19b-4df7-aa71-7b4fa765a4db at host 10.1.10.15
INFO 2012-01-23 04:45:23,205 main backtype.storm.daemon.nimbus Received topology submission for test with conf {"topology.kryo.register" nil, "storm.id" "test-1-1327293923", "storm.zookeeper.port" 60782, "topology.debug" true, "nimbus.thrift.port" 60783}
INFO 2012-01-23 04:45:23,269 main backtype.storm.daemon.nimbus Task test-1-1327293923:1 timed out
INFO 2012-01-23 04:45:23,270 main backtype.storm.daemon.nimbus Task test-1-1327293923:2 timed out
INFO 2012-01-23 04:45:23,270 main backtype.storm.daemon.nimbus Task test-1-1327293923:3 timed out
INFO 2012-01-23 04:45:23,271 main backtype.storm.daemon.nimbus Task test-1-1327293923:4 timed out
INFO 2012-01-23 04:45:23,272 main backtype.storm.daemon.nimbus Task test-1-1327293923:5 timed out
INFO 2012-01-23 04:45:23,274 main backtype.storm.daemon.nimbus Reassigning test-1-1327293923 to 1 slots
INFO 2012-01-23 04:45:23,275 main backtype.storm.daemon.nimbus Reassign ids: [1 2 3 4 5]
INFO 2012-01-23 04:45:23,275 main backtype.storm.daemon.nimbus Available slots: (["f78f3bac-f19b-4df7-aa71-7b4fa765a4db" 4] ["f78f3bac-f19b-4df7-aa71-7b4fa765a4db" 5] ["f78f3bac-f19b-4df7-aa71-7b4fa765a4db" 6] ["61741bfd-39bb-443a-8eff-1c8fbb6975b8" 1] ["61741bfd-39bb-443a-8eff-1c8fbb6975b8" 2] ["61741bfd-39bb-443a-8eff-1c8fbb6975b8" 3])
INFO 2012-01-23 04:45:23,278 main backtype.storm.daemon.nimbus Setting new assignment for storm id test-1-1327293923: #:backtype.storm.daemon.common.Assignment{:master-code-dir "/var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//e4d62f55-b330-4689-9b86-bc0f6c1e6277/nimbus/stormdist/test-1-1327293923", :node->host {"f78f3bac-f19b-4df7-aa71-7b4fa765a4db" "10.1.10.15"}, :task->node+port {5 ["f78f3bac-f19b-4df7-aa71-7b4fa765a4db" 4], 4 ["f78f3bac-f19b-4df7-aa71-7b4fa765a4db" 4], 3 ["f78f3bac-f19b-4df7-aa71-7b4fa765a4db" 4], 2 ["f78f3bac-f19b-4df7-aa71-7b4fa765a4db" 4], 1 ["f78f3bac-f19b-4df7-aa71-7b4fa765a4db" 4]}, :task->start-time-secs {1 1327293923, 2 1327293923, 3 1327293923, 4 1327293923, 5 1327293923}}
INFO 2012-01-23 04:45:23,286 main backtype.storm.daemon.nimbus Activating test: test-1-1327293923
INFO 2012-01-23 04:45:23,296 Thread-6 backtype.storm.daemon.supervisor Downloading code for storm id test-1-1327293923 from /var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//e4d62f55-b330-4689-9b86-bc0f6c1e6277/nimbus/stormdist/test-1-1327293923
INFO 2012-01-23 04:45:23,317 Thread-11 backtype.storm.daemon.supervisor Downloading code for storm id test-1-1327293923 from /var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//e4d62f55-b330-4689-9b86-bc0f6c1e6277/nimbus/stormdist/test-1-1327293923
INFO 2012-01-23 04:45:23,906 Thread-6 backtype.storm.daemon.supervisor Finished downloading code for storm id test-1-1327293923 from /var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//e4d62f55-b330-4689-9b86-bc0f6c1e6277/nimbus/stormdist/test-1-1327293923
INFO 2012-01-23 04:45:23,940 Thread-11 backtype.storm.daemon.supervisor Finished downloading code for storm id test-1-1327293923 from /var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//e4d62f55-b330-4689-9b86-bc0f6c1e6277/nimbus/stormdist/test-1-1327293923
INFO 2012-01-23 04:45:23,967 Thread-12 backtype.storm.daemon.supervisor Launching worker with assignment #:backtype.storm.daemon.supervisor.LocalAssignment{:storm-id "test-1-1327293923", :task-ids (5 4 3 2 1)} for this supervisor f78f3bac-f19b-4df7-aa71-7b4fa765a4db on port 4 with id c7d905d9-193b-48ae-86f4-6c12f3b3a829
INFO 2012-01-23 04:45:23,969 Thread-12 backtype.storm.daemon.worker Launching worker for test-1-1327293923 on f78f3bac-f19b-4df7-aa71-7b4fa765a4db:4 with id c7d905d9-193b-48ae-86f4-6c12f3b3a829 and conf {"topology.fall.back.on.java.serialization" true, "zmq.linger.millis" 0, "topology.skip.missing.kryo.registrations" true, "storm.zookeeper.session.timeout" 20000, "nimbus.reassign" true, "nimbus.monitor.freq.secs" 10, "java.library.path" "/usr/local/lib:/opt/local/lib:/usr/lib", "storm.local.dir" "/var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//135d7f01-8d0a-457a-a2d3-ff7714c1b16c", "supervisor.worker.start.timeout.secs" 240, "nimbus.cleanup.inbox.freq.secs" 600, "nimbus.inbox.jar.expiration.secs" 3600, "storm.zookeeper.port" 2181, "storm.zookeeper.root" "/storm", "supervisor.enable" true, "topology.worker.childopts" nil, "worker.childopts" "-Xmx768m", "supervisor.heartbeat.frequency.secs" 5, "drpc.port" 3772, "supervisor.monitor.frequency.secs" 3, "task.heartbeat.frequency.secs" 3, "topology.max.spout.pending" nil, "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, "nimbus.task.timeout.secs" 30, "drpc.invocations.port" 3773, "zmq.threads" 1, "topology.state.synchronization.timeout.secs" 60, "supervisor.worker.timeout.secs" 30, "nimbus.file.copy.expiration.secs" 600, "storm.local.mode.zmq" false, "ui.port" 8080, "nimbus.childopts" "-Xmx1024m", "topology.ackers" 1, "storm.cluster.mode" "local", "topology.optimize" true, "topology.max.task.parallelism" nil}
INFO 2012-01-23 04:45:23,969 Thread-12 com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:23,969 Thread-12 org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/ sessionTimeout=10000 watcher=com.netflix.curator.ConnectionState@6fe88c7f
INFO 2012-01-23 04:45:23,970 Thread-12-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:23,972 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60784
INFO 2012-01-23 04:45:23,972 Thread-12-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:23,973 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60784
INFO 2012-01-23 04:45:23,974 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e1fd48000a with negotiated timeout 10000 for client /127.0.0.1:60784
INFO 2012-01-23 04:45:23,974 Thread-12-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e1fd48000a, negotiated timeout = 10000
INFO 2012-01-23 04:45:23,974 Thread-12-EventThread backtype.storm.zookeeper Zookeeper state update: :connected:none
INFO 2012-01-23 04:45:23,978 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e1fd48000a
INFO 2012-01-23 04:45:23,979 Thread-12 org.apache.zookeeper.ZooKeeper Session: 0x13508e1fd48000a closed
INFO 2012-01-23 04:45:23,979 Thread-12 com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:23,979 Thread-12 org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/storm sessionTimeout=20000 watcher=com.netflix.curator.ConnectionState@44a64a92
INFO 2012-01-23 04:45:23,992 Thread-12-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
INFO 2012-01-23 04:45:23,993 Thread-12-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:23,993 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60784 which had sessionid 0x13508e1fd48000a
INFO 2012-01-23 04:45:23,993 Thread-12-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:23,993 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60785
INFO 2012-01-23 04:45:23,994 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60785
INFO 2012-01-23 04:45:23,995 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e1fd48000b with negotiated timeout 20000 for client /127.0.0.1:60785
INFO 2012-01-23 04:45:23,995 Thread-12-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e1fd48000b, negotiated timeout = 20000
INFO 2012-01-23 04:45:24,057 Thread-12 backtype.storm.daemon.task Loading task spout2:5
INFO 2012-01-23 04:45:24,136 Thread-12 backtype.storm.daemon.task Opening spout spout2:5
INFO 2012-01-23 04:45:24,136 Thread-12 backtype.storm.daemon.task Opened spout spout2:5
Emitting tuple [1]
INFO 2012-01-23 04:45:24,140 Thread-20 backtype.storm.daemon.task Emitting: spout2 source: spout2:5, stream: default, id: {}, [1]
INFO 2012-01-23 04:45:24,141 Thread-12 backtype.storm.daemon.task Finished loading task spout2:5
Emitting tuple [3]
INFO 2012-01-23 04:45:24,144 Thread-20 backtype.storm.daemon.task Emitting: spout2 source: spout2:5, stream: default, id: {}, [3]
Emitting tuple [2]
INFO 2012-01-23 04:45:24,145 Thread-20 backtype.storm.daemon.task Emitting: spout2 source: spout2:5, stream: default, id: {}, [2]
INFO 2012-01-23 04:45:24,157 Thread-12 backtype.storm.daemon.task Loading task spout1:4
Emitting tuple [4]
INFO 2012-01-23 04:45:24,160 Thread-20 backtype.storm.daemon.task Emitting: spout2 source: spout2:5, stream: default, id: {}, [4]
INFO 2012-01-23 04:45:24,179 Thread-12 backtype.storm.daemon.task Opening spout spout1:4
INFO 2012-01-23 04:45:24,179 Thread-12 backtype.storm.daemon.task Opened spout spout1:4
Emitting tuple [4]
INFO 2012-01-23 04:45:24,184 Thread-24 backtype.storm.daemon.task Emitting: spout1 source: spout1:4, stream: default, id: {}, [4]
Emitting tuple [2]
INFO 2012-01-23 04:45:24,185 Thread-24 backtype.storm.daemon.task Emitting: spout1 source: spout1:4, stream: default, id: {}, [2]
Emitting tuple [1]
INFO 2012-01-23 04:45:24,185 Thread-24 backtype.storm.daemon.task Emitting: spout1 source: spout1:4, stream: default, id: {}, [1]
Emitting tuple [3]
INFO 2012-01-23 04:45:24,185 Thread-24 backtype.storm.daemon.task Emitting: spout1 source: spout1:4, stream: default, id: {}, [3]
INFO 2012-01-23 04:45:24,199 Thread-12 backtype.storm.daemon.task Finished loading task spout1:4
INFO 2012-01-23 04:45:24,200 Thread-12 backtype.storm.daemon.task Loading task bolt4:3
INFO 2012-01-23 04:45:24,233 Thread-12 backtype.storm.daemon.task Preparing bolt bolt4:3
INFO 2012-01-23 04:45:24,233 Thread-12 backtype.storm.daemon.task Prepared bolt bolt4:3
INFO 2012-01-23 04:45:24,239 Thread-12 backtype.storm.daemon.task Finished loading task bolt4:3
INFO 2012-01-23 04:45:24,240 Thread-12 backtype.storm.daemon.task Loading task bolt3:2
INFO 2012-01-23 04:45:24,286 Thread-12 backtype.storm.daemon.task Preparing bolt bolt3:2
INFO 2012-01-23 04:45:24,493 Thread-12 com.espertech.esper.core.EPServiceProviderImpl Initializing engine URI 'default' version 4.3.0
INFO 2012-01-23 04:45:24,827 Thread-12 com.espertech.esper.core.EPServiceProviderImpl Initializing engine URI 'default' version 4.3.0
INFO 2012-01-23 04:45:25,841 Thread-12 backtype.storm.daemon.task Prepared bolt bolt3:2
INFO 2012-01-23 04:45:25,843 Thread-12 backtype.storm.daemon.task Finished loading task bolt3:2
INFO 2012-01-23 04:45:25,844 Thread-12 backtype.storm.daemon.task Loading task __acker:1
INFO 2012-01-23 04:45:25,879 Thread-12 backtype.storm.daemon.task Preparing bolt __acker:1
INFO 2012-01-23 04:45:25,880 Thread-12 backtype.storm.daemon.task Prepared bolt __acker:1
INFO 2012-01-23 04:45:25,880 Thread-12 backtype.storm.daemon.task Finished loading task __acker:1
INFO 2012-01-23 04:45:25,948 Thread-30 backtype.storm.daemon.task Emitting: bolt3 source: bolt3:2, stream: default, id: {}, [1, 4]
INFO 2012-01-23 04:45:25,954 Thread-12 backtype.storm.daemon.worker Worker has topology config {"storm.id" "test-1-1327293923", "topology.fall.back.on.java.serialization" true, "zmq.linger.millis" 0, "topology.skip.missing.kryo.registrations" true, "storm.zookeeper.session.timeout" 20000, "nimbus.reassign" true, "nimbus.monitor.freq.secs" 10, "java.library.path" "/usr/local/lib:/opt/local/lib:/usr/lib", "storm.local.dir" "/var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//135d7f01-8d0a-457a-a2d3-ff7714c1b16c", "supervisor.worker.start.timeout.secs" 240, "nimbus.cleanup.inbox.freq.secs" 600, "nimbus.inbox.jar.expiration.secs" 3600, "storm.zookeeper.port" 60782, "storm.zookeeper.root" "/storm", "supervisor.enable" true, "topology.worker.childopts" nil, "worker.childopts" "-Xmx768m", "supervisor.heartbeat.frequency.secs" 5, "drpc.port" 3772, "supervisor.monitor.frequency.secs" 3, "task.heartbeat.frequency.secs" 3, "topology.max.spout.pending" nil, "supervisor.slots.ports" (4 5 6), "topology.debug" true, "nimbus.task.launch.secs" 120, "nimbus.supervisor.timeout.secs" 60, "topology.kryo.register" nil, "topology.message.timeout.secs" 30, "task.refresh.poll.secs" 10, "topology.workers" 1, "supervisor.childopts" "-Xmx1024m", "nimbus.thrift.port" 60783, "topology.stats.sample.rate" 0.05, "worker.heartbeat.frequency.secs" 1, "nimbus.task.timeout.secs" 30, "drpc.invocations.port" 3773, "zmq.threads" 1, "topology.state.synchronization.timeout.secs" 60, "supervisor.worker.timeout.secs" 30, "nimbus.file.copy.expiration.secs" 600, "storm.local.mode.zmq" false, "ui.port" 8080, "nimbus.childopts" "-Xmx1024m", "topology.ackers" 1, "storm.cluster.mode" "local", "topology.optimize" true, "topology.max.task.parallelism" nil}
INFO 2012-01-23 04:45:25,955 Thread-12 backtype.storm.daemon.worker Worker c7d905d9-193b-48ae-86f4-6c12f3b3a829 for storm test-1-1327293923 on f78f3bac-f19b-4df7-aa71-7b4fa765a4db:4 has finished loading
INFO 2012-01-23 04:45:26,053 main backtype.storm.daemon.nimbus Delaying event :remove for 30 secs for test-1-1327293923
INFO 2012-01-23 04:45:26,057 main backtype.storm.daemon.nimbus Updated test-1-1327293923 with status {:type :killed, :kill-time-secs 30}
INFO 2012-01-23 04:45:26,057 main backtype.storm.daemon.nimbus Shutting down master
INFO 2012-01-23 04:45:26,059 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e1fd480001
INFO 2012-01-23 04:45:26,059 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60773 which had sessionid 0x13508e1fd480001
INFO 2012-01-23 04:45:26,060 main org.apache.zookeeper.ZooKeeper Session: 0x13508e1fd480001 closed
INFO 2012-01-23 04:45:26,060 main-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
INFO 2012-01-23 04:45:26,060 main backtype.storm.daemon.nimbus Shut down master
INFO 2012-01-23 04:45:26,063 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e1fd480003
INFO 2012-01-23 04:45:26,064 main org.apache.zookeeper.ZooKeeper Session: 0x13508e1fd480003 closed
INFO 2012-01-23 04:45:26,064 main-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
WARN 2012-01-23 04:45:26,064 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn EndOfStreamException: Unable to read additional data from client sessionid 0x13508e1fd480003, likely client has closed socket
INFO 2012-01-23 04:45:26,065 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60775 which had sessionid 0x13508e1fd480003
INFO 2012-01-23 04:45:26,065 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e1fd480005
INFO 2012-01-23 04:45:26,066 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60777 which had sessionid 0x13508e1fd480005
INFO 2012-01-23 04:45:26,066 main org.apache.zookeeper.ZooKeeper Session: 0x13508e1fd480005 closed
INFO 2012-01-23 04:45:26,066 main-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
INFO 2012-01-23 04:45:26,067 main backtype.storm.daemon.supervisor Shutting down supervisor 61741bfd-39bb-443a-8eff-1c8fbb6975b8
INFO 2012-01-23 04:45:26,067 Thread-8 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,067 Thread-9 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,067 Thread-10 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,068 Thread-6 backtype.storm.event Event manager interrupted
INFO 2012-01-23 04:45:26,068 Thread-7 backtype.storm.event Event manager interrupted
INFO 2012-01-23 04:45:26,069 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e1fd480007
INFO 2012-01-23 04:45:26,069 main org.apache.zookeeper.ZooKeeper Session: 0x13508e1fd480007 closed
INFO 2012-01-23 04:45:26,069 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60779 which had sessionid 0x13508e1fd480007
INFO 2012-01-23 04:45:26,069 main-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
INFO 2012-01-23 04:45:26,069 main backtype.storm.daemon.supervisor Shutting down f78f3bac-f19b-4df7-aa71-7b4fa765a4db:c7d905d9-193b-48ae-86f4-6c12f3b3a829
INFO 2012-01-23 04:45:26,070 main backtype.storm.process-simulator Killing process 82d3d40b-ca02-4390-bd02-125dd00039cf
INFO 2012-01-23 04:45:26,070 main backtype.storm.daemon.worker Shutting down worker test-1-1327293923 f78f3bac-f19b-4df7-aa71-7b4fa765a4db 4
INFO 2012-01-23 04:45:26,070 main backtype.storm.daemon.task Shutting down task test-1-1327293923:5
INFO 2012-01-23 04:45:26,071 Thread-20 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,071 Thread-18 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,077 main backtype.storm.daemon.task Shut down task test-1-1327293923:5
INFO 2012-01-23 04:45:26,077 main backtype.storm.daemon.task Shutting down task test-1-1327293923:4
INFO 2012-01-23 04:45:26,077 Thread-24 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,077 Thread-22 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,080 main backtype.storm.daemon.task Shut down task test-1-1327293923:4
INFO 2012-01-23 04:45:26,080 main backtype.storm.daemon.task Shutting down task test-1-1327293923:3
INFO 2012-01-23 04:45:26,081 Thread-26 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,083 main backtype.storm.daemon.task Shut down task test-1-1327293923:3
INFO 2012-01-23 04:45:26,083 main backtype.storm.daemon.task Shutting down task test-1-1327293923:2
INFO 2012-01-23 04:45:26,084 Thread-29 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,289 main backtype.storm.daemon.task Shut down task test-1-1327293923:2
INFO 2012-01-23 04:45:26,289 main backtype.storm.daemon.task Shutting down task test-1-1327293923:1
INFO 2012-01-23 04:45:26,290 Thread-31 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,294 main backtype.storm.daemon.task Shut down task test-1-1327293923:1
INFO 2012-01-23 04:45:26,294 main backtype.storm.daemon.worker Terminating zmq context
INFO 2012-01-23 04:45:26,294 main backtype.storm.daemon.worker Disconnecting from storm cluster state context
INFO 2012-01-23 04:45:26,294 main backtype.storm.daemon.worker Waiting for heartbeat thread to die
INFO 2012-01-23 04:45:26,295 Thread-34 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,295 Thread-35 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,296 Thread-17 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,296 Thread-16 backtype.storm.event Event manager interrupted
INFO 2012-01-23 04:45:26,297 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e1fd48000b
INFO 2012-01-23 04:45:26,298 main org.apache.zookeeper.ZooKeeper Session: 0x13508e1fd48000b closed
INFO 2012-01-23 04:45:26,298 main backtype.storm.daemon.worker Shut down worker test-1-1327293923 f78f3bac-f19b-4df7-aa71-7b4fa765a4db 4
INFO 2012-01-23 04:45:26,299 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60785 which had sessionid 0x13508e1fd48000b
INFO 2012-01-23 04:45:26,299 Thread-12-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
INFO 2012-01-23 04:45:26,300 main backtype.storm.daemon.supervisor Shut down f78f3bac-f19b-4df7-aa71-7b4fa765a4db:c7d905d9-193b-48ae-86f4-6c12f3b3a829
INFO 2012-01-23 04:45:26,301 main backtype.storm.daemon.supervisor Shutting down supervisor f78f3bac-f19b-4df7-aa71-7b4fa765a4db
INFO 2012-01-23 04:45:26,301 Thread-13 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,301 Thread-14 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,301 Thread-15 backtype.storm.util Async loop interrupted!
INFO 2012-01-23 04:45:26,301 Thread-11 backtype.storm.event Event manager interrupted
INFO 2012-01-23 04:45:26,302 Thread-12 backtype.storm.event Event manager interrupted
INFO 2012-01-23 04:45:26,302 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e1fd480009
INFO 2012-01-23 04:45:26,303 main org.apache.zookeeper.ZooKeeper Session: 0x13508e1fd480009 closed
INFO 2012-01-23 04:45:26,303 main backtype.storm.testing Shutting down in process zookeeper
INFO 2012-01-23 04:45:26,303 main org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60781 which had sessionid 0x13508e1fd480009
INFO 2012-01-23 04:45:26,304 main-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
INFO 2012-01-23 04:45:26,304 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn NIOServerCnxn factory exited run method
INFO 2012-01-23 04:45:26,304 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor PrepRequestProcessor exited loop!
INFO 2012-01-23 04:45:26,304 SyncThread:0 org.apache.zookeeper.server.SyncRequestProcessor SyncRequestProcessor exited!
INFO 2012-01-23 04:45:26,304 main org.apache.zookeeper.server.FinalRequestProcessor shutdown of request processor complete
INFO 2012-01-23 04:45:26,305 main backtype.storm.testing Done shutting down in process zookeeper
INFO 2012-01-23 04:45:26,310 main backtype.storm.testing Deleting temporary path /var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//e4d62f55-b330-4689-9b86-bc0f6c1e6277
INFO 2012-01-23 04:45:26,319 main backtype.storm.testing Deleting temporary path /var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//6ddda619-0f31-4624-8842-556ecdb128e1
INFO 2012-01-23 04:45:26,319 main backtype.storm.testing Deleting temporary path /var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//4572a18b-d469-4172-9d48-32ae6d44244e
INFO 2012-01-23 04:45:26,321 main backtype.storm.testing Deleting temporary path /var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//135d7f01-8d0a-457a-a2d3-ff7714c1b16c
INFO 2012-01-23 04:45:26,480 main backtype.storm.zookeeper Starting inprocess zookeeper at port 2181 and dir /var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//27458e94-54c4-41fe-b123-a62cfd96189a
INFO 2012-01-23 04:45:26,480 main org.apache.zookeeper.server.ZooKeeperServer Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T/27458e94-54c4-41fe-b123-a62cfd96189a/version-2 snapdir /var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T/27458e94-54c4-41fe-b123-a62cfd96189a/version-2
INFO 2012-01-23 04:45:26,480 main org.apache.zookeeper.server.NIOServerCnxn binding to port 0.0.0.0/0.0.0.0:2181
INFO 2012-01-23 04:45:26,481 main org.apache.zookeeper.server.persistence.FileTxnSnapLog Snapshotting: 0
INFO 2012-01-23 04:45:26,486 main backtype.storm.daemon.nimbus Starting Nimbus with conf {"topology.fall.back.on.java.serialization" true, "zmq.linger.millis" 0, "topology.skip.missing.kryo.registrations" true, "storm.zookeeper.session.timeout" 20000, "nimbus.reassign" true, "nimbus.monitor.freq.secs" 10, "java.library.path" "/usr/local/lib:/opt/local/lib:/usr/lib", "storm.local.dir" "/var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//4f8be61b-97b1-4fac-876f-439295d0c953", "supervisor.worker.start.timeout.secs" 240, "nimbus.cleanup.inbox.freq.secs" 600, "nimbus.inbox.jar.expiration.secs" 3600, "storm.zookeeper.port" 2181, "storm.zookeeper.root" "/storm", "supervisor.enable" true, "topology.worker.childopts" nil, "worker.childopts" "-Xmx768m", "supervisor.heartbeat.frequency.secs" 5, "drpc.port" 3772, "supervisor.monitor.frequency.secs" 3, "task.heartbeat.frequency.secs" 3, "topology.max.spout.pending" nil, "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, "nimbus.task.timeout.secs" 30, "drpc.invocations.port" 3773, "zmq.threads" 1, "topology.state.synchronization.timeout.secs" 60, "supervisor.worker.timeout.secs" 30, "nimbus.file.copy.expiration.secs" 600, "storm.local.mode.zmq" false, "ui.port" 8080, "nimbus.childopts" "-Xmx1024m", "topology.ackers" 1, "storm.cluster.mode" "local", "topology.optimize" true, "topology.max.task.parallelism" nil}
INFO 2012-01-23 04:45:26,487 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:26,488 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/ sessionTimeout=10000 watcher=com.netflix.curator.ConnectionState@7bfb7cbb
INFO 2012-01-23 04:45:26,499 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:26,502 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:26,502 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60786
INFO 2012-01-23 04:45:26,502 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60786
INFO 2012-01-23 04:45:26,502 SyncThread:0 org.apache.zookeeper.server.persistence.FileTxnLog Creating new log file: log.1
INFO 2012-01-23 04:45:26,505 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e20c510000 with negotiated timeout 10000 for client /127.0.0.1:60786
INFO 2012-01-23 04:45:26,505 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e20c510000, negotiated timeout = 10000
INFO 2012-01-23 04:45:26,505 main-EventThread backtype.storm.zookeeper Zookeeper state update: :connected:none
INFO 2012-01-23 04:45:26,507 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e20c510000
INFO 2012-01-23 04:45:26,508 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60786 which had sessionid 0x13508e20c510000
INFO 2012-01-23 04:45:26,508 main org.apache.zookeeper.ZooKeeper Session: 0x13508e20c510000 closed
INFO 2012-01-23 04:45:26,510 main-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
INFO 2012-01-23 04:45:26,510 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:26,510 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/storm sessionTimeout=20000 watcher=com.netflix.curator.ConnectionState@1c45484a
INFO 2012-01-23 04:45:26,512 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:26,512 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60787
INFO 2012-01-23 04:45:26,513 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:26,513 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60787
INFO 2012-01-23 04:45:26,514 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e20c510001 with negotiated timeout 20000 for client /127.0.0.1:60787
INFO 2012-01-23 04:45:26,514 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e20c510001, negotiated timeout = 20000
INFO 2012-01-23 04:45:26,531 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:26,532 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/ sessionTimeout=10000 watcher=com.netflix.curator.ConnectionState@21882d18
INFO 2012-01-23 04:45:26,532 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:26,533 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60788
INFO 2012-01-23 04:45:26,535 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:26,535 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60788
INFO 2012-01-23 04:45:26,536 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e20c510002 with negotiated timeout 10000 for client /127.0.0.1:60788
INFO 2012-01-23 04:45:26,536 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e20c510002, negotiated timeout = 10000
INFO 2012-01-23 04:45:26,536 main-EventThread backtype.storm.zookeeper Zookeeper state update: :connected:none
INFO 2012-01-23 04:45:26,537 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e20c510002
INFO 2012-01-23 04:45:26,538 main org.apache.zookeeper.ZooKeeper Session: 0x13508e20c510002 closed
INFO 2012-01-23 04:45:26,538 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60788 which had sessionid 0x13508e20c510002
INFO 2012-01-23 04:45:26,538 main-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
INFO 2012-01-23 04:45:26,538 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:26,538 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/storm sessionTimeout=20000 watcher=com.netflix.curator.ConnectionState@1b186cf9
INFO 2012-01-23 04:45:26,539 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:26,539 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60789
INFO 2012-01-23 04:45:26,542 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:26,542 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60789
INFO 2012-01-23 04:45:26,542 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:26,542 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/ sessionTimeout=10000 watcher=com.netflix.curator.ConnectionState@459bdb65
INFO 2012-01-23 04:45:26,543 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e20c510003 with negotiated timeout 20000 for client /127.0.0.1:60789
INFO 2012-01-23 04:45:26,543 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e20c510003, negotiated timeout = 20000
INFO 2012-01-23 04:45:26,543 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:26,547 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60790
INFO 2012-01-23 04:45:26,549 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:26,549 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60790
INFO 2012-01-23 04:45:26,550 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e20c510004 with negotiated timeout 10000 for client /127.0.0.1:60790
INFO 2012-01-23 04:45:26,550 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e20c510004, negotiated timeout = 10000
INFO 2012-01-23 04:45:26,550 main-EventThread backtype.storm.zookeeper Zookeeper state update: :connected:none
INFO 2012-01-23 04:45:26,551 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e20c510004
INFO 2012-01-23 04:45:26,552 main org.apache.zookeeper.ZooKeeper Session: 0x13508e20c510004 closed
INFO 2012-01-23 04:45:26,552 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60790 which had sessionid 0x13508e20c510004
INFO 2012-01-23 04:45:26,552 main-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
INFO 2012-01-23 04:45:26,552 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:26,552 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/storm sessionTimeout=20000 watcher=com.netflix.curator.ConnectionState@2389b9bd
INFO 2012-01-23 04:45:26,553 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:26,553 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60791
INFO 2012-01-23 04:45:26,554 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:26,555 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60791
INFO 2012-01-23 04:45:26,556 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e20c510005 with negotiated timeout 20000 for client /127.0.0.1:60791
INFO 2012-01-23 04:45:26,556 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e20c510005, negotiated timeout = 20000
INFO 2012-01-23 04:45:26,570 main backtype.storm.daemon.supervisor Starting Supervisor with conf {"topology.fall.back.on.java.serialization" true, "zmq.linger.millis" 0, "topology.skip.missing.kryo.registrations" true, "storm.zookeeper.session.timeout" 20000, "nimbus.reassign" true, "nimbus.monitor.freq.secs" 10, "java.library.path" "/usr/local/lib:/opt/local/lib:/usr/lib", "storm.local.dir" "/var/folders/04/nrrmlfvx05l43fj6rljc2z400000gq/T//65dd39fb-e8ff-4189-a280-d4b97806b618", "supervisor.worker.start.timeout.secs" 240, "nimbus.cleanup.inbox.freq.secs" 600, "nimbus.inbox.jar.expiration.secs" 3600, "storm.zookeeper.port" 2181, "storm.zookeeper.root" "/storm", "supervisor.enable" true, "topology.worker.childopts" nil, "worker.childopts" "-Xmx768m", "supervisor.heartbeat.frequency.secs" 5, "drpc.port" 3772, "supervisor.monitor.frequency.secs" 3, "task.heartbeat.frequency.secs" 3, "topology.max.spout.pending" nil, "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, "nimbus.task.timeout.secs" 30, "drpc.invocations.port" 3773, "zmq.threads" 1, "topology.state.synchronization.timeout.secs" 60, "supervisor.worker.timeout.secs" 30, "nimbus.file.copy.expiration.secs" 600, "storm.local.mode.zmq" false, "ui.port" 8080, "nimbus.childopts" "-Xmx1024m", "topology.ackers" 1, "storm.cluster.mode" "local", "topology.optimize" true, "topology.max.task.parallelism" nil}
INFO 2012-01-23 04:45:26,572 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:26,572 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/ sessionTimeout=10000 watcher=com.netflix.curator.ConnectionState@25082661
INFO 2012-01-23 04:45:26,572 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:26,583 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:26,583 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60792
INFO 2012-01-23 04:45:26,584 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60792
INFO 2012-01-23 04:45:26,585 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e20c510006 with negotiated timeout 10000 for client /127.0.0.1:60792
INFO 2012-01-23 04:45:26,585 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e20c510006, negotiated timeout = 10000
INFO 2012-01-23 04:45:26,585 main-EventThread backtype.storm.zookeeper Zookeeper state update: :connected:none
INFO 2012-01-23 04:45:26,587 ProcessThread:-1 org.apache.zookeeper.server.PrepRequestProcessor Processed session termination for sessionid: 0x13508e20c510006
INFO 2012-01-23 04:45:26,588 main org.apache.zookeeper.ZooKeeper Session: 0x13508e20c510006 closed
INFO 2012-01-23 04:45:26,588 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Closed socket connection for client /127.0.0.1:60792 which had sessionid 0x13508e20c510006
INFO 2012-01-23 04:45:26,588 main-EventThread org.apache.zookeeper.ClientCnxn EventThread shut down
INFO 2012-01-23 04:45:26,588 main com.netflix.curator.framework.imps.CuratorFrameworkImpl Starting
INFO 2012-01-23 04:45:26,588 main org.apache.zookeeper.ZooKeeper Initiating client connection, connectString=/storm sessionTimeout=20000 watcher=com.netflix.curator.ConnectionState@788c1852
INFO 2012-01-23 04:45:26,590 main-SendThread() org.apache.zookeeper.ClientCnxn Opening socket connection to server localhost/127.0.0.1:2181
INFO 2012-01-23 04:45:26,591 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Accepted socket connection from /127.0.0.1:60793
INFO 2012-01-23 04:45:26,594 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Socket connection established to localhost/127.0.0.1:2181, initiating session
INFO 2012-01-23 04:45:26,595 NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181 org.apache.zookeeper.server.NIOServerCnxn Client attempting to establish new session at /127.0.0.1:60793
INFO 2012-01-23 04:45:26,596 SyncThread:0 org.apache.zookeeper.server.NIOServerCnxn Established session 0x13508e20c510007 with negotiated timeout 20000 for client /127.0.0.1:60793
INFO 2012-01-23 04:45:26,596 main-SendThread(localhost:2181) org.apache.zookeeper.ClientCnxn Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x13508e20c510007, negotiated timeout = 20000
INFO 2012-01-23 04:45:26,605 main backtype.storm.daemon.supervisor Starting supervisor with id 807634ff-fdf1-4a8f-9df6-9e6294005cab at host 10.1.10.15
INFO 2012-01-23 04:45:26,608 main backtype.storm.daemon.supervisor Starting Supervisor with conf {"topology.fall.back.on.java.serialization" true, "zmq.linger.millis" 0, "topology.skip.missing.kryo.registrations" true, "storm.zookeeper.session.timeout" 20000, "nimbus.reassign" true, "nimbus.monitor.freq.secs" 10, "