Hi, I am new to storm and I want to do a real-time analysis of log from
my tomcat.
The first feature I add is to collect the time of each method so I can
get the average cost of them.
However, when my topology runs for a while , it breaks down, here is the
log from stdout:
......
130048 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:19 method queryAdverts cost 3 ms
130048 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:20 method queryUnreadMessage cost 27 ms
130048 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:25 method queryAdverts cost 2 ms
130048 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:28 method queryAdverts cost 3 ms
130048 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:28 method queryAdverts cost 3 ms
130048 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:30 method queryAdverts cost 2 ms
130048 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:32 method queryAdverts cost 3 ms
130049 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:20 method recoveryTeam cost 3 ms
130049 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:21 method queryAdverts cost 2 ms
130049 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:21 method queryAdverts cost 5 ms
130049 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:23 method queryAdverts cost 3 ms
130049 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:27 method queryUserDetail cost 3 ms
130049 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:31 method queryAdverts cost 3 ms
130075 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:33 method queryAdverts cost 3 ms
130076 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:33 method queryAdverts cost 3 ms
130077 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:34 method realTimeData cost 14 ms
130078 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:35 method queryAdverts cost 2 ms
130080 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:35 method queryAdverts cost 3 ms
130081 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:36 method queryAdverts cost 3 ms
130083 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:38 method queryAdverts cost 4 ms
130084 [main] INFO backtype.storm.daemon.nimbus - Shutting down master
130085 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:38 method queryAdverts cost 3 ms
130085 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:40 method queryUserDetail cost 2 ms
130086 [ProcessThread(sid:0 cport:-1):] INFO
org.apache.storm.zookeeper.server.PrepRequestProcessor - Processed
session termination for sessionid: 0x14f20f84bb80001
130088 [main] INFO org.apache.storm.zookeeper.ZooKeeper - Session:
0x14f20f84bb80001 closed
130088 [main] INFO backtype.storm.daemon.nimbus - Shut down master
130088 [main-EventThread] INFO org.apache.storm.zookeeper.ClientCnxn -
EventThread shut down
130088 [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2000] INFO
org.apache.storm.zookeeper.server.NIOServerCnxn - Closed socket
connection for client /127.0.0.1:46562 which had sessionid 0x14f20f84bb80001
130092 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:41 method queryAdverts cost 3 ms
130092 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:41 method queryUnreadMessage cost 28 ms
130093 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:42 method queryAdverts cost 3 ms
130094 [ProcessThread(sid:0 cport:-1):] INFO
org.apache.storm.zookeeper.server.PrepRequestProcessor - Processed
session termination for sessionid: 0x14f20f84bb80004
130095 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:44 method recoveryTeam cost 3 ms
130096 [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2000] INFO
org.apache.storm.zookeeper.server.NIOServerCnxn - Closed socket
connection for client /127.0.0.1:46568 which had sessionid 0x14f20f84bb80004
130096 [main-EventThread] INFO org.apache.storm.zookeeper.ClientCnxn -
EventThread shut down
130096 [main] INFO org.apache.storm.zookeeper.ZooKeeper - Session:
0x14f20f84bb80004 closed
130097 [ProcessThread(sid:0 cport:-1):] INFO
org.apache.storm.zookeeper.server.PrepRequestProcessor - Processed
session termination for sessionid: 0x14f20f84bb80005
130098 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:44 method queryAdverts cost 3 ms
130099 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:45 method queryVersion101 cost 13 ms
130099 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:45 method login101 cost 102 ms
130100 [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2000] INFO
org.apache.storm.zookeeper.server.NIOServerCnxn - Closed socket
connection for client /127.0.0.1:46569 which had sessionid 0x14f20f84bb80005
130100 [main-EventThread] INFO org.apache.storm.zookeeper.ClientCnxn -
EventThread shut down
130100 [main] INFO org.apache.storm.zookeeper.ZooKeeper - Session:
0x14f20f84bb80005 closed
130101 [main] INFO backtype.storm.daemon.supervisor - Shutting down
9550d8eb-d961-45e4-8699-ad5a39bcf87d:6deff82f-96b4-4259-a84f-43e84a53077c
130101 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:46 method recoveryTeam cost 17 ms
130101 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:46 method queryAdvertList110 cost 12 ms
130101 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:46 method friendList cost 26 ms
130102 [main] INFO backtype.storm.process-simulator - Killing process
3676d38a-b516-48ab-bb35-55e252335264
130102 [main] INFO backtype.storm.daemon.worker - Shutting down worker
StormAnalysis-1-1439367254 9550d8eb-d961-45e4-8699-ad5a39bcf87d 1024
130103 [main] INFO backtype.storm.daemon.worker - Shutting down receive
thread
130103 [main] INFO backtype.storm.messaging.loader - Shutting down
receiving-thread: [StormAnalysis-1-1439367254, 1024]
130103 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:46 method recoveryTeam cost 3 ms
130104 [Thread-7-worker-receiver-thread-0] INFO
backtype.storm.messaging.loader -
Receiving-thread:[StormAnalysis-1-1439367254, 1024] received shutdown notice
130105 [main] INFO backtype.storm.messaging.loader - Waiting for
receiving-thread:[StormAnalysis-1-1439367254, 1024] to die
130105 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:46 method queryAdverts cost 2 ms
130106 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:47 method queryPostList cost 222 ms
130106 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:47 method queryAdvertList110 cost 16 ms
130107 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:47 method queryUnreadMessage cost 33 ms
130108 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:48 method queryUnreadMessage cost 36 ms
130109 [main] INFO backtype.storm.messaging.loader - Shutdown
receiving-thread: [StormAnalysis-1-1439367254, 1024]
130109 [main] INFO backtype.storm.daemon.worker - Shut down receive thread
130123 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:48 method queryAdverts cost 3 ms
130123 [main] INFO backtype.storm.daemon.worker - Terminating messaging
context
130123 [main] INFO backtype.storm.daemon.worker - Shutting down executors
130124 [main] INFO backtype.storm.daemon.executor - Shutting down
executor kafka-reader:[2 2]
130124 [Thread-11-log-counter] INFO com.madao.storm.analysis.LogCount -
2015-08-10 20:07:48 method recoveryTeam cost 3 ms
130125 [Thread-9-kafka-reader] INFO backtype.storm.util - Async loop
interrupted!
130125 [Thread-8-disruptor-executor[2 2]-send-queue] INFO
backtype.storm.util - Async loop interrupted!
130133 [main] INFO backtype.storm.daemon.executor - Shut down executor
kafka-reader:[2 2]
130135 [main] INFO backtype.storm.daemon.executor - Shutting down
executor log-counter:[3 3]
130135 [Thread-11-log-counter] INFO backtype.storm.util - Async loop
interrupted!
130135 [Thread-10-disruptor-executor[3 3]-send-queue] INFO
backtype.storm.util - Async loop interrupted!
130135 [main] INFO com.madao.storm.analysis.LogCount - The final result:
130136 [main] INFO backtype.storm.daemon.executor - Shut down executor
log-counter:[3 3]
130136 [main] INFO backtype.storm.daemon.executor - Shutting down
executor log-filter:[4 4]
130136 [Thread-12-disruptor-executor[4 4]-send-queue] INFO
backtype.storm.util - Async loop interrupted!
130136 [Thread-13-log-filter] INFO backtype.storm.util - Async loop
interrupted!
130137 [main] INFO backtype.storm.daemon.executor - Shut down executor
log-filter:[4 4]
130137 [main] INFO backtype.storm.daemon.executor - Shutting down
executor log-filter:[5 5]
130137 [Thread-15-log-filter] INFO backtype.storm.util - Async loop
interrupted!
130137 [Thread-14-disruptor-executor[5 5]-send-queue] INFO
backtype.storm.util - Async loop interrupted!
130138 [main] INFO backtype.storm.daemon.executor - Shut down executor
log-filter:[5 5]
130136 [Thread-12-disruptor-executor[4 4]-send-queue] INFO
backtype.storm.util - Async loop interrupted!
130136 [Thread-13-log-filter] INFO backtype.storm.util - Async loop
interrupted!
130137 [main] INFO backtype.storm.daemon.executor - Shut down executor
log-filter:[4 4]
130137 [main] INFO backtype.storm.daemon.executor - Shutting down
executor log-filter:[5 5]
130137 [Thread-15-log-filter] INFO backtype.storm.util - Async loop
interrupted!
130137 [Thread-14-disruptor-executor[5 5]-send-queue] INFO
backtype.storm.util - Async loop interrupted!
130138 [main] INFO backtype.storm.daemon.executor - Shut down executor
log-filter:[5 5]
130138 [main] INFO backtype.storm.daemon.executor - Shutting down
executor __system:[-1 -1]
130138 [Thread-16-disruptor-executor[-1 -1]-send-queue] INFO
backtype.storm.util - Async loop interrupted!
130138 [Thread-17-__system] INFO backtype.storm.util - Async loop
interrupted!
130138 [main] INFO backtype.storm.daemon.executor - Shut down executor
__system:[-1 -1]
130138 [main] INFO backtype.storm.daemon.executor - Shutting down
executor __acker:[1 1]
130139 [Thread-19-__acker] INFO backtype.storm.util - Async loop
interrupted!
130139 [Thread-18-disruptor-executor[1 1]-send-queue] INFO
backtype.storm.util - Async loop interrupted!
130139 [main] INFO backtype.storm.daemon.executor - Shut down executor
__acker:[1 1]
130139 [main] INFO backtype.storm.daemon.worker - Shut down executors
130139 [main] INFO backtype.storm.daemon.worker - Shutting down
transfer thread
130139 [Thread-20-disruptor-worker-transfer-queue] INFO
backtype.storm.util - Async loop interrupted!
130140 [main] INFO backtype.storm.daemon.worker - Shut down transfer thread
130141 [main] INFO backtype.storm.daemon.worker - Shutting down default
resources
130142 [main] INFO backtype.storm.daemon.worker - Shut down default
resources
130150 [main] INFO backtype.storm.daemon.worker - Disconnecting from
storm cluster state context
130151 [ProcessThread(sid:0 cport:-1):] INFO
org.apache.storm.zookeeper.server.PrepRequestProcessor - Processed
session termination for sessionid: 0x14f20f84bb8000b
130154 [main] INFO org.apache.storm.zookeeper.ZooKeeper - Session:
0x14f20f84bb8000b closed
130154 [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2000] INFO
org.apache.storm.zookeeper.server.NIOServerCnxn - Closed socket
connection for client /127.0.0.1:46579 which had sessionid 0x14f20f84bb8000b
130154 [Thread-4-EventThread] INFO org.apache.storm.zookeeper.ClientCnxn
- EventThread shut down
130154 [main] INFO backtype.storm.daemon.worker - Shut down worker
StormAnalysis-1-1439367254 9550d8eb-d961-45e4-8699-ad5a39bcf87d 1024
130163 [main] INFO backtype.storm.daemon.supervisor - Shut down
9550d8eb-d961-45e4-8699-ad5a39bcf87d:6deff82f-96b4-4259-a84f-43e84a53077c
130163 [main] INFO backtype.storm.daemon.supervisor - Shutting down
supervisor 9550d8eb-d961-45e4-8699-ad5a39bcf87d
130164 [Thread-3] INFO backtype.storm.event - Event manager interrupted
130164 [Thread-4] INFO backtype.storm.event - Event manager interrupted
130165 [ProcessThread(sid:0 cport:-1):] INFO
org.apache.storm.zookeeper.server.PrepRequestProcessor - Processed
session termination for sessionid: 0x14f20f84bb80007
130168 [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2000] INFO
org.apache.storm.zookeeper.server.NIOServerCnxn - Closed socket
connection for client /127.0.0.1:46573 which had sessionid 0x14f20f84bb80007
130168 [main] INFO org.apache.storm.zookeeper.ZooKeeper - Session:
0x14f20f84bb80007 closed
130168 [main] INFO backtype.storm.daemon.supervisor - Shutting down
supervisor 4385d1d6-076a-4e51-8c16-bf4857df6ec0
130169 [Thread-5] INFO backtype.storm.event - Event manager interrupted
130169 [main-EventThread] INFO org.apache.storm.zookeeper.ClientCnxn -
EventThread shut down
130170 [Thread-6] INFO backtype.storm.event - Event manager interrupted
130175 [ProcessThread(sid:0 cport:-1):] INFO
org.apache.storm.zookeeper.server.PrepRequestProcessor - Processed
session termination for sessionid: 0x14f20f84bb80009
130177 [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2000] INFO
org.apache.storm.zookeeper.server.NIOServerCnxn - Closed socket
connection for client /127.0.0.1:46576 which had sessionid 0x14f20f84bb80009
130177 [main-EventThread] INFO org.apache.storm.zookeeper.ClientCnxn -
EventThread shut down
130177 [main] INFO org.apache.storm.zookeeper.ZooKeeper - Session:
0x14f20f84bb80009 closed
130178 [main] INFO backtype.storm.testing - Shutting down in process
zookeeper
130178 [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2000] INFO
org.apache.storm.zookeeper.server.NIOServerCnxnFactory - NIOServerCnxn
factory exited run method
130178 [main] INFO org.apache.storm.zookeeper.server.ZooKeeperServer -
shutting down
130178 [main] INFO org.apache.storm.zookeeper.server.SessionTrackerImpl
- Shutting down
130178 [main] INFO
org.apache.storm.zookeeper.server.PrepRequestProcessor - Shutting down
130179 [main] INFO
org.apache.storm.zookeeper.server.SyncRequestProcessor - Shutting down
130179 [ProcessThread(sid:0 cport:-1):] INFO
org.apache.storm.zookeeper.server.PrepRequestProcessor -
PrepRequestProcessor exited loop!
130179 [SyncThread:0] INFO
org.apache.storm.zookeeper.server.SyncRequestProcessor -
SyncRequestProcessor exited!
130179 [main] INFO
org.apache.storm.zookeeper.server.FinalRequestProcessor - shutdown of
request processor complete
130179 [main] INFO backtype.storm.testing - Done shutting down in
process zookeeper
130179 [main] INFO backtype.storm.testing - Deleting temporary path
/tmp/a7ee2048-5ddb-4c50-a8d1-26544f24c2a7
130182 [main] INFO backtype.storm.testing - Deleting temporary path
/tmp/929f10f9-5371-4405-9e09-c719faf9369d
130182 [main] INFO backtype.storm.testing - Deleting temporary path
/tmp/1c16f0c8-6d9e-4ccc-9517-83c388e334fe
130184 [main] INFO backtype.storm.testing - Deleting temporary path
/tmp/7a6b779a-f6a3-43ce-9fed-b15d8d04ba75
131646 [SessionTracker] INFO
org.apache.storm.zookeeper.server.SessionTrackerImpl -
SessionTrackerImpl exited loop!
And I can not find any error like log, so any one could give me some advise?
thanks!
