Details
-
Improvement
-
Status: Open
-
Minor
-
Resolution: Unresolved
-
None
-
None
-
None
Description
Occasionally, hadoop.ipc.Server throws exception when tasks are finished. like below.
IMO, it doesn't affect system stability at all, but it'd be nice if we can prevent that exception.
2012-02-05 18:58:08,870 INFO org.apache.hama.GroomServerRunner: STARTUP_MSG: /************************************************************ STARTUP_MSG: Starting GroomServer STARTUP_MSG: host = server2/192.168.0.110 STARTUP_MSG: args = [] STARTUP_MSG: version = 0.20.2 STARTUP_MSG: build = -r ; compiled by 'chrisdo' on Wed Mar 10 13:22:54 PST 2010 ************************************************************/ 2012-02-05 18:58:08,936 INFO org.apache.hama.bsp.GroomServer: groom start 2012-02-05 18:58:08,984 INFO org.apache.zookeeper.ZooKeeper: Client environment:zookeeper.version=3.3.3-1073969, built on 02/23/2011 22:27 GMT 2012-02-05 18:58:08,984 INFO org.apache.zookeeper.ZooKeeper: Client environment:host.name=server2.abcfood.org 2012-02-05 18:58:08,984 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.version=1.7.0_02 2012-02-05 18:58:08,984 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.vendor=Oracle Corporation 2012-02-05 18:58:08,984 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.home=/home/userA/jdk1.7.0_02/jre 2012-02-05 18:58:08,984 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.class.path=/home/userA/hama-0.4.0-incubating/bin/../conf:/home/userA/jdk1.7.0_02/lib/tools.jar:/home/userA/hama-0.4.0-incubating/bin/../hama-core-0.4.0-incubating.jar:/home/userA/hama-0.4.0-incubating/bin/../hama-examples-0.4.0-incubating.jar:/home/userA/hama-0.4.0-incubating/bin/../hama-graph-0.4.0-incubating.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/ant-1.7.1.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/ant-launcher-1.7.1.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/commons-cli-1.2.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/commons-logging-1.1.1.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/hadoop-core-0.20.2.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/hadoop-test-0.20.2.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/jetty-6.1.14.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/jetty-annotations-6.1.14.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/jetty-util-6.1.14.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/jsp-2.1-6.1.14.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/jsp-api-2.1-6.1.14.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/junit-4.8.1.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/log4j-1.2.16.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/servlet-api-6.0.32.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/slf4j-api-1.5.8.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/slf4j-log4j12-1.5.8.jar:/home/userA/hama-0.4.0-incubating/bin/../lib/zookeeper-3.3.3.jar 2012-02-05 18:58:08,985 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.library.path=/usr/java/packages/lib/i386:/lib:/usr/lib 2012-02-05 18:58:08,985 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.io.tmpdir=/tmp 2012-02-05 18:58:08,985 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.compiler=<NA> 2012-02-05 18:58:08,985 INFO org.apache.zookeeper.ZooKeeper: Client environment:os.name=Linux 2012-02-05 18:58:08,985 INFO org.apache.zookeeper.ZooKeeper: Client environment:os.arch=i386 2012-02-05 18:58:08,985 INFO org.apache.zookeeper.ZooKeeper: Client environment:os.version=2.6.32-5-686 2012-02-05 18:58:08,985 INFO org.apache.zookeeper.ZooKeeper: Client environment:user.name=userA 2012-02-05 18:58:08,985 INFO org.apache.zookeeper.ZooKeeper: Client environment:user.home=/home/userA 2012-02-05 18:58:08,985 INFO org.apache.zookeeper.ZooKeeper: Client environment:user.dir=/home/userA/hama-0.4.0-incubating 2012-02-05 18:58:08,990 INFO org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=server4:21810 sessionTimeout=1200000 watcher=org.apache.hama.bsp.GroomServer@196978f 2012-02-05 18:58:09,020 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server server4/192.168.0.199:21810 2012-02-05 18:58:09,025 INFO org.apache.hama.bsp.GroomServer: /tmp/hadoop-userA/bsp/local 2012-02-05 18:58:09,040 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to server4/192.168.0.199:21810, initiating session 2012-02-05 18:58:09,141 INFO org.apache.zookeeper.ClientCnxn: Unable to read additional data from server sessionid 0x0, likely server has closed socket, closing socket connection and attempting reconnect 2012-02-05 18:58:09,174 INFO org.apache.hadoop.ipc.metrics.RpcMetrics: Initializing RPC Metrics with hostName=GroomServer, port=50000 2012-02-05 18:58:09,266 INFO org.apache.hadoop.ipc.Server: IPC Server Responder: starting 2012-02-05 18:58:09,266 INFO org.apache.hadoop.ipc.Server: IPC Server listener on 50000: starting 2012-02-05 18:58:09,268 INFO org.apache.hama.bsp.GroomServer: Worker rpc server --> server2.abcfood.org:50000 2012-02-05 18:58:09,268 INFO org.apache.hadoop.ipc.Server: IPC Server handler 0 on 50000: starting 2012-02-05 18:58:09,269 INFO org.apache.hadoop.ipc.metrics.RpcMetrics: Initializing RPC Metrics with hostName=GroomServer, port=53084 2012-02-05 18:58:09,273 INFO org.apache.hadoop.ipc.Server: IPC Server listener on 53084: starting 2012-02-05 18:58:09,273 INFO org.apache.hadoop.ipc.Server: IPC Server Responder: starting 2012-02-05 18:58:09,274 INFO org.apache.hadoop.ipc.Server: IPC Server handler 0 on 53084: starting 2012-02-05 18:58:09,280 INFO org.apache.hadoop.ipc.Server: IPC Server handler 1 on 53084: starting 2012-02-05 18:58:09,282 INFO org.apache.hadoop.ipc.Server: IPC Server handler 2 on 53084: starting 2012-02-05 18:58:09,293 INFO org.apache.hadoop.ipc.Server: IPC Server handler 3 on 53084: starting 2012-02-05 18:58:09,302 INFO org.apache.hadoop.ipc.Server: IPC Server handler 4 on 53084: starting 2012-02-05 18:58:09,308 INFO org.apache.hadoop.ipc.Server: IPC Server handler 5 on 53084: starting 2012-02-05 18:58:09,313 INFO org.apache.hadoop.ipc.Server: IPC Server handler 6 on 53084: starting 2012-02-05 18:58:09,315 INFO org.apache.hadoop.ipc.Server: IPC Server handler 7 on 53084: starting 2012-02-05 18:58:09,316 INFO org.apache.hadoop.ipc.Server: IPC Server handler 8 on 53084: starting 2012-02-05 18:58:09,316 INFO org.apache.hadoop.ipc.Server: IPC Server handler 9 on 53084: starting 2012-02-05 18:58:09,317 INFO org.apache.hama.bsp.GroomServer: GroomServer up at: localhost/127.0.0.1:53084 2012-02-05 18:58:09,317 INFO org.apache.hama.bsp.GroomServer: Starting groom: server2.abcfood.org:50000 2012-02-05 18:58:10,956 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server server4/192.168.0.199:21810 2012-02-05 18:58:10,957 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to server4/192.168.0.199:21810, initiating session 2012-02-05 18:58:10,966 INFO org.apache.zookeeper.ClientCnxn: Session establishment complete on server server4/192.168.0.199:21810, sessionid = 0x1354d29f1b30001, negotiated timeout = 1200000 2012-02-05 19:02:31,046 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 19:02:31,416 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0001_000001_0' has started. 2012-02-05 19:02:31,416 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 19:02:32,210 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0001_000003_0' has started. 2012-02-05 19:02:32,211 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 19:02:32,648 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0001_000005_0' has started. 2012-02-05 19:02:36,282 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0001_000005_0 is done. 2012-02-05 19:02:36,478 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0001_000001_0 is done. 2012-02-05 19:02:36,514 INFO org.apache.hadoop.ipc.Server: IPC Server listener on 53084: readAndProcess threw exception java.io.IOException: Connection reset by peer. Count of bytes read: 0 java.io.IOException: Connection reset by peer at sun.nio.ch.FileDispatcherImpl.read0(Native Method) at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39) at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:218) at sun.nio.ch.IOUtil.read(IOUtil.java:191) at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:359) at org.apache.hadoop.ipc.Server.channelRead(Server.java:1211) at org.apache.hadoop.ipc.Server.access$2300(Server.java:77) at org.apache.hadoop.ipc.Server$Connection.readAndProcess(Server.java:799) at org.apache.hadoop.ipc.Server$Listener.doRead(Server.java:419) at org.apache.hadoop.ipc.Server$Listener.run(Server.java:328) 2012-02-05 19:02:36,653 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0001_000003_0 is done. 2012-02-05 19:25:42,980 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 19:25:43,438 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0002_000000_0' has started. 2012-02-05 19:25:43,439 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 19:25:44,056 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0002_000001_0' has started. 2012-02-05 19:25:44,056 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 19:25:44,675 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0002_000002_0' has started. 2012-02-05 19:25:50,170 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0002_000001_0 is done. 2012-02-05 19:25:50,372 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0002_000000_0 is done. 2012-02-05 19:25:50,377 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0002_000002_0 is done. 2012-02-05 19:26:03,539 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 19:26:03,710 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0003_000003_0' has started. 2012-02-05 19:26:03,711 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 19:26:03,963 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0003_000004_0' has started. 2012-02-05 19:26:03,964 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 19:26:04,170 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0003_000005_0' has started. 2012-02-05 19:26:07,990 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0003_000005_0 is done. 2012-02-05 19:26:08,018 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0003_000004_0 is done. 2012-02-05 19:26:08,062 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0003_000003_0 is done. 2012-02-05 19:28:11,618 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 19:28:11,769 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0004_000003_0' has started. 2012-02-05 19:28:11,782 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 19:28:12,258 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0004_000004_0' has started. 2012-02-05 19:28:12,259 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 19:28:12,612 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0004_000005_0' has started. 2012-02-05 19:28:15,971 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0004_000004_0 is done. 2012-02-05 19:28:16,023 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0004_000005_0 is done. 2012-02-05 19:28:16,143 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0004_000003_0 is done. 2012-02-05 20:54:55,866 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 20:54:56,017 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0005_000003_0' has started. 2012-02-05 20:54:56,017 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 20:54:56,326 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0005_000004_0' has started. 2012-02-05 20:54:56,327 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 20:54:56,655 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0005_000005_0' has started. 2012-02-05 20:54:59,962 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0005_000004_0 is done. 2012-02-05 20:55:00,049 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0005_000005_0 is done. 2012-02-05 20:55:00,102 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0005_000003_0 is done. 2012-02-05 20:55:08,697 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 20:55:08,860 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0006_000001_0' has started. 2012-02-05 20:55:08,865 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 20:55:09,185 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0006_000003_0' has started. 2012-02-05 20:55:09,186 INFO org.apache.hama.bsp.GroomServer: Launch 3 tasks. 2012-02-05 20:55:09,497 INFO org.apache.hama.bsp.GroomServer: Task 'attempt_201202051858_0006_000005_0' has started. 2012-02-05 20:55:13,539 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0006_000001_0 is done. 2012-02-05 20:55:13,582 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0006_000005_0 is done. 2012-02-05 20:55:13,620 INFO org.apache.hama.bsp.GroomServer: Task attempt_201202051858_0006_000003_0 is done. 2012-02-05 20:55:13,623 INFO org.apache.hadoop.ipc.Server: IPC Server listener on 53084: readAndProcess threw exception java.io.IOException: Connection reset by peer. Count of bytes read: 0 java.io.IOException: Connection reset by peer at sun.nio.ch.FileDispatcherImpl.read0(Native Method) at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39) at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:218) at sun.nio.ch.IOUtil.read(IOUtil.java:191) at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:359) at org.apache.hadoop.ipc.Server.channelRead(Server.java:1211) at org.apache.hadoop.ipc.Server.access$2300(Server.java:77) at org.apache.hadoop.ipc.Server$Connection.readAndProcess(Server.java:799) at org.apache.hadoop.ipc.Server$Listener.doRead(Server.java:419) at org.apache.hadoop.ipc.Server$Listener.run(Server.java:328) 2012-02-05 20:56:26,474 INFO org.apache.hama.GroomServerRunner: SHUTDOWN_MSG: /************************************************************ SHUTDOWN_MSG: Shutting down GroomServer at server2/192.168.0.110 ************************************************************/