See http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/838/
------------------------------------------ [...truncated 522229 lines...] [junit] 09/05/18 12:03:49 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=mkdirs src=/testing/out dst=null perm=hudson:supergroup:rwxr-xr-x [junit] 09/05/18 12:03:49 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS); [junit] 09/05/18 12:03:49 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS); [junit] 09/05/18 12:03:49 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=rename src=/testing/out/_temporary/_attempt_200905181203_0001_m_000000_0/part-00000 dst=/testing/out/part-00000 perm=hudson:supergroup:rw-r--r-- [junit] 09/05/18 12:03:49 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS); [junit] 09/05/18 12:03:49 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS); [junit] 09/05/18 12:03:49 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/testing/out/_temporary/_attempt_200905181203_0001_m_000000_0 dst=null perm=null [junit] 09/05/18 12:03:49 INFO mapred.TaskTracker: attempt_200905181203_0001_m_000000_0 1.0% Records R/W=1/1 [junit] 09/05/18 12:03:49 INFO mapred.TaskTracker: Task attempt_200905181203_0001_m_000000_0 is done. [junit] 09/05/18 12:03:49 INFO mapred.TaskTracker: reported output size for attempt_200905181203_0001_m_000000_0 was 0 [junit] 09/05/18 12:03:49 INFO mapred.TaskTracker: addFreeSlot : current free slots : 2 [junit] 09/05/18 12:03:49 WARN util.ProcessTree: Error executing shell command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process [junit] [junit] 09/05/18 12:03:49 INFO util.ProcessTree: Killing all processes in the process group 10641 with SIGTERM. Exit code 1 [junit] 09/05/18 12:03:52 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find taskTracker/jobcache/job_200905181203_0001/attempt_200905181203_0001_m_000000_0/output/file.out in any of the configured local directories [junit] 09/05/18 12:03:52 INFO mapred.JobInProgress: Task 'attempt_200905181203_0001_m_000000_0' has completed task_200905181203_0001_m_000000 successfully. [junit] 09/05/18 12:03:52 INFO mapred.JobTracker: Adding task 'attempt_200905181203_0001_m_000001_0' to tip task_200905181203_0001_m_000001, for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:35766' [junit] 09/05/18 12:03:52 INFO mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_200905181203_0001_m_000001_0 task's state:UNASSIGNED [junit] 09/05/18 12:03:52 INFO mapred.TaskTracker: Trying to launch : attempt_200905181203_0001_m_000001_0 [junit] 09/05/18 12:03:52 INFO mapred.TaskTracker: In TaskLauncher, current free slots : 2 and trying to launch attempt_200905181203_0001_m_000001_0 [junit] 09/05/18 12:03:52 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_200905181203_0001_m_-1989897598 [junit] 09/05/18 12:03:52 INFO mapred.JvmManager: JVM Runner jvm_200905181203_0001_m_-1989897598 spawned. [junit] 09/05/18 12:03:52 INFO mapred.TaskTracker: JVM with ID: jvm_200905181203_0001_m_-1989897598 given task: attempt_200905181203_0001_m_000001_0 [junit] 09/05/18 12:03:52 INFO streaming.StreamJob: map 100% reduce 0% [junit] 09/05/18 12:03:52 INFO mapred.TaskTracker: attempt_200905181203_0001_m_000001_0 0.0% [junit] 09/05/18 12:03:52 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS); [junit] 09/05/18 12:03:52 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS); [junit] 09/05/18 12:03:52 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/testing/out/_temporary dst=null perm=null [junit] 09/05/18 12:03:52 INFO mapred.TaskTracker: attempt_200905181203_0001_m_000001_0 0.0% cleanup [junit] 09/05/18 12:03:52 INFO mapred.TaskTracker: Task attempt_200905181203_0001_m_000001_0 is done. [junit] 09/05/18 12:03:52 INFO mapred.TaskTracker: reported output size for attempt_200905181203_0001_m_000001_0 was 0 [junit] 09/05/18 12:03:52 INFO mapred.TaskTracker: addFreeSlot : current free slots : 2 [junit] 09/05/18 12:03:53 WARN util.ProcessTree: Error executing shell command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process [junit] [junit] 09/05/18 12:03:53 INFO util.ProcessTree: Killing all processes in the process group 10731 with SIGTERM. Exit code 1 [junit] 09/05/18 12:03:54 WARN util.ProcessTree: Error executing shell command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process [junit] [junit] 09/05/18 12:03:54 INFO util.ProcessTree: Killing process group10641 with SIGKILL. Exit code 1 [junit] 09/05/18 12:03:54 INFO mapred.DefaultTaskController: Process exited with exit code:0 [junit] 09/05/18 12:03:54 INFO mapred.JvmManager: JVM : jvm_200905181203_0001_m_875628198 exited. Number of tasks it ran: 1 [junit] 09/05/18 12:03:55 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find taskTracker/jobcache/job_200905181203_0001/attempt_200905181203_0001_m_000001_0/output/file.out in any of the configured local directories [junit] 09/05/18 12:03:55 INFO mapred.JobInProgress: Task 'attempt_200905181203_0001_m_000001_0' has completed task_200905181203_0001_m_000001 successfully. [junit] 09/05/18 12:03:55 INFO mapred.JobInProgress: Job job_200905181203_0001 has completed successfully. [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /testing/out/_logs/history/localhost_1242648208633_job_200905181203_0001_hudson_streamjob5223584783509274135.jar. blk_5329267710104540669_1008 [junit] 09/05/18 12:03:55 INFO datanode.DataNode: Receiving block blk_5329267710104540669_1008 src: /127.0.0.1:32771 dest: /127.0.0.1:36349 [junit] 09/05/18 12:03:55 INFO datanode.DataNode: Receiving block blk_5329267710104540669_1008 src: /127.0.0.1:43399 dest: /127.0.0.1:51526 [junit] 09/05/18 12:03:55 INFO DataNode.clienttrace: src: /127.0.0.1:43399, dest: /127.0.0.1:51526, bytes: 4570, op: HDFS_WRITE, cliID: DFSClient_-716448121, offset: 0, srvID: DS-54190188-67.195.138.9-51526-1242648208385, blockid: blk_5329267710104540669_1008, duration: 1164117 [junit] 09/05/18 12:03:55 INFO datanode.DataNode: PacketResponder 0 for block blk_5329267710104540669_1008 terminating [junit] 09/05/18 12:03:55 INFO DataNode.clienttrace: src: /127.0.0.1:32771, dest: /127.0.0.1:36349, bytes: 4570, op: HDFS_WRITE, cliID: DFSClient_-716448121, offset: 0, srvID: DS-848352829-67.195.138.9-36349-1242648207810, blockid: blk_5329267710104540669_1008, duration: 2736405 [junit] 09/05/18 12:03:55 INFO datanode.DataNode: PacketResponder 1 for block blk_5329267710104540669_1008 terminating [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:51526 is added to blk_5329267710104540669_1008 size 4570 [junit] 09/05/18 12:03:55 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS); [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /testing/out/_logs/history/localhost_1242648208633_job_200905181203_0001_hudson_streamjob5223584783509274135.jar is closed by DFSClient_-716448121 [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:36349 is added to blk_5329267710104540669_1008 size 4570 [junit] 09/05/18 12:03:55 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS); [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3471928555032832492 is added to invalidSet of 127.0.0.1:36349 [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3471928555032832492 is added to invalidSet of 127.0.0.1:51526 [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8227416877586243941 is added to invalidSet of 127.0.0.1:36349 [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8227416877586243941 is added to invalidSet of 127.0.0.1:51526 [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_1186702244191852037 is added to invalidSet of 127.0.0.1:51526 [junit] 09/05/18 12:03:55 INFO mapred.JobTracker: Removed completed task 'attempt_200905181203_0001_m_000000_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:35766' [junit] 09/05/18 12:03:55 INFO mapred.JobTracker: Removed completed task 'attempt_200905181203_0001_m_000001_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:35766' [junit] 09/05/18 12:03:55 INFO mapred.JobTracker: Removed completed task 'attempt_200905181203_0001_m_000002_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:35766' [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_1186702244191852037 is added to invalidSet of 127.0.0.1:36349 [junit] 09/05/18 12:03:55 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS); [junit] 09/05/18 12:03:55 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_200905181203_0001 [junit] 09/05/18 12:03:55 INFO mapred.TaskRunner: attempt_200905181203_0001_m_000001_0 done; removing files. [junit] 09/05/18 12:03:55 INFO mapred.IndexCache: Map ID attempt_200905181203_0001_m_000001_0 not found in cache [junit] 09/05/18 12:03:55 INFO mapred.TaskRunner: attempt_200905181203_0001_m_000000_0 done; removing files. [junit] 09/05/18 12:03:55 INFO mapred.IndexCache: Map ID attempt_200905181203_0001_m_000000_0 not found in cache [junit] 09/05/18 12:03:55 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS); [junit] 09/05/18 12:03:55 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/user/hudson/build/contrib/streaming/test/system/job_200905181203_0001 dst=null perm=null [junit] 09/05/18 12:03:55 INFO streaming.StreamJob: Job complete: job_200905181203_0001 [junit] 09/05/18 12:03:55 INFO streaming.StreamJob: Output: /testing/out [junit] 09/05/18 12:03:55 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=listStatus src=/testing/out dst=null perm=null [junit] 09/05/18 12:03:55 INFO mapred.TestMiniMRWithDFS: File list[0]: hdfs://localhost:36502/testing/out/part-00000 [junit] 09/05/18 12:03:55 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/testing/out/part-00000 dst=null perm=null [junit] 09/05/18 12:03:55 INFO DataNode.clienttrace: src: /127.0.0.1:36349, dest: /127.0.0.1:32773, bytes: 12, op: HDFS_READ, cliID: DFSClient_-716448121, offset: 0, srvID: DS-848352829-67.195.138.9-36349-1242648207810, blockid: blk_-3376537034392740006_1008, duration: 256853 [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_4905938530277429397 is added to invalidSet of 127.0.0.1:36349 [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_4905938530277429397 is added to invalidSet of 127.0.0.1:51526 [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_5329267710104540669 is added to invalidSet of 127.0.0.1:51526 [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_5329267710104540669 is added to invalidSet of 127.0.0.1:36349 [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-3376537034392740006 is added to invalidSet of 127.0.0.1:51526 [junit] 09/05/18 12:03:55 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-3376537034392740006 is added to invalidSet of 127.0.0.1:36349 [junit] 09/05/18 12:03:55 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS); [junit] 09/05/18 12:03:55 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS); [junit] 09/05/18 12:03:55 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/testing/out dst=null perm=null [junit] 09/05/18 12:03:55 INFO mapred.TaskTracker: Shutting down: Map-events fetcher for all reduce tasks on tracker_host0.foo.com:localhost/127.0.0.1:55645 [junit] 09/05/18 12:03:55 INFO ipc.Server: Stopping server on 55645 [junit] 09/05/18 12:03:55 INFO ipc.Server: Stopping IPC Server listener on 55645 [junit] 09/05/18 12:03:55 INFO ipc.Server: Stopping IPC Server Responder [junit] 09/05/18 12:03:55 INFO mapred.TaskTracker: Shutting down StatusHttpServer [junit] 09/05/18 12:03:55 INFO ipc.Server: IPC Server handler 1 on 55645: exiting [junit] 09/05/18 12:03:55 INFO ipc.Server: IPC Server handler 2 on 55645: exiting [junit] 09/05/18 12:03:55 INFO ipc.Server: IPC Server handler 3 on 55645: exiting [junit] 09/05/18 12:03:55 INFO ipc.Server: IPC Server handler 0 on 55645: exiting [junit] 09/05/18 12:03:56 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:36349 to delete blk_5329267710104540669_1008 blk_1186702244191852037_1005 blk_-8227416877586243941_1004 blk_-3376537034392740006_1008 blk_3471928555032832492_1003 blk_4905938530277429397_1007 [junit] 09/05/18 12:03:57 INFO datanode.DataNode: Deleting block blk_-8227416877586243941_1004 file http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data2/current/blk_-8227416877586243941 [junit] 09/05/18 12:03:57 INFO datanode.DataNode: Deleting block blk_-3376537034392740006_1008 file http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data1/current/blk_-3376537034392740006 [junit] 09/05/18 12:03:57 INFO datanode.DataNode: Deleting block blk_1186702244191852037_1005 file http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data1/current/blk_1186702244191852037 [junit] 09/05/18 12:03:57 INFO datanode.DataNode: Deleting block blk_3471928555032832492_1003 file http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data1/current/blk_3471928555032832492 [junit] 09/05/18 12:03:57 INFO datanode.DataNode: Deleting block blk_4905938530277429397_1007 file http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data2/current/blk_4905938530277429397 [junit] 09/05/18 12:03:57 INFO datanode.DataNode: Deleting block blk_5329267710104540669_1008 file http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data2/current/blk_5329267710104540669 [junit] 09/05/18 12:03:58 WARN util.ProcessTree: Error executing shell command org.apache.hadoop.util.Shell$ExitCodeException: kill: No such process [junit] [junit] 09/05/18 12:03:58 INFO util.ProcessTree: Killing process group10731 with SIGKILL. Exit code 1 [junit] 09/05/18 12:03:58 INFO mapred.DefaultTaskController: Process exited with exit code:0 [junit] 09/05/18 12:03:58 INFO mapred.JvmManager: JVM : jvm_200905181203_0001_m_-1989897598 exited. Number of tasks it ran: 1 [junit] 09/05/18 12:03:59 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:51526 to delete blk_5329267710104540669_1008 blk_1186702244191852037_1005 blk_-8227416877586243941_1004 blk_-3376537034392740006_1008 blk_3471928555032832492_1003 blk_4905938530277429397_1007 [junit] 09/05/18 12:04:01 INFO datanode.DataNode: Deleting block blk_-8227416877586243941_1004 file http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data4/current/blk_-8227416877586243941 [junit] 09/05/18 12:04:01 INFO datanode.DataNode: Deleting block blk_-3376537034392740006_1008 file http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data3/current/blk_-3376537034392740006 [junit] 09/05/18 12:04:01 INFO datanode.DataNode: Deleting block blk_1186702244191852037_1005 file http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data3/current/blk_1186702244191852037 [junit] 09/05/18 12:04:01 INFO datanode.DataNode: Deleting block blk_3471928555032832492_1003 file http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data3/current/blk_3471928555032832492 [junit] 09/05/18 12:04:01 INFO datanode.DataNode: Deleting block blk_4905938530277429397_1007 file http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data4/current/blk_4905938530277429397 [junit] 09/05/18 12:04:01 INFO datanode.DataNode: Deleting block blk_5329267710104540669_1008 file http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data4/current/blk_5329267710104540669 [junit] 09/05/18 12:04:49 INFO datanode.DataBlockScanner: Verification succeeded for blk_-4805327476164772847_1001 [junit] 09/05/18 12:04:55 ERROR mapred.TaskTracker: Caught exception: java.io.IOException: Call to localhost/127.0.0.1:55972 failed on local exception: java.nio.channels.ClosedByInterruptException [junit] at org.apache.hadoop.ipc.Client.wrapException(Client.java:778) [junit] at org.apache.hadoop.ipc.Client.call(Client.java:746) [junit] at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220) [junit] at org.apache.hadoop.mapred.$Proxy6.heartbeat(Unknown Source) [junit] at org.apache.hadoop.mapred.TaskTracker.transmitHeartBeat(TaskTracker.java:1263) [junit] at org.apache.hadoop.mapred.TaskTracker.offerService(TaskTracker.java:1085) [junit] at org.apache.hadoop.mapred.TaskTracker.run(TaskTracker.java:1808) [junit] at org.apache.hadoop.mapred.MiniMRCluster$TaskTrackerRunner.run(MiniMRCluster.java:193) [junit] at java.lang.Thread.run(Thread.java:619) [junit] Caused by: java.nio.channels.ClosedByInterruptException [junit] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:184) [junit] at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:341) [junit] at org.apache.hadoop.net.SocketOutputStream$Writer.performIO(SocketOutputStream.java:55) [junit] at org.apache.hadoop.net.SocketIOWithTimeout.doIO(SocketIOWithTimeout.java:142) [junit] at org.apache.hadoop.net.SocketOutputStream.write(SocketOutputStream.java:146) [junit] at org.apache.hadoop.net.SocketOutputStream.write(SocketOutputStream.java:107) [junit] at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65) [junit] at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123) [junit] at java.io.DataOutputStream.flush(DataOutputStream.java:106) [junit] at org.apache.hadoop.ipc.Client$Connection.sendParam(Client.java:484) [junit] at org.apache.hadoop.ipc.Client.call(Client.java:724) [junit] ... 7 more [junit] [junit] 09/05/18 12:04:55 INFO mapred.TaskTracker: Shutting down: Map-events fetcher for all reduce tasks on tracker_host1.foo.com:localhost/127.0.0.1:35766 [junit] 09/05/18 12:04:55 INFO ipc.Server: Stopping server on 35766 [junit] 09/05/18 12:04:55 INFO ipc.Server: IPC Server handler 2 on 35766: exiting [junit] 09/05/18 12:04:55 INFO ipc.Server: IPC Server handler 3 on 35766: exiting [junit] 09/05/18 12:04:55 INFO ipc.Server: IPC Server handler 1 on 35766: exiting [junit] 09/05/18 12:04:55 INFO ipc.Server: IPC Server handler 0 on 35766: exiting [junit] 09/05/18 12:04:55 INFO ipc.Server: Stopping IPC Server listener on 35766 [junit] 09/05/18 12:04:55 INFO ipc.Server: Stopping IPC Server Responder [junit] 09/05/18 12:04:55 INFO mapred.TaskTracker: Shutting down StatusHttpServer [junit] 09/05/18 12:04:55 INFO mapred.TaskTracker: Interrupted. Closing down. [junit] 09/05/18 12:04:55 INFO mapred.JobTracker: Stopping infoServer [junit] 09/05/18 12:04:56 INFO mapred.JobTracker: Stopping interTrackerServer [junit] 09/05/18 12:04:56 INFO ipc.Server: Stopping server on 55972 [junit] 09/05/18 12:04:56 INFO ipc.Server: IPC Server handler 3 on 55972: exiting [junit] 09/05/18 12:04:56 INFO ipc.Server: IPC Server handler 5 on 55972: exiting [junit] 09/05/18 12:04:56 INFO ipc.Server: IPC Server handler 9 on 55972: exiting [junit] 09/05/18 12:04:56 INFO mapred.JobTracker: Stopped interTrackerServer [junit] 09/05/18 12:04:56 INFO mapred.JobTracker: Stopping expireTrackers [junit] 09/05/18 12:04:56 INFO ipc.Server: IPC Server handler 1 on 55972: exiting [junit] 09/05/18 12:04:56 INFO ipc.Server: IPC Server handler 8 on 55972: exiting [junit] 09/05/18 12:04:56 INFO ipc.Server: IPC Server handler 0 on 55972: exiting [junit] 09/05/18 12:04:56 INFO ipc.Server: Stopping IPC Server Responder [junit] 09/05/18 12:04:56 INFO mapred.JobTracker: Stopping retirer [junit] 09/05/18 12:04:56 INFO ipc.Server: IPC Server handler 7 on 55972: exiting [junit] 09/05/18 12:04:56 INFO mapred.EagerTaskInitializationListener: Stopping Job Init Manager thread [junit] 09/05/18 12:04:56 INFO ipc.Server: IPC Server handler 6 on 55972: exiting [junit] 09/05/18 12:04:56 INFO ipc.Server: IPC Server handler 4 on 55972: exiting [junit] 09/05/18 12:04:56 INFO ipc.Server: IPC Server handler 2 on 55972: exiting [junit] 09/05/18 12:04:56 INFO ipc.Server: Stopping IPC Server listener on 55972 [junit] 09/05/18 12:04:56 INFO mapred.EagerTaskInitializationListener: JobInitManagerThread interrupted. [junit] 09/05/18 12:04:56 INFO mapred.EagerTaskInitializationListener: Shutting down thread pool [junit] 09/05/18 12:04:56 INFO mapred.JobTracker: Stopping expireLaunchingTasks [junit] 09/05/18 12:04:56 INFO mapred.JobTracker: stopped all jobtracker services [junit] Shutting down the Mini HDFS Cluster [junit] Shutting down DataNode 1 [junit] 09/05/18 12:04:56 INFO ipc.Server: Stopping server on 56965 [junit] 09/05/18 12:04:56 INFO ipc.Server: IPC Server handler 2 on 56965: exiting [junit] 09/05/18 12:04:56 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1 [junit] 09/05/18 12:04:56 INFO ipc.Server: IPC Server handler 0 on 56965: exiting [junit] 09/05/18 12:04:56 INFO ipc.Server: Stopping IPC Server Responder [junit] 09/05/18 12:04:56 INFO ipc.Server: Stopping IPC Server listener on 56965 [junit] 09/05/18 12:04:56 INFO ipc.Server: IPC Server handler 1 on 56965: exiting [junit] 09/05/18 12:04:56 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:51526, storageID=DS-54190188-67.195.138.9-51526-1242648208385, infoPort=54596, ipcPort=56965):DataXceiveServer: java.nio.channels.AsynchronousCloseException [junit] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:185) [junit] at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:152) [junit] at sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:84) [junit] at org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:130) [junit] at java.lang.Thread.run(Thread.java:619) [junit] [junit] 09/05/18 12:04:56 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread. [junit] 09/05/18 12:04:57 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0 [junit] 09/05/18 12:04:57 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:51526, storageID=DS-54190188-67.195.138.9-51526-1242648208385, infoPort=54596, ipcPort=56965):Finishing DataNode in: FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data3/current,/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/data/data4/current'} [junit] 09/05/18 12:04:57 INFO ipc.Server: Stopping server on 56965 [junit] 09/05/18 12:04:57 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0 [junit] Shutting down DataNode 0 [junit] 09/05/18 12:04:57 INFO ipc.Server: Stopping server on 43611 [junit] 09/05/18 12:04:57 INFO ipc.Server: IPC Server handler 2 on 43611: exiting [junit] 09/05/18 12:04:57 INFO ipc.Server: IPC Server handler 0 on 43611: exiting [junit] 09/05/18 12:04:57 INFO ipc.Server: IPC Server handler 1 on 43611: exiting [junit] 09/05/18 12:04:57 INFO ipc.Server: Stopping IPC Server Responder [junit] 09/05/18 12:04:57 INFO ipc.Server: Stopping IPC Server listener on 43611 [junit] 09/05/18 12:04:57 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:36349, storageID=DS-848352829-67.195.138.9-36349-1242648207810, infoPort=59615, ipcPort=43611):DataXceiveServer: java.nio.channels.AsynchronousCloseException [junit] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:185) [junit] at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:152) [junit] at sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:84) [junit] at org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:130) [junit] at java.lang.Thread.run(Thread.java:619) [junit] [junit] 09/05/18 12:04:57 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0 [junit] 09/05/18 12:04:57 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread. [junit] 09/05/18 12:04:57 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:36349, storageID=DS-848352829-67.195.138.9-36349-1242648207810, infoPort=59615, ipcPort=43611):Finishing DataNode in: FSDataset{dirpath='http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/data/data1/current,/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/data/data2/current'} [junit] 09/05/18 12:04:57 INFO ipc.Server: Stopping server on 43611 [junit] 09/05/18 12:04:57 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0 [junit] 09/05/18 12:04:57 WARN namenode.FSNamesystem: ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted [junit] 09/05/18 12:04:57 INFO namenode.FSNamesystem: Number of transactions: 51 Total time for transactions(ms): 9Number of transactions batched in Syncs: 1 Number of syncs: 34 SyncTimes(ms): 345 247 [junit] 09/05/18 12:04:57 WARN namenode.DecommissionManager: Monitor interrupted: java.lang.InterruptedException: sleep interrupted [junit] 09/05/18 12:04:57 INFO namenode.FSNamesystem: current list of storage dirs:http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build/contrib/streaming/test/data/dfs/name1(IMAGE_AND_EDITS);/home/hudson/hudson-slave/workspace/Hadoop-trunk/trunk/build/contrib/streaming/test/data/dfs/name2(IMAGE_AND_EDITS); [junit] 09/05/18 12:04:57 INFO ipc.Server: Stopping server on 36502 [junit] 09/05/18 12:04:57 INFO ipc.Server: IPC Server handler 1 on 36502: exiting [junit] 09/05/18 12:04:57 INFO ipc.Server: IPC Server handler 2 on 36502: exiting [junit] 09/05/18 12:04:57 INFO ipc.Server: IPC Server handler 3 on 36502: exiting [junit] 09/05/18 12:04:57 INFO ipc.Server: IPC Server handler 0 on 36502: exiting [junit] 09/05/18 12:04:57 INFO ipc.Server: IPC Server handler 5 on 36502: exiting [junit] 09/05/18 12:04:57 INFO ipc.Server: IPC Server handler 9 on 36502: exiting [junit] 09/05/18 12:04:57 INFO ipc.Server: IPC Server handler 6 on 36502: exiting [junit] 09/05/18 12:04:57 INFO ipc.Server: IPC Server handler 4 on 36502: exiting [junit] 09/05/18 12:04:57 INFO ipc.Server: IPC Server handler 7 on 36502: exiting [junit] 09/05/18 12:04:57 INFO ipc.Server: IPC Server handler 8 on 36502: exiting [junit] 09/05/18 12:04:57 INFO ipc.Server: Stopping IPC Server listener on 36502 [junit] 09/05/18 12:04:57 INFO ipc.Server: Stopping IPC Server Responder [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 91.964 sec [junit] Running org.apache.hadoop.typedbytes.TestIO [junit] 09/05/18 12:04:57 WARN conf.Configuration: DEPRECATED: hadoop-site.xml found in the classpath. Usage of hadoop-site.xml is deprecated. Instead use core-site.xml, mapred-site.xml and hdfs-site.xml to override properties of core-default.xml, mapred-default.xml and hdfs-default.xml respectively [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.247 sec [junit] Running org.apache.hadoop.typedbytes.TestTypedBytesWritable [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.191 sec BUILD FAILED http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1046: The following error occurred while executing this line: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/build.xml :1027: The following error occurred while executing this line: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/src/contrib/build.xml :48: The following error occurred while executing this line: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/src/contrib/streaming/build.xml :42: The following error occurred while executing this line: http://hudson.zones.apache.org/hudson/job/Hadoop-trunk/ws/trunk/src/contrib/build-contrib.xml :250: Tests failed! Total time: 232 minutes 52 seconds Publishing Javadoc Recording test results Recording fingerprints Publishing Clover coverage report...