You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@pig.apache.org by Apache Hudson Server <hu...@hudson.zones.apache.org> on 2009/10/10 03:00:25 UTC
Build failed in Hudson: Pig-trunk #583
See <http://hudson.zones.apache.org/hudson/job/Pig-trunk/583/changes>
Changes:
[daijy] PIG-995: Limit Optimizer throw exception 'ERROR 2156: Error while fixing projections'
[daijy] PIG-894: order-by fails when input is empty
------------------------------------------
[...truncated 166540 lines...]
[junit] 09/10/10 00:58:52 INFO DataNode.clienttrace: src: /127.0.0.1:48035, dest: /127.0.0.1:36513, bytes: 1859, op: HDFS_WRITE, cliID: DFSClient_-77174316, srvID: DS-286696190-127.0.1.1-36513-1255136299705, blockid: blk_-1334121746913284522_1014
[junit] 09/10/10 00:58:52 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:36513 is added to blk_-1334121746913284522_1014 size 1859
[junit] 09/10/10 00:58:52 INFO datanode.DataNode: PacketResponder 0 for block blk_-1334121746913284522_1014 terminating
[junit] 09/10/10 00:58:52 INFO DataNode.clienttrace: src: /127.0.0.1:52427, dest: /127.0.0.1:35232, bytes: 1859, op: HDFS_WRITE, cliID: DFSClient_-77174316, srvID: DS-1003288558-127.0.1.1-35232-1255136299143, blockid: blk_-1334121746913284522_1014
[junit] 09/10/10 00:58:52 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:35232 is added to blk_-1334121746913284522_1014 size 1859
[junit] 09/10/10 00:58:52 INFO datanode.DataNode: PacketResponder 1 for block blk_-1334121746913284522_1014 terminating
[junit] 09/10/10 00:58:52 INFO DataNode.clienttrace: src: /127.0.0.1:60317, dest: /127.0.0.1:57908, bytes: 1859, op: HDFS_WRITE, cliID: DFSClient_-77174316, srvID: DS-2066684421-127.0.1.1-57908-1255136298560, blockid: blk_-1334121746913284522_1014
[junit] 09/10/10 00:58:52 INFO datanode.DataNode: PacketResponder 2 for block blk_-1334121746913284522_1014 terminating
[junit] 09/10/10 00:58:52 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57908 is added to blk_-1334121746913284522_1014 size 1859
[junit] 09/10/10 00:58:52 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/hadoop-hudson/mapred/system/job_20091010005819797_0002/job.split is closed by DFSClient_-77174316
[junit] 09/10/10 00:58:52 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=create src=/tmp/hadoop-hudson/mapred/system/job_20091010005819797_0002/job.xml dst=null perm=hudson:supergroup:rw-r--r--
[junit] 09/10/10 00:58:52 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=setPermission src=/tmp/hadoop-hudson/mapred/system/job_20091010005819797_0002/job.xml dst=null perm=hudson:supergroup:rw-r--r--
[junit] 09/10/10 00:58:52 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/hadoop-hudson/mapred/system/job_20091010005819797_0002/job.xml. blk_8761924747304658191_1015
[junit] 09/10/10 00:58:52 INFO datanode.DataNode: Receiving block blk_8761924747304658191_1015 src: /127.0.0.1:60320 dest: /127.0.0.1:57908
[junit] 09/10/10 00:58:52 INFO datanode.DataNode: Receiving block blk_8761924747304658191_1015 src: /127.0.0.1:52430 dest: /127.0.0.1:35232
[junit] 09/10/10 00:58:52 INFO datanode.DataNode: Receiving block blk_8761924747304658191_1015 src: /127.0.0.1:48038 dest: /127.0.0.1:36513
[junit] 09/10/10 00:58:52 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:36513 is added to blk_8761924747304658191_1015 size 48254
[junit] 09/10/10 00:58:52 INFO DataNode.clienttrace: src: /127.0.0.1:48038, dest: /127.0.0.1:36513, bytes: 48254, op: HDFS_WRITE, cliID: DFSClient_-77174316, srvID: DS-286696190-127.0.1.1-36513-1255136299705, blockid: blk_8761924747304658191_1015
[junit] 09/10/10 00:58:52 INFO datanode.DataNode: PacketResponder 0 for block blk_8761924747304658191_1015 terminating
[junit] 09/10/10 00:58:52 INFO DataNode.clienttrace: src: /127.0.0.1:52430, dest: /127.0.0.1:35232, bytes: 48254, op: HDFS_WRITE, cliID: DFSClient_-77174316, srvID: DS-1003288558-127.0.1.1-35232-1255136299143, blockid: blk_8761924747304658191_1015
[junit] 09/10/10 00:58:52 INFO datanode.DataNode: PacketResponder 1 for block blk_8761924747304658191_1015 terminating
[junit] 09/10/10 00:58:52 INFO DataNode.clienttrace: src: /127.0.0.1:60320, dest: /127.0.0.1:57908, bytes: 48254, op: HDFS_WRITE, cliID: DFSClient_-77174316, srvID: DS-2066684421-127.0.1.1-57908-1255136298560, blockid: blk_8761924747304658191_1015
[junit] 09/10/10 00:58:52 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:35232 is added to blk_8761924747304658191_1015 size 48254
[junit] 09/10/10 00:58:52 INFO datanode.DataNode: PacketResponder 2 for block blk_8761924747304658191_1015 terminating
[junit] 09/10/10 00:58:52 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57908 is added to blk_8761924747304658191_1015 size 48254
[junit] 09/10/10 00:58:52 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/hadoop-hudson/mapred/system/job_20091010005819797_0002/job.xml is closed by DFSClient_-77174316
[junit] 09/10/10 00:58:52 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/hadoop-hudson/mapred/system/job_20091010005819797_0002/job.xml dst=null perm=null
[junit] 09/10/10 00:58:52 INFO DataNode.clienttrace: src: /127.0.0.1:36513, dest: /127.0.0.1:48039, bytes: 48634, op: HDFS_READ, cliID: DFSClient_-77174316, srvID: DS-286696190-127.0.1.1-36513-1255136299705, blockid: blk_8761924747304658191_1015
[junit] 09/10/10 00:58:52 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/hadoop-hudson/mapred/system/job_20091010005819797_0002/job.jar dst=null perm=null
[junit] 09/10/10 00:58:52 INFO DataNode.clienttrace: src: /127.0.0.1:57908, dest: /127.0.0.1:60324, bytes: 2483736, op: HDFS_READ, cliID: DFSClient_-77174316, srvID: DS-2066684421-127.0.1.1-57908-1255136298560, blockid: blk_3750071453426248789_1013
[junit] 09/10/10 00:58:52 INFO mapred.JobTracker: Initializing job_20091010005819797_0002
[junit] 09/10/10 00:58:52 INFO mapred.JobInProgress: Initializing job_20091010005819797_0002
[junit] 09/10/10 00:58:52 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=create src=/tmp/temp-1427071197/tmp-783301132/_logs/history/localhost_1255136299820_job_20091010005819797_0002_hudson_Job3756228276918050786.jar dst=null perm=hudson:supergroup:rw-r--r--
[junit] 09/10/10 00:58:53 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=create src=/tmp/temp-1427071197/tmp-783301132/_logs/history/localhost_1255136299820_job_20091010005819797_0002_conf.xml dst=null perm=hudson:supergroup:rw-r--r--
[junit] 09/10/10 00:58:53 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/temp-1427071197/tmp-783301132/_logs/history/localhost_1255136299820_job_20091010005819797_0002_conf.xml. blk_2753248026776011957_1017
[junit] 09/10/10 00:58:53 INFO datanode.DataNode: Receiving block blk_2753248026776011957_1017 src: /127.0.0.1:60325 dest: /127.0.0.1:57908
[junit] 09/10/10 00:58:53 INFO datanode.DataNode: Receiving block blk_2753248026776011957_1017 src: /127.0.0.1:34706 dest: /127.0.0.1:55577
[junit] 09/10/10 00:58:53 INFO datanode.DataNode: Receiving block blk_2753248026776011957_1017 src: /127.0.0.1:52436 dest: /127.0.0.1:35232
[junit] 09/10/10 00:58:53 INFO DataNode.clienttrace: src: /127.0.0.1:52436, dest: /127.0.0.1:35232, bytes: 48284, op: HDFS_WRITE, cliID: DFSClient_-77174316, srvID: DS-1003288558-127.0.1.1-35232-1255136299143, blockid: blk_2753248026776011957_1017
[junit] 09/10/10 00:58:53 INFO datanode.DataNode: PacketResponder 0 for block blk_2753248026776011957_1017 terminating
[junit] 09/10/10 00:58:53 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:35232 is added to blk_2753248026776011957_1017 size 48284
[junit] 09/10/10 00:58:53 INFO DataNode.clienttrace: src: /127.0.0.1:34706, dest: /127.0.0.1:55577, bytes: 48284, op: HDFS_WRITE, cliID: DFSClient_-77174316, srvID: DS-763709620-127.0.1.1-55577-1255136297957, blockid: blk_2753248026776011957_1017
[junit] 09/10/10 00:58:53 INFO datanode.DataNode: PacketResponder 1 for block blk_2753248026776011957_1017 terminating
[junit] 09/10/10 00:58:53 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:55577 is added to blk_2753248026776011957_1017 size 48284
[junit] 09/10/10 00:58:53 INFO DataNode.clienttrace: src: /127.0.0.1:60325, dest: /127.0.0.1:57908, bytes: 48284, op: HDFS_WRITE, cliID: DFSClient_-77174316, srvID: DS-2066684421-127.0.1.1-57908-1255136298560, blockid: blk_2753248026776011957_1017
[junit] 09/10/10 00:58:53 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57908 is added to blk_2753248026776011957_1017 size 48284
[junit] 09/10/10 00:58:53 INFO datanode.DataNode: PacketResponder 2 for block blk_2753248026776011957_1017 terminating
[junit] 09/10/10 00:58:53 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/temp-1427071197/tmp-783301132/_logs/history/localhost_1255136299820_job_20091010005819797_0002_conf.xml is closed by DFSClient_-77174316
[junit] 09/10/10 00:58:53 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/hadoop-hudson/mapred/system/job_20091010005819797_0002/job.split dst=null perm=null
[junit] 09/10/10 00:58:53 INFO DataNode.clienttrace: src: /127.0.0.1:36513, dest: /127.0.0.1:48044, bytes: 1875, op: HDFS_READ, cliID: DFSClient_-77174316, srvID: DS-286696190-127.0.1.1-36513-1255136299705, blockid: blk_-1334121746913284522_1014
[junit] 09/10/10 00:58:53 INFO mapred.JobInProgress: Input size for job job_20091010005819797_0002 = 12. Number of splits = 2
[junit] 09/10/10 00:58:53 INFO mapred.JobInProgress: tip:task_20091010005819797_0002_m_000000 has split on node:/default-rack/h7.grid.sp2.yahoo.net
[junit] 09/10/10 00:58:53 INFO mapred.JobInProgress: tip:task_20091010005819797_0002_m_000001 has split on node:/default-rack/h7.grid.sp2.yahoo.net
[junit] 09/10/10 00:58:53 INFO mapReduceLayer.MapReduceLauncher: Submitting job: job_20091010005819797_0002 to execution engine.
[junit] 09/10/10 00:58:53 INFO mapReduceLayer.MapReduceLauncher: More information at: http://localhost:60544/jobdetails.jsp?jobid=job_20091010005819797_0002
[junit] 09/10/10 00:58:53 INFO mapReduceLayer.MapReduceLauncher: To kill this job, use: kill job_20091010005819797_0002
[junit] 09/10/10 00:58:53 INFO datanode.DataNode: Deleting block blk_-4052760131583957924_1006 file build/test/data/dfs/data/data2/current/blk_-4052760131583957924
[junit] 09/10/10 00:58:53 INFO datanode.DataNode: Deleting block blk_-1316834933025031654_1007 file build/test/data/dfs/data/data1/current/blk_-1316834933025031654
[junit] 09/10/10 00:58:54 INFO mapReduceLayer.MapReduceLauncher: 0% complete
[junit] 09/10/10 00:58:54 INFO mapred.JobTracker: Adding task 'attempt_20091010005819797_0002_m_000003_0' to tip task_20091010005819797_0002_m_000003, for tracker 'tracker_host0.foo.com:localhost/127.0.0.1:45897'
[junit] 09/10/10 00:58:54 INFO mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_20091010005819797_0002_m_000003_0 task's state:UNASSIGNED
[junit] 09/10/10 00:58:54 INFO mapred.TaskTracker: Trying to launch : attempt_20091010005819797_0002_m_000003_0
[junit] 09/10/10 00:58:54 INFO mapred.TaskTracker: In TaskLauncher, current free slots : 2 and trying to launch attempt_20091010005819797_0002_m_000003_0
[junit] 09/10/10 00:58:54 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/hadoop-hudson/mapred/system/job_20091010005819797_0002/job.xml dst=null perm=null
[junit] 09/10/10 00:58:54 INFO DataNode.clienttrace: src: /127.0.0.1:35232, dest: /127.0.0.1:52438, bytes: 48634, op: HDFS_READ, cliID: DFSClient_-77174316, srvID: DS-1003288558-127.0.1.1-35232-1255136299143, blockid: blk_8761924747304658191_1015
[junit] 09/10/10 00:58:54 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/hadoop-hudson/mapred/system/job_20091010005819797_0002/job.jar dst=null perm=null
[junit] 09/10/10 00:58:54 INFO DataNode.clienttrace: src: /127.0.0.1:57908, dest: /127.0.0.1:60330, bytes: 2483736, op: HDFS_READ, cliID: DFSClient_-77174316, srvID: DS-2066684421-127.0.1.1-57908-1255136298560, blockid: blk_3750071453426248789_1013
[junit] 09/10/10 00:58:54 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_20091010005819797_0002_m_1857093865
[junit] 09/10/10 00:58:54 INFO mapred.JvmManager: JVM Runner jvm_20091010005819797_0002_m_1857093865 spawned.
[junit] 09/10/10 00:58:54 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:36513 to delete blk_3750071453426248789_1013
[junit] 09/10/10 00:58:55 INFO mapred.TaskTracker: JVM with ID: jvm_20091010005819797_0002_m_1857093865 given task: attempt_20091010005819797_0002_m_000003_0
[junit] 09/10/10 00:58:55 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=mkdirs src=/tmp/temp-1427071197/tmp-783301132/_temporary dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 09/10/10 00:58:55 INFO mapred.TaskTracker: attempt_20091010005819797_0002_m_000003_0 0.0% setup
[junit] 09/10/10 00:58:55 INFO mapred.TaskTracker: Task attempt_20091010005819797_0002_m_000003_0 is done.
[junit] 09/10/10 00:58:55 INFO mapred.TaskTracker: reported output size for attempt_20091010005819797_0002_m_000003_0 was 0
[junit] 09/10/10 00:58:55 INFO mapred.TaskTracker: addFreeSlot : current free slots : 2
[junit] 09/10/10 00:58:55 INFO mapred.JvmManager: JVM : jvm_20091010005819797_0002_m_1857093865 exited. Number of tasks it ran: 1
[junit] 09/10/10 00:58:55 INFO datanode.DataNode: Deleting block blk_3750071453426248789_1013 file build/test/data/dfs/data/data7/current/blk_3750071453426248789
[junit] 09/10/10 00:58:57 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find taskTracker/jobcache/job_20091010005819797_0002/attempt_20091010005819797_0002_m_000003_0/output/file.out in any of the configured local directories
[junit] 09/10/10 00:58:57 INFO mapred.JobInProgress: Task 'attempt_20091010005819797_0002_m_000003_0' has completed task_20091010005819797_0002_m_000003 successfully.
[junit] 09/10/10 00:58:57 INFO mapred.JobTracker: Adding task 'attempt_20091010005819797_0002_m_000000_0' to tip task_20091010005819797_0002_m_000000, for tracker 'tracker_host0.foo.com:localhost/127.0.0.1:45897'
[junit] 09/10/10 00:58:57 INFO mapred.JobInProgress: Choosing rack-local task task_20091010005819797_0002_m_000000
[junit] 09/10/10 00:58:57 INFO mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_20091010005819797_0002_m_000000_0 task's state:UNASSIGNED
[junit] 09/10/10 00:58:57 INFO mapred.TaskTracker: Trying to launch : attempt_20091010005819797_0002_m_000000_0
[junit] 09/10/10 00:58:57 INFO mapred.TaskTracker: Received KillTaskAction for task: attempt_20091010005819797_0002_m_000003_0
[junit] 09/10/10 00:58:57 INFO mapred.TaskTracker: About to purge task: attempt_20091010005819797_0002_m_000003_0
[junit] 09/10/10 00:58:57 INFO mapred.TaskTracker: In TaskLauncher, current free slots : 2 and trying to launch attempt_20091010005819797_0002_m_000000_0
[junit] 09/10/10 00:58:57 INFO mapred.TaskRunner: attempt_20091010005819797_0002_m_000003_0 done; removing files.
[junit] 09/10/10 00:58:57 INFO mapred.IndexCache: Map ID attempt_20091010005819797_0002_m_000003_0 not found in cache
[junit] 09/10/10 00:58:57 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_20091010005819797_0002_m_-832698438
[junit] 09/10/10 00:58:57 INFO mapred.JvmManager: JVM Runner jvm_20091010005819797_0002_m_-832698438 spawned.
[junit] 09/10/10 00:58:57 INFO mapred.TaskTracker: JVM with ID: jvm_20091010005819797_0002_m_-832698438 given task: attempt_20091010005819797_0002_m_000000_0
[junit] 09/10/10 00:58:57 INFO mapred.JobTracker: Adding task 'attempt_20091010005819797_0002_m_000001_0' to tip task_20091010005819797_0002_m_000001, for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:41286'
[junit] 09/10/10 00:58:57 INFO mapred.JobInProgress: Choosing rack-local task task_20091010005819797_0002_m_000001
[junit] 09/10/10 00:58:57 INFO mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_20091010005819797_0002_m_000001_0 task's state:UNASSIGNED
[junit] 09/10/10 00:58:57 INFO mapred.TaskTracker: Trying to launch : attempt_20091010005819797_0002_m_000001_0
[junit] 09/10/10 00:58:57 INFO mapred.TaskTracker: In TaskLauncher, current free slots : 2 and trying to launch attempt_20091010005819797_0002_m_000001_0
[junit] 09/10/10 00:58:57 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/hadoop-hudson/mapred/system/job_20091010005819797_0002/job.xml dst=null perm=null
[junit] 09/10/10 00:58:57 INFO DataNode.clienttrace: src: /127.0.0.1:57908, dest: /127.0.0.1:60339, bytes: 48634, op: HDFS_READ, cliID: DFSClient_-77174316, srvID: DS-2066684421-127.0.1.1-57908-1255136298560, blockid: blk_8761924747304658191_1015
[junit] 09/10/10 00:58:57 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/hadoop-hudson/mapred/system/job_20091010005819797_0002/job.jar dst=null perm=null
[junit] 09/10/10 00:58:57 INFO DataNode.clienttrace: src: /127.0.0.1:57908, dest: /127.0.0.1:60340, bytes: 2483736, op: HDFS_READ, cliID: DFSClient_-77174316, srvID: DS-2066684421-127.0.1.1-57908-1255136298560, blockid: blk_3750071453426248789_1013
[junit] 09/10/10 00:58:58 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_20091010005819797_0002_m_1506276631
[junit] 09/10/10 00:58:58 INFO mapred.JvmManager: JVM Runner jvm_20091010005819797_0002_m_1506276631 spawned.
[junit] 09/10/10 00:58:58 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/user/hudson/input2.txt dst=null perm=null
[junit] 09/10/10 00:58:58 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=create src=/tmp/temp-1427071197/tmp-783301132/_temporary/_attempt_20091010005819797_0002_m_000000_0/part-00000 dst=null perm=hudson:supergroup:rw-r--r--
[junit] 09/10/10 00:58:58 INFO DataNode.clienttrace: src: /127.0.0.1:55577, dest: /127.0.0.1:34723, bytes: 10, op: HDFS_READ, cliID: DFSClient_attempt_20091010005819797_0002_m_000000_0, srvID: DS-763709620-127.0.1.1-55577-1255136297957, blockid: blk_8073274333389882793_1012
[junit] 09/10/10 00:58:58 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/temp-1427071197/tmp-783301132/_temporary/_attempt_20091010005819797_0002_m_000000_0/part-00000. blk_7973526658410217689_1018
[junit] 09/10/10 00:58:58 INFO datanode.DataNode: Receiving block blk_7973526658410217689_1018 src: /127.0.0.1:60344 dest: /127.0.0.1:57908
[junit] 09/10/10 00:58:58 INFO datanode.DataNode: Receiving block blk_7973526658410217689_1018 src: /127.0.0.1:52454 dest: /127.0.0.1:35232
[junit] 09/10/10 00:58:58 INFO datanode.DataNode: Receiving block blk_7973526658410217689_1018 src: /127.0.0.1:34726 dest: /127.0.0.1:55577
[junit] 09/10/10 00:58:58 INFO DataNode.clienttrace: src: /127.0.0.1:34726, dest: /127.0.0.1:55577, bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091010005819797_0002_m_000000_0, srvID: DS-763709620-127.0.1.1-55577-1255136297957, blockid: blk_7973526658410217689_1018
[junit] 09/10/10 00:58:58 INFO datanode.DataNode: PacketResponder 0 for block blk_7973526658410217689_1018 terminating
[junit] 09/10/10 00:58:58 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:55577 is added to blk_7973526658410217689_1018 size 39
[junit] 09/10/10 00:58:58 INFO DataNode.clienttrace: src: /127.0.0.1:52454, dest: /127.0.0.1:35232, bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091010005819797_0002_m_000000_0, srvID: DS-1003288558-127.0.1.1-35232-1255136299143, blockid: blk_7973526658410217689_1018
[junit] 09/10/10 00:58:58 INFO datanode.DataNode: PacketResponder 1 for block blk_7973526658410217689_1018 terminating
[junit] 09/10/10 00:58:58 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:35232 is added to blk_7973526658410217689_1018 size 39
[junit] 09/10/10 00:58:58 INFO DataNode.clienttrace: src: /127.0.0.1:60344, dest: /127.0.0.1:57908, bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091010005819797_0002_m_000000_0, srvID: DS-2066684421-127.0.1.1-57908-1255136298560, blockid: blk_7973526658410217689_1018
[junit] 09/10/10 00:58:58 INFO datanode.DataNode: PacketResponder 2 for block blk_7973526658410217689_1018 terminating
[junit] 09/10/10 00:58:58 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57908 is added to blk_7973526658410217689_1018 size 39
[junit] 09/10/10 00:58:58 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/temp-1427071197/tmp-783301132/_temporary/_attempt_20091010005819797_0002_m_000000_0/part-00000 is closed by DFSClient_attempt_20091010005819797_0002_m_000000_0
[junit] 09/10/10 00:58:58 INFO mapred.TaskTracker: Task attempt_20091010005819797_0002_m_000000_0 is in commit-pending, task state:COMMIT_PENDING
[junit] 09/10/10 00:58:58 INFO mapred.TaskTracker: attempt_20091010005819797_0002_m_000000_0 0.0%
[junit] 09/10/10 00:58:58 INFO mapred.TaskTracker: JVM with ID: jvm_20091010005819797_0002_m_1506276631 given task: attempt_20091010005819797_0002_m_000001_0
[junit] 09/10/10 00:58:59 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/user/hudson/input1.txt dst=null perm=null
[junit] 09/10/10 00:58:59 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=create src=/tmp/temp-1427071197/tmp-783301132/_temporary/_attempt_20091010005819797_0002_m_000001_0/part-00001 dst=null perm=hudson:supergroup:rw-r--r--
[junit] 09/10/10 00:58:59 INFO DataNode.clienttrace: src: /127.0.0.1:55577, dest: /127.0.0.1:34732, bytes: 10, op: HDFS_READ, cliID: DFSClient_attempt_20091010005819797_0002_m_000001_0, srvID: DS-763709620-127.0.1.1-55577-1255136297957, blockid: blk_-2248922827833092161_1011
[junit] 09/10/10 00:58:59 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/temp-1427071197/tmp-783301132/_temporary/_attempt_20091010005819797_0002_m_000001_0/part-00001. blk_7607962732334717308_1019
[junit] 09/10/10 00:58:59 INFO datanode.DataNode: Receiving block blk_7607962732334717308_1019 src: /127.0.0.1:60353 dest: /127.0.0.1:57908
[junit] 09/10/10 00:58:59 INFO datanode.DataNode: Receiving block blk_7607962732334717308_1019 src: /127.0.0.1:34734 dest: /127.0.0.1:55577
[junit] 09/10/10 00:58:59 INFO datanode.DataNode: Receiving block blk_7607962732334717308_1019 src: /127.0.0.1:52464 dest: /127.0.0.1:35232
[junit] 09/10/10 00:58:59 INFO DataNode.clienttrace: src: /127.0.0.1:52464, dest: /127.0.0.1:35232, bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091010005819797_0002_m_000001_0, srvID: DS-1003288558-127.0.1.1-35232-1255136299143, blockid: blk_7607962732334717308_1019
[junit] 09/10/10 00:58:59 INFO datanode.DataNode: PacketResponder 0 for block blk_7607962732334717308_1019 terminating
[junit] 09/10/10 00:58:59 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:35232 is added to blk_7607962732334717308_1019 size 39
[junit] 09/10/10 00:58:59 INFO DataNode.clienttrace: src: /127.0.0.1:34734, dest: /127.0.0.1:55577, bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091010005819797_0002_m_000001_0, srvID: DS-763709620-127.0.1.1-55577-1255136297957, blockid: blk_7607962732334717308_1019
[junit] 09/10/10 00:58:59 INFO datanode.DataNode: PacketResponder 1 for block blk_7607962732334717308_1019 terminating
[junit] 09/10/10 00:58:59 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:55577 is added to blk_7607962732334717308_1019 size 39
[junit] 09/10/10 00:58:59 INFO DataNode.clienttrace: src: /127.0.0.1:60353, dest: /127.0.0.1:57908, bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091010005819797_0002_m_000001_0, srvID: DS-2066684421-127.0.1.1-57908-1255136298560, blockid: blk_7607962732334717308_1019
[junit] 09/10/10 00:58:59 INFO datanode.DataNode: PacketResponder 2 for block blk_7607962732334717308_1019 terminating
[junit] 09/10/10 00:58:59 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57908 is added to blk_7607962732334717308_1019 size 39
[junit] 09/10/10 00:58:59 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/temp-1427071197/tmp-783301132/_temporary/_attempt_20091010005819797_0002_m_000001_0/part-00001 is closed by DFSClient_attempt_20091010005819797_0002_m_000001_0
[junit] 09/10/10 00:58:59 INFO mapred.TaskTracker: Task attempt_20091010005819797_0002_m_000001_0 is in commit-pending, task state:COMMIT_PENDING
[junit] 09/10/10 00:58:59 INFO mapred.TaskTracker: attempt_20091010005819797_0002_m_000001_0 0.0%
[junit] 09/10/10 00:59:00 INFO mapred.TaskTracker: Received commit task action for attempt_20091010005819797_0002_m_000000_0
[junit] 09/10/10 00:59:00 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=listStatus src=/tmp/temp-1427071197/tmp-783301132/_temporary/_attempt_20091010005819797_0002_m_000000_0 dst=null perm=null
[junit] 09/10/10 00:59:00 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=mkdirs src=/tmp/temp-1427071197/tmp-783301132 dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 09/10/10 00:59:00 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=rename src=/tmp/temp-1427071197/tmp-783301132/_temporary/_attempt_20091010005819797_0002_m_000000_0/part-00000 dst=/tmp/temp-1427071197/tmp-783301132/part-00000 perm=hudson:supergroup:rw-r--r--
[junit] 09/10/10 00:59:00 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/tmp/temp-1427071197/tmp-783301132/_temporary/_attempt_20091010005819797_0002_m_000000_0 dst=null perm=null
[junit] 09/10/10 00:59:00 INFO mapred.TaskTracker: attempt_20091010005819797_0002_m_000000_0 1.0%
[junit] 09/10/10 00:59:00 INFO mapred.TaskTracker: Task attempt_20091010005819797_0002_m_000000_0 is done.
[junit] 09/10/10 00:59:00 INFO mapred.TaskTracker: reported output size for attempt_20091010005819797_0002_m_000000_0 was 0
[junit] 09/10/10 00:59:00 INFO mapred.TaskTracker: addFreeSlot : current free slots : 2
[junit] 09/10/10 00:59:00 INFO mapred.JvmManager: JVM : jvm_20091010005819797_0002_m_-832698438 exited. Number of tasks it ran: 1
[junit] 09/10/10 00:59:00 INFO mapred.TaskTracker: Received commit task action for attempt_20091010005819797_0002_m_000001_0
[junit] 09/10/10 00:59:01 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=listStatus src=/tmp/temp-1427071197/tmp-783301132/_temporary/_attempt_20091010005819797_0002_m_000001_0 dst=null perm=null
[junit] 09/10/10 00:59:01 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=mkdirs src=/tmp/temp-1427071197/tmp-783301132 dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 09/10/10 00:59:01 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=rename src=/tmp/temp-1427071197/tmp-783301132/_temporary/_attempt_20091010005819797_0002_m_000001_0/part-00001 dst=/tmp/temp-1427071197/tmp-783301132/part-00001 perm=hudson:supergroup:rw-r--r--
[junit] 09/10/10 00:59:01 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/tmp/temp-1427071197/tmp-783301132/_temporary/_attempt_20091010005819797_0002_m_000001_0 dst=null perm=null
[junit] 09/10/10 00:59:01 INFO mapred.TaskTracker: attempt_20091010005819797_0002_m_000001_0 1.0%
[junit] 09/10/10 00:59:01 INFO mapred.TaskTracker: Task attempt_20091010005819797_0002_m_000001_0 is done.
[junit] 09/10/10 00:59:01 INFO mapred.TaskTracker: reported output size for attempt_20091010005819797_0002_m_000001_0 was 0
[junit] 09/10/10 00:59:01 INFO mapred.TaskTracker: addFreeSlot : current free slots : 2
[junit] 09/10/10 00:59:01 INFO mapred.JvmManager: JVM : jvm_20091010005819797_0002_m_1506276631 exited. Number of tasks it ran: 1
[junit] 09/10/10 00:59:03 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find taskTracker/jobcache/job_20091010005819797_0002/attempt_20091010005819797_0002_m_000000_0/output/file.out in any of the configured local directories
[junit] 09/10/10 00:59:03 INFO mapred.JobInProgress: Task 'attempt_20091010005819797_0002_m_000000_0' has completed task_20091010005819797_0002_m_000000 successfully.
[junit] 09/10/10 00:59:03 INFO mapReduceLayer.MapReduceLauncher: 25% complete
[junit] 09/10/10 00:59:03 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find taskTracker/jobcache/job_20091010005819797_0002/attempt_20091010005819797_0002_m_000001_0/output/file.out in any of the configured local directories
[junit] 09/10/10 00:59:03 INFO mapred.JobInProgress: Task 'attempt_20091010005819797_0002_m_000001_0' has completed task_20091010005819797_0002_m_000001 successfully.
[junit] 09/10/10 00:59:03 INFO mapred.JobTracker: Adding task 'attempt_20091010005819797_0002_m_000002_0' to tip task_20091010005819797_0002_m_000002, for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:41286'
[junit] 09/10/10 00:59:03 INFO mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_20091010005819797_0002_m_000002_0 task's state:UNASSIGNED
[junit] 09/10/10 00:59:03 INFO mapred.TaskTracker: Trying to launch : attempt_20091010005819797_0002_m_000002_0
[junit] 09/10/10 00:59:03 INFO mapred.TaskTracker: In TaskLauncher, current free slots : 2 and trying to launch attempt_20091010005819797_0002_m_000002_0
[junit] 09/10/10 00:59:03 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_20091010005819797_0002_m_2031261339
[junit] 09/10/10 00:59:03 INFO mapred.JvmManager: JVM Runner jvm_20091010005819797_0002_m_2031261339 spawned.
[junit] 09/10/10 00:59:04 INFO mapReduceLayer.MapReduceLauncher: 50% complete
[junit] 09/10/10 00:59:04 INFO mapred.TaskTracker: JVM with ID: jvm_20091010005819797_0002_m_2031261339 given task: attempt_20091010005819797_0002_m_000002_0
[junit] 09/10/10 00:59:04 INFO mapred.TaskTracker: attempt_20091010005819797_0002_m_000002_0 0.0%
[junit] 09/10/10 00:59:04 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/tmp/temp-1427071197/tmp-783301132/_temporary dst=null perm=null
[junit] 09/10/10 00:59:04 INFO mapred.TaskTracker: attempt_20091010005819797_0002_m_000002_0 0.0% cleanup
[junit] 09/10/10 00:59:04 INFO mapred.TaskTracker: Task attempt_20091010005819797_0002_m_000002_0 is done.
[junit] 09/10/10 00:59:04 INFO mapred.TaskTracker: reported output size for attempt_20091010005819797_0002_m_000002_0 was 0
[junit] 09/10/10 00:59:04 INFO mapred.TaskTracker: addFreeSlot : current free slots : 2
[junit] 09/10/10 00:59:04 INFO mapred.JvmManager: JVM : jvm_20091010005819797_0002_m_2031261339 exited. Number of tasks it ran: 1
[junit] 09/10/10 00:59:06 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find taskTracker/jobcache/job_20091010005819797_0002/attempt_20091010005819797_0002_m_000002_0/output/file.out in any of the configured local directories
[junit] 09/10/10 00:59:06 INFO mapred.JobInProgress: Task 'attempt_20091010005819797_0002_m_000002_0' has completed task_20091010005819797_0002_m_000002 successfully.
[junit] 09/10/10 00:59:06 INFO mapred.JobInProgress: Job job_20091010005819797_0002 has completed successfully.
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/temp-1427071197/tmp-783301132/_logs/history/localhost_1255136299820_job_20091010005819797_0002_hudson_Job3756228276918050786.jar. blk_-4670792676074632197_1019
[junit] 09/10/10 00:59:06 INFO datanode.DataNode: Receiving block blk_-4670792676074632197_1019 src: /127.0.0.1:48077 dest: /127.0.0.1:36513
[junit] 09/10/10 00:59:06 INFO datanode.DataNode: Receiving block blk_-4670792676074632197_1019 src: /127.0.0.1:52471 dest: /127.0.0.1:35232
[junit] 09/10/10 00:59:06 INFO datanode.DataNode: Receiving block blk_-4670792676074632197_1019 src: /127.0.0.1:60363 dest: /127.0.0.1:57908
[junit] 09/10/10 00:59:06 INFO DataNode.clienttrace: src: /127.0.0.1:60363, dest: /127.0.0.1:57908, bytes: 6117, op: HDFS_WRITE, cliID: DFSClient_-77174316, srvID: DS-2066684421-127.0.1.1-57908-1255136298560, blockid: blk_-4670792676074632197_1019
[junit] 09/10/10 00:59:06 INFO DataNode.clienttrace: src: /127.0.0.1:52471, dest: /127.0.0.1:35232, bytes: 6117, op: HDFS_WRITE, cliID: DFSClient_-77174316, srvID: DS-1003288558-127.0.1.1-35232-1255136299143, blockid: blk_-4670792676074632197_1019
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57908 is added to blk_-4670792676074632197_1019 size 6117
[junit] 09/10/10 00:59:06 INFO datanode.DataNode: PacketResponder 0 for block blk_-4670792676074632197_1019 terminating
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:35232 is added to blk_-4670792676074632197_1019 size 6117
[junit] 09/10/10 00:59:06 INFO datanode.DataNode: PacketResponder 1 for block blk_-4670792676074632197_1019 terminating
[junit] 09/10/10 00:59:06 INFO DataNode.clienttrace: src: /127.0.0.1:48077, dest: /127.0.0.1:36513, bytes: 6117, op: HDFS_WRITE, cliID: DFSClient_-77174316, srvID: DS-286696190-127.0.1.1-36513-1255136299705, blockid: blk_-4670792676074632197_1019
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:36513 is added to blk_-4670792676074632197_1019 size 6117
[junit] 09/10/10 00:59:06 INFO datanode.DataNode: PacketResponder 2 for block blk_-4670792676074632197_1019 terminating
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/temp-1427071197/tmp-783301132/_logs/history/localhost_1255136299820_job_20091010005819797_0002_hudson_Job3756228276918050786.jar is closed by DFSClient_-77174316
[junit] 09/10/10 00:59:06 INFO mapred.JobTracker: Removed completed task 'attempt_20091010005819797_0002_m_000001_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:41286'
[junit] 09/10/10 00:59:06 INFO mapred.JobTracker: Removed completed task 'attempt_20091010005819797_0002_m_000002_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:41286'
[junit] 09/10/10 00:59:06 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_20091010005819797_0002
[junit] 09/10/10 00:59:06 INFO mapred.TaskRunner: attempt_20091010005819797_0002_m_000001_0 done; removing files.
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3750071453426248789 is added to invalidSet of 127.0.0.1:36513
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3750071453426248789 is added to invalidSet of 127.0.0.1:35232
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3750071453426248789 is added to invalidSet of 127.0.0.1:57908
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-1334121746913284522 is added to invalidSet of 127.0.0.1:36513
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-1334121746913284522 is added to invalidSet of 127.0.0.1:35232
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-1334121746913284522 is added to invalidSet of 127.0.0.1:57908
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_8761924747304658191 is added to invalidSet of 127.0.0.1:36513
[junit] 09/10/10 00:59:06 INFO mapred.IndexCache: Map ID attempt_20091010005819797_0002_m_000001_0 not found in cache
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_8761924747304658191 is added to invalidSet of 127.0.0.1:35232
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_8761924747304658191 is added to invalidSet of 127.0.0.1:57908
[junit] 09/10/10 00:59:06 INFO mapred.TaskRunner: attempt_20091010005819797_0002_m_000002_0 done; removing files.
[junit] 09/10/10 00:59:06 INFO mapred.IndexCache: Map ID attempt_20091010005819797_0002_m_000002_0 not found in cache
[junit] 09/10/10 00:59:06 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/tmp/hadoop-hudson/mapred/system/job_20091010005819797_0002 dst=null perm=null
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:35232 to delete blk_8761924747304658191_1015 blk_-1334121746913284522_1014 blk_3750071453426248789_1013
[junit] 09/10/10 00:59:06 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:57908 to delete blk_8761924747304658191_1015 blk_-1334121746913284522_1014 blk_3750071453426248789_1013
[junit] 09/10/10 00:59:07 INFO datanode.DataNode: Deleting block blk_-1334121746913284522_1014 file build/test/data/dfs/data/data5/current/blk_-1334121746913284522
[junit] 09/10/10 00:59:07 INFO datanode.DataNode: Deleting block blk_3750071453426248789_1013 file build/test/data/dfs/data/data6/current/blk_3750071453426248789
[junit] 09/10/10 00:59:07 INFO datanode.DataNode: Deleting block blk_8761924747304658191_1015 file build/test/data/dfs/data/data6/current/blk_8761924747304658191
[junit] 09/10/10 00:59:07 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_20091010005819797_0002
[junit] 09/10/10 00:59:07 WARN mapred.TaskTracker: Unknown job job_20091010005819797_0002 being deleted.
[junit] 09/10/10 00:59:07 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_20091010005819797_0002
[junit] 09/10/10 00:59:07 WARN mapred.TaskTracker: Unknown job job_20091010005819797_0002 being deleted.
[junit] 09/10/10 00:59:08 INFO mapReduceLayer.MapReduceLauncher: 100% complete
[junit] 09/10/10 00:59:08 INFO mapReduceLayer.MapReduceLauncher: Successfully stored result in: "hdfs://localhost:59989/tmp/temp-1427071197/tmp-783301132"
[junit] 09/10/10 00:59:08 INFO mapReduceLayer.MapReduceLauncher: Records written : 2
[junit] 09/10/10 00:59:08 INFO mapReduceLayer.MapReduceLauncher: Bytes written : 78
[junit] 09/10/10 00:59:08 INFO mapReduceLayer.MapReduceLauncher: Success!
[junit] 09/10/10 00:59:08 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=listStatus src=/tmp/temp-1427071197/tmp-783301132 dst=null perm=null
[junit] 09/10/10 00:59:08 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/temp-1427071197/tmp-783301132/part-00000 dst=null perm=null
[junit] 09/10/10 00:59:08 INFO DataNode.clienttrace: src: /127.0.0.1:55577, dest: /127.0.0.1:34744, bytes: 43, op: HDFS_READ, cliID: DFSClient_-77174316, srvID: DS-763709620-127.0.1.1-55577-1255136297957, blockid: blk_7973526658410217689_1018
[junit] 09/10/10 00:59:08 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/temp-1427071197/tmp-783301132/part-00001 dst=null perm=null
[junit] 09/10/10 00:59:08 INFO DataNode.clienttrace: src: /127.0.0.1:55577, dest: /127.0.0.1:34745, bytes: 43, op: HDFS_READ, cliID: DFSClient_-77174316, srvID: DS-763709620-127.0.1.1-55577-1255136297957, blockid: blk_7607962732334717308_1019
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 45.248 sec
BUILD FAILED
<http://hudson.zones.apache.org/hudson/job/Pig-trunk/ws/trunk/build.xml>:496: The following error occurred while executing this line:
<http://hudson.zones.apache.org/hudson/job/Pig-trunk/ws/trunk/build.xml>:430: The following error occurred while executing this line:
<http://hudson.zones.apache.org/hudson/job/Pig-trunk/ws/trunk/build.xml>:491: Tests failed!
Total time: 169 minutes 14 seconds
Publishing Javadoc
Archiving artifacts
Recording test results
Recording fingerprints
Publishing Clover coverage report...
No Clover report will be published due to a Build Failure
Hudson build is back to normal: Pig-trunk #585
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See <http://hudson.zones.apache.org/hudson/job/Pig-trunk/585/changes>
Build failed in Hudson: Pig-trunk #584
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See <http://hudson.zones.apache.org/hudson/job/Pig-trunk/584/changes>
Changes:
[rangadi] PIG-986. Second commit. forgot to svn-add new files in the previous commit.
[rangadi] PIG-986. Column groups can have explicit names specified instorage hint. (Yan Zhou via rangadi)
------------------------------------------
[...truncated 139249 lines...]
[junit] 09/10/12 12:41:49 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=create src=/tmp/hadoop-hudson/mapred/system/job_20091012124116715_0002/job.xml dst=null perm=hudson:supergroup:rw-r--r--
[junit] 09/10/12 12:41:49 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=setPermission src=/tmp/hadoop-hudson/mapred/system/job_20091012124116715_0002/job.xml dst=null perm=hudson:supergroup:rw-r--r--
[junit] 09/10/12 12:41:49 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/hadoop-hudson/mapred/system/job_20091012124116715_0002/job.xml. blk_64099637709780241_1015
[junit] 09/10/12 12:41:49 INFO datanode.DataNode: Receiving block blk_64099637709780241_1015 src: /127.0.0.1:54132 dest: /127.0.0.1:55754
[junit] 09/10/12 12:41:49 INFO datanode.DataNode: Receiving block blk_64099637709780241_1015 src: /127.0.0.1:43241 dest: /127.0.0.1:47521
[junit] 09/10/12 12:41:49 INFO datanode.DataNode: Receiving block blk_64099637709780241_1015 src: /127.0.0.1:44670 dest: /127.0.0.1:48402
[junit] 09/10/12 12:41:49 INFO DataNode.clienttrace: src: /127.0.0.1:44670, dest: /127.0.0.1:48402, bytes: 48253, op: HDFS_WRITE, cliID: DFSClient_-928526854, srvID: DS-1295567057-127.0.1.1-48402-1255351276055, blockid: blk_64099637709780241_1015
[junit] 09/10/12 12:41:49 INFO datanode.DataNode: PacketResponder 0 for block blk_64099637709780241_1015 terminating
[junit] 09/10/12 12:41:49 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:48402 is added to blk_64099637709780241_1015 size 48253
[junit] 09/10/12 12:41:49 INFO DataNode.clienttrace: src: /127.0.0.1:43241, dest: /127.0.0.1:47521, bytes: 48253, op: HDFS_WRITE, cliID: DFSClient_-928526854, srvID: DS-1256327855-127.0.1.1-47521-1255351276624, blockid: blk_64099637709780241_1015
[junit] 09/10/12 12:41:49 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:47521 is added to blk_64099637709780241_1015 size 48253
[junit] 09/10/12 12:41:49 INFO datanode.DataNode: PacketResponder 1 for block blk_64099637709780241_1015 terminating
[junit] 09/10/12 12:41:49 INFO DataNode.clienttrace: src: /127.0.0.1:54132, dest: /127.0.0.1:55754, bytes: 48253, op: HDFS_WRITE, cliID: DFSClient_-928526854, srvID: DS-108433573-127.0.1.1-55754-1255351274841, blockid: blk_64099637709780241_1015
[junit] 09/10/12 12:41:49 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:55754 is added to blk_64099637709780241_1015 size 48253
[junit] 09/10/12 12:41:49 INFO datanode.DataNode: PacketResponder 2 for block blk_64099637709780241_1015 terminating
[junit] 09/10/12 12:41:49 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/hadoop-hudson/mapred/system/job_20091012124116715_0002/job.xml is closed by DFSClient_-928526854
[junit] 09/10/12 12:41:49 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/hadoop-hudson/mapred/system/job_20091012124116715_0002/job.xml dst=null perm=null
[junit] 09/10/12 12:41:49 INFO DataNode.clienttrace: src: /127.0.0.1:47521, dest: /127.0.0.1:43243, bytes: 48633, op: HDFS_READ, cliID: DFSClient_-928526854, srvID: DS-1256327855-127.0.1.1-47521-1255351276624, blockid: blk_64099637709780241_1015
[junit] 09/10/12 12:41:49 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/hadoop-hudson/mapred/system/job_20091012124116715_0002/job.jar dst=null perm=null
[junit] 09/10/12 12:41:49 INFO DataNode.clienttrace: src: /127.0.0.1:55754, dest: /127.0.0.1:54136, bytes: 2481312, op: HDFS_READ, cliID: DFSClient_-928526854, srvID: DS-108433573-127.0.1.1-55754-1255351274841, blockid: blk_8897466993134543700_1013
[junit] 09/10/12 12:41:49 INFO mapred.JobTracker: Initializing job_20091012124116715_0002
[junit] 09/10/12 12:41:49 INFO mapred.JobInProgress: Initializing job_20091012124116715_0002
[junit] 09/10/12 12:41:49 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=create src=/tmp/temp1896202947/tmp-1253282919/_logs/history/localhost_1255351276736_job_20091012124116715_0002_hudson_Job841759538738982609.jar dst=null perm=hudson:supergroup:rw-r--r--
[junit] 09/10/12 12:41:49 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=create src=/tmp/temp1896202947/tmp-1253282919/_logs/history/localhost_1255351276736_job_20091012124116715_0002_conf.xml dst=null perm=hudson:supergroup:rw-r--r--
[junit] 09/10/12 12:41:49 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/temp1896202947/tmp-1253282919/_logs/history/localhost_1255351276736_job_20091012124116715_0002_conf.xml. blk_-6565587421743964533_1017
[junit] 09/10/12 12:41:49 INFO datanode.DataNode: Receiving block blk_-6565587421743964533_1017 src: /127.0.0.1:54137 dest: /127.0.0.1:55754
[junit] 09/10/12 12:41:49 INFO datanode.DataNode: Receiving block blk_-6565587421743964533_1017 src: /127.0.0.1:44674 dest: /127.0.0.1:48402
[junit] 09/10/12 12:41:49 INFO datanode.DataNode: Receiving block blk_-6565587421743964533_1017 src: /127.0.0.1:50423 dest: /127.0.0.1:52350
[junit] 09/10/12 12:41:49 INFO DataNode.clienttrace: src: /127.0.0.1:50423, dest: /127.0.0.1:52350, bytes: 48283, op: HDFS_WRITE, cliID: DFSClient_-928526854, srvID: DS-1188159356-127.0.1.1-52350-1255351275463, blockid: blk_-6565587421743964533_1017
[junit] 09/10/12 12:41:49 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:52350 is added to blk_-6565587421743964533_1017 size 48283
[junit] 09/10/12 12:41:49 INFO datanode.DataNode: PacketResponder 0 for block blk_-6565587421743964533_1017 terminating
[junit] 09/10/12 12:41:49 INFO DataNode.clienttrace: src: /127.0.0.1:44674, dest: /127.0.0.1:48402, bytes: 48283, op: HDFS_WRITE, cliID: DFSClient_-928526854, srvID: DS-1295567057-127.0.1.1-48402-1255351276055, blockid: blk_-6565587421743964533_1017
[junit] 09/10/12 12:41:49 INFO datanode.DataNode: PacketResponder 1 for block blk_-6565587421743964533_1017 terminating
[junit] 09/10/12 12:41:49 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:48402 is added to blk_-6565587421743964533_1017 size 48283
[junit] 09/10/12 12:41:49 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:55754 is added to blk_-6565587421743964533_1017 size 48283
[junit] 09/10/12 12:41:49 INFO DataNode.clienttrace: src: /127.0.0.1:54137, dest: /127.0.0.1:55754, bytes: 48283, op: HDFS_WRITE, cliID: DFSClient_-928526854, srvID: DS-108433573-127.0.1.1-55754-1255351274841, blockid: blk_-6565587421743964533_1017
[junit] 09/10/12 12:41:49 INFO datanode.DataNode: PacketResponder 2 for block blk_-6565587421743964533_1017 terminating
[junit] 09/10/12 12:41:49 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/temp1896202947/tmp-1253282919/_logs/history/localhost_1255351276736_job_20091012124116715_0002_conf.xml is closed by DFSClient_-928526854
[junit] 09/10/12 12:41:50 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/hadoop-hudson/mapred/system/job_20091012124116715_0002/job.split dst=null perm=null
[junit] 09/10/12 12:41:50 INFO DataNode.clienttrace: src: /127.0.0.1:52350, dest: /127.0.0.1:50424, bytes: 1875, op: HDFS_READ, cliID: DFSClient_-928526854, srvID: DS-1188159356-127.0.1.1-52350-1255351275463, blockid: blk_-2880930421464948328_1014
[junit] 09/10/12 12:41:50 INFO mapred.JobInProgress: Input size for job job_20091012124116715_0002 = 12. Number of splits = 2
[junit] 09/10/12 12:41:50 INFO mapred.JobInProgress: tip:task_20091012124116715_0002_m_000000 has split on node:/default-rack/h7.grid.sp2.yahoo.net
[junit] 09/10/12 12:41:50 INFO mapred.JobInProgress: tip:task_20091012124116715_0002_m_000001 has split on node:/default-rack/h7.grid.sp2.yahoo.net
[junit] 09/10/12 12:41:50 INFO mapReduceLayer.MapReduceLauncher: Submitting job: job_20091012124116715_0002 to execution engine.
[junit] 09/10/12 12:41:50 INFO mapReduceLayer.MapReduceLauncher: More information at: http://localhost:52769/jobdetails.jsp?jobid=job_20091012124116715_0002
[junit] 09/10/12 12:41:50 INFO mapReduceLayer.MapReduceLauncher: To kill this job, use: kill job_20091012124116715_0002
[junit] 09/10/12 12:41:50 INFO datanode.DataNode: Deleting block blk_7393293881851490809_1007 file build/test/data/dfs/data/data1/current/blk_7393293881851490809
[junit] 09/10/12 12:41:51 INFO mapReduceLayer.MapReduceLauncher: 0% complete
[junit] 09/10/12 12:41:51 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:47521 to delete blk_206687224935682415_1006 blk_-5235315925979426583_1005 blk_8897466993134543700_1013 blk_7393293881851490809_1007
[junit] 09/10/12 12:41:51 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:48402 to delete blk_206687224935682415_1006 blk_-5235315925979426583_1005 blk_7393293881851490809_1007
[junit] 09/10/12 12:41:51 INFO mapred.JobTracker: Adding task 'attempt_20091012124116715_0002_m_000003_0' to tip task_20091012124116715_0002_m_000003, for tracker 'tracker_host0.foo.com:localhost/127.0.0.1:48533'
[junit] 09/10/12 12:41:51 INFO mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_20091012124116715_0002_m_000003_0 task's state:UNASSIGNED
[junit] 09/10/12 12:41:51 INFO mapred.TaskTracker: Trying to launch : attempt_20091012124116715_0002_m_000003_0
[junit] 09/10/12 12:41:51 INFO mapred.TaskTracker: In TaskLauncher, current free slots : 2 and trying to launch attempt_20091012124116715_0002_m_000003_0
[junit] 09/10/12 12:41:51 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/hadoop-hudson/mapred/system/job_20091012124116715_0002/job.xml dst=null perm=null
[junit] 09/10/12 12:41:51 INFO DataNode.clienttrace: src: /127.0.0.1:55754, dest: /127.0.0.1:54141, bytes: 48633, op: HDFS_READ, cliID: DFSClient_-928526854, srvID: DS-108433573-127.0.1.1-55754-1255351274841, blockid: blk_64099637709780241_1015
[junit] 09/10/12 12:41:51 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/hadoop-hudson/mapred/system/job_20091012124116715_0002/job.jar dst=null perm=null
[junit] 09/10/12 12:41:51 INFO DataNode.clienttrace: src: /127.0.0.1:47521, dest: /127.0.0.1:43250, bytes: 2481312, op: HDFS_READ, cliID: DFSClient_-928526854, srvID: DS-1256327855-127.0.1.1-47521-1255351276624, blockid: blk_8897466993134543700_1013
[junit] 09/10/12 12:41:51 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_20091012124116715_0002_m_-1853673944
[junit] 09/10/12 12:41:51 INFO mapred.JvmManager: JVM Runner jvm_20091012124116715_0002_m_-1853673944 spawned.
[junit] 09/10/12 12:41:52 INFO datanode.DataNode: Deleting block blk_-5235315925979426583_1005 file build/test/data/dfs/data/data6/current/blk_-5235315925979426583
[junit] 09/10/12 12:41:52 INFO datanode.DataNode: Deleting block blk_206687224935682415_1006 file build/test/data/dfs/data/data5/current/blk_206687224935682415
[junit] 09/10/12 12:41:52 INFO datanode.DataNode: Deleting block blk_7393293881851490809_1007 file build/test/data/dfs/data/data6/current/blk_7393293881851490809
[junit] 09/10/12 12:41:52 INFO mapred.TaskTracker: JVM with ID: jvm_20091012124116715_0002_m_-1853673944 given task: attempt_20091012124116715_0002_m_000003_0
[junit] 09/10/12 12:41:52 INFO namenode.FSNamesystem: Number of transactions: 84 Total time for transactions(ms): 2Number of transactions batched in Syncs: 4 Number of syncs: 55 SyncTimes(ms): 272 27
[junit] 09/10/12 12:41:52 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=mkdirs src=/tmp/temp1896202947/tmp-1253282919/_temporary dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 09/10/12 12:41:52 INFO mapred.TaskTracker: attempt_20091012124116715_0002_m_000003_0 0.0% setup
[junit] 09/10/12 12:41:52 INFO mapred.TaskTracker: Task attempt_20091012124116715_0002_m_000003_0 is done.
[junit] 09/10/12 12:41:52 INFO mapred.TaskTracker: reported output size for attempt_20091012124116715_0002_m_000003_0 was 0
[junit] 09/10/12 12:41:52 INFO mapred.TaskTracker: addFreeSlot : current free slots : 2
[junit] 09/10/12 12:41:52 WARN datanode.DataNode: Unexpected error trying to delete block blk_-5235315925979426583_1005. BlockInfo not found in volumeMap.
[junit] 09/10/12 12:41:52 INFO datanode.DataNode: Deleting block blk_206687224935682415_1006 file build/test/data/dfs/data/data8/current/blk_206687224935682415
[junit] 09/10/12 12:41:52 INFO datanode.DataNode: Deleting block blk_7393293881851490809_1007 file build/test/data/dfs/data/data7/current/blk_7393293881851490809
[junit] 09/10/12 12:41:52 INFO datanode.DataNode: Deleting block blk_8897466993134543700_1013 file build/test/data/dfs/data/data8/current/blk_8897466993134543700
[junit] 09/10/12 12:41:52 WARN datanode.DataNode: Error processing datanode Command
[junit] java.io.IOException: Error in deleting blocks.
[junit] at org.apache.hadoop.hdfs.server.datanode.FSDataset.invalidate(FSDataset.java:1361)
[junit] at org.apache.hadoop.hdfs.server.datanode.DataNode.processCommand(DataNode.java:868)
[junit] at org.apache.hadoop.hdfs.server.datanode.DataNode.processCommand(DataNode.java:830)
[junit] at org.apache.hadoop.hdfs.server.datanode.DataNode.offerService(DataNode.java:710)
[junit] at org.apache.hadoop.hdfs.server.datanode.DataNode.run(DataNode.java:1186)
[junit] at java.lang.Thread.run(Thread.java:619)
[junit] 09/10/12 12:41:52 INFO mapred.JvmManager: JVM : jvm_20091012124116715_0002_m_-1853673944 exited. Number of tasks it ran: 1
[junit] 09/10/12 12:41:54 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find taskTracker/jobcache/job_20091012124116715_0002/attempt_20091012124116715_0002_m_000003_0/output/file.out in any of the configured local directories
[junit] 09/10/12 12:41:54 INFO mapred.JobInProgress: Task 'attempt_20091012124116715_0002_m_000003_0' has completed task_20091012124116715_0002_m_000003 successfully.
[junit] 09/10/12 12:41:54 INFO mapred.JobTracker: Adding task 'attempt_20091012124116715_0002_m_000000_0' to tip task_20091012124116715_0002_m_000000, for tracker 'tracker_host0.foo.com:localhost/127.0.0.1:48533'
[junit] 09/10/12 12:41:54 INFO mapred.JobInProgress: Choosing rack-local task task_20091012124116715_0002_m_000000
[junit] 09/10/12 12:41:54 INFO mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_20091012124116715_0002_m_000000_0 task's state:UNASSIGNED
[junit] 09/10/12 12:41:54 INFO mapred.TaskTracker: Trying to launch : attempt_20091012124116715_0002_m_000000_0
[junit] 09/10/12 12:41:54 INFO mapred.TaskTracker: Received KillTaskAction for task: attempt_20091012124116715_0002_m_000003_0
[junit] 09/10/12 12:41:54 INFO mapred.TaskTracker: About to purge task: attempt_20091012124116715_0002_m_000003_0
[junit] 09/10/12 12:41:54 INFO mapred.TaskTracker: In TaskLauncher, current free slots : 2 and trying to launch attempt_20091012124116715_0002_m_000000_0
[junit] 09/10/12 12:41:54 INFO mapred.TaskRunner: attempt_20091012124116715_0002_m_000003_0 done; removing files.
[junit] 09/10/12 12:41:54 INFO mapred.IndexCache: Map ID attempt_20091012124116715_0002_m_000003_0 not found in cache
[junit] 09/10/12 12:41:54 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_20091012124116715_0002_m_199427287
[junit] 09/10/12 12:41:54 INFO mapred.JvmManager: JVM Runner jvm_20091012124116715_0002_m_199427287 spawned.
[junit] 09/10/12 12:41:54 INFO mapred.TaskTracker: JVM with ID: jvm_20091012124116715_0002_m_199427287 given task: attempt_20091012124116715_0002_m_000000_0
[junit] 09/10/12 12:41:54 INFO mapred.JobTracker: Adding task 'attempt_20091012124116715_0002_m_000001_0' to tip task_20091012124116715_0002_m_000001, for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:50522'
[junit] 09/10/12 12:41:54 INFO mapred.JobInProgress: Choosing rack-local task task_20091012124116715_0002_m_000001
[junit] 09/10/12 12:41:54 INFO mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_20091012124116715_0002_m_000001_0 task's state:UNASSIGNED
[junit] 09/10/12 12:41:54 INFO mapred.TaskTracker: Trying to launch : attempt_20091012124116715_0002_m_000001_0
[junit] 09/10/12 12:41:54 INFO mapred.TaskTracker: In TaskLauncher, current free slots : 2 and trying to launch attempt_20091012124116715_0002_m_000001_0
[junit] 09/10/12 12:41:54 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/hadoop-hudson/mapred/system/job_20091012124116715_0002/job.xml dst=null perm=null
[junit] 09/10/12 12:41:54 INFO DataNode.clienttrace: src: /127.0.0.1:55754, dest: /127.0.0.1:54151, bytes: 48633, op: HDFS_READ, cliID: DFSClient_-928526854, srvID: DS-108433573-127.0.1.1-55754-1255351274841, blockid: blk_64099637709780241_1015
[junit] 09/10/12 12:41:54 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/hadoop-hudson/mapred/system/job_20091012124116715_0002/job.jar dst=null perm=null
[junit] 09/10/12 12:41:54 INFO DataNode.clienttrace: src: /127.0.0.1:52350, dest: /127.0.0.1:50436, bytes: 2481312, op: HDFS_READ, cliID: DFSClient_-928526854, srvID: DS-1188159356-127.0.1.1-52350-1255351275463, blockid: blk_8897466993134543700_1013
[junit] 09/10/12 12:41:55 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_20091012124116715_0002_m_230818407
[junit] 09/10/12 12:41:55 INFO mapred.JvmManager: JVM Runner jvm_20091012124116715_0002_m_230818407 spawned.
[junit] 09/10/12 12:41:55 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/user/hudson/input2.txt dst=null perm=null
[junit] 09/10/12 12:41:55 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=create src=/tmp/temp1896202947/tmp-1253282919/_temporary/_attempt_20091012124116715_0002_m_000000_0/part-00000 dst=null perm=hudson:supergroup:rw-r--r--
[junit] 09/10/12 12:41:55 INFO DataNode.clienttrace: src: /127.0.0.1:47521, dest: /127.0.0.1:43263, bytes: 10, op: HDFS_READ, cliID: DFSClient_attempt_20091012124116715_0002_m_000000_0, srvID: DS-1256327855-127.0.1.1-47521-1255351276624, blockid: blk_2817101291697522214_1012
[junit] 09/10/12 12:41:55 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/temp1896202947/tmp-1253282919/_temporary/_attempt_20091012124116715_0002_m_000000_0/part-00000. blk_672430965767855373_1018
[junit] 09/10/12 12:41:55 INFO datanode.DataNode: Receiving block blk_672430965767855373_1018 src: /127.0.0.1:54156 dest: /127.0.0.1:55754
[junit] 09/10/12 12:41:55 INFO datanode.DataNode: Receiving block blk_672430965767855373_1018 src: /127.0.0.1:43265 dest: /127.0.0.1:47521
[junit] 09/10/12 12:41:55 INFO datanode.DataNode: Receiving block blk_672430965767855373_1018 src: /127.0.0.1:50442 dest: /127.0.0.1:52350
[junit] 09/10/12 12:41:55 INFO DataNode.clienttrace: src: /127.0.0.1:50442, dest: /127.0.0.1:52350, bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091012124116715_0002_m_000000_0, srvID: DS-1188159356-127.0.1.1-52350-1255351275463, blockid: blk_672430965767855373_1018
[junit] 09/10/12 12:41:55 INFO datanode.DataNode: PacketResponder 0 for block blk_672430965767855373_1018 terminating
[junit] 09/10/12 12:41:55 INFO DataNode.clienttrace: src: /127.0.0.1:43265, dest: /127.0.0.1:47521, bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091012124116715_0002_m_000000_0, srvID: DS-1256327855-127.0.1.1-47521-1255351276624, blockid: blk_672430965767855373_1018
[junit] 09/10/12 12:41:55 INFO datanode.DataNode: PacketResponder 1 for block blk_672430965767855373_1018 terminating
[junit] 09/10/12 12:41:55 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:47521 is added to blk_672430965767855373_1018 size 39
[junit] 09/10/12 12:41:55 INFO DataNode.clienttrace: src: /127.0.0.1:54156, dest: /127.0.0.1:55754, bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091012124116715_0002_m_000000_0, srvID: DS-108433573-127.0.1.1-55754-1255351274841, blockid: blk_672430965767855373_1018
[junit] 09/10/12 12:41:55 INFO datanode.DataNode: PacketResponder 2 for block blk_672430965767855373_1018 terminating
[junit] 09/10/12 12:41:55 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:52350 is added to blk_672430965767855373_1018 size 39
[junit] 09/10/12 12:41:55 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:55754 is added to blk_672430965767855373_1018 size 39
[junit] 09/10/12 12:41:55 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/temp1896202947/tmp-1253282919/_temporary/_attempt_20091012124116715_0002_m_000000_0/part-00000 is closed by DFSClient_attempt_20091012124116715_0002_m_000000_0
[junit] 09/10/12 12:41:55 INFO mapred.TaskTracker: Task attempt_20091012124116715_0002_m_000000_0 is in commit-pending, task state:COMMIT_PENDING
[junit] 09/10/12 12:41:55 INFO mapred.TaskTracker: attempt_20091012124116715_0002_m_000000_0 0.0%
[junit] 09/10/12 12:41:55 INFO mapred.TaskTracker: JVM with ID: jvm_20091012124116715_0002_m_230818407 given task: attempt_20091012124116715_0002_m_000001_0
[junit] 09/10/12 12:41:56 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/user/hudson/input1.txt dst=null perm=null
[junit] 09/10/12 12:41:56 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=create src=/tmp/temp1896202947/tmp-1253282919/_temporary/_attempt_20091012124116715_0002_m_000001_0/part-00001 dst=null perm=hudson:supergroup:rw-r--r--
[junit] 09/10/12 12:41:56 INFO DataNode.clienttrace: src: /127.0.0.1:48402, dest: /127.0.0.1:44700, bytes: 10, op: HDFS_READ, cliID: DFSClient_attempt_20091012124116715_0002_m_000001_0, srvID: DS-1295567057-127.0.1.1-48402-1255351276055, blockid: blk_-7114339600812863670_1011
[junit] 09/10/12 12:41:56 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/temp1896202947/tmp-1253282919/_temporary/_attempt_20091012124116715_0002_m_000001_0/part-00001. blk_5914217004738264773_1019
[junit] 09/10/12 12:41:56 INFO datanode.DataNode: Receiving block blk_5914217004738264773_1019 src: /127.0.0.1:50449 dest: /127.0.0.1:52350
[junit] 09/10/12 12:41:56 INFO datanode.DataNode: Receiving block blk_5914217004738264773_1019 src: /127.0.0.1:44702 dest: /127.0.0.1:48402
[junit] 09/10/12 12:41:56 INFO datanode.DataNode: Receiving block blk_5914217004738264773_1019 src: /127.0.0.1:54167 dest: /127.0.0.1:55754
[junit] 09/10/12 12:41:56 INFO DataNode.clienttrace: src: /127.0.0.1:54167, dest: /127.0.0.1:55754, bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091012124116715_0002_m_000001_0, srvID: DS-108433573-127.0.1.1-55754-1255351274841, blockid: blk_5914217004738264773_1019
[junit] 09/10/12 12:41:56 INFO datanode.DataNode: PacketResponder 0 for block blk_5914217004738264773_1019 terminating
[junit] 09/10/12 12:41:56 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:55754 is added to blk_5914217004738264773_1019 size 39
[junit] 09/10/12 12:41:56 INFO DataNode.clienttrace: src: /127.0.0.1:44702, dest: /127.0.0.1:48402, bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091012124116715_0002_m_000001_0, srvID: DS-1295567057-127.0.1.1-48402-1255351276055, blockid: blk_5914217004738264773_1019
[junit] 09/10/12 12:41:56 INFO datanode.DataNode: PacketResponder 1 for block blk_5914217004738264773_1019 terminating
[junit] 09/10/12 12:41:56 INFO DataNode.clienttrace: src: /127.0.0.1:50449, dest: /127.0.0.1:52350, bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091012124116715_0002_m_000001_0, srvID: DS-1188159356-127.0.1.1-52350-1255351275463, blockid: blk_5914217004738264773_1019
[junit] 09/10/12 12:41:56 INFO datanode.DataNode: PacketResponder 2 for block blk_5914217004738264773_1019 terminating
[junit] 09/10/12 12:41:56 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:48402 is added to blk_5914217004738264773_1019 size 39
[junit] 09/10/12 12:41:56 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:52350 is added to blk_5914217004738264773_1019 size 39
[junit] 09/10/12 12:41:56 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/temp1896202947/tmp-1253282919/_temporary/_attempt_20091012124116715_0002_m_000001_0/part-00001 is closed by DFSClient_attempt_20091012124116715_0002_m_000001_0
[junit] 09/10/12 12:41:56 INFO mapred.TaskTracker: Task attempt_20091012124116715_0002_m_000001_0 is in commit-pending, task state:COMMIT_PENDING
[junit] 09/10/12 12:41:56 INFO mapred.TaskTracker: attempt_20091012124116715_0002_m_000001_0 0.0%
[junit] 09/10/12 12:41:57 INFO mapred.TaskTracker: Received commit task action for attempt_20091012124116715_0002_m_000000_0
[junit] 09/10/12 12:41:57 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=listStatus src=/tmp/temp1896202947/tmp-1253282919/_temporary/_attempt_20091012124116715_0002_m_000000_0 dst=null perm=null
[junit] 09/10/12 12:41:57 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=mkdirs src=/tmp/temp1896202947/tmp-1253282919 dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 09/10/12 12:41:57 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=rename src=/tmp/temp1896202947/tmp-1253282919/_temporary/_attempt_20091012124116715_0002_m_000000_0/part-00000 dst=/tmp/temp1896202947/tmp-1253282919/part-00000 perm=hudson:supergroup:rw-r--r--
[junit] 09/10/12 12:41:57 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/tmp/temp1896202947/tmp-1253282919/_temporary/_attempt_20091012124116715_0002_m_000000_0 dst=null perm=null
[junit] 09/10/12 12:41:57 INFO mapred.TaskTracker: attempt_20091012124116715_0002_m_000000_0 1.0%
[junit] 09/10/12 12:41:57 INFO mapred.TaskTracker: Task attempt_20091012124116715_0002_m_000000_0 is done.
[junit] 09/10/12 12:41:57 INFO mapred.TaskTracker: reported output size for attempt_20091012124116715_0002_m_000000_0 was 0
[junit] 09/10/12 12:41:57 INFO mapred.TaskTracker: addFreeSlot : current free slots : 2
[junit] 09/10/12 12:41:57 INFO mapred.JvmManager: JVM : jvm_20091012124116715_0002_m_199427287 exited. Number of tasks it ran: 1
[junit] 09/10/12 12:41:57 INFO mapred.TaskTracker: Received commit task action for attempt_20091012124116715_0002_m_000001_0
[junit] 09/10/12 12:41:58 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=listStatus src=/tmp/temp1896202947/tmp-1253282919/_temporary/_attempt_20091012124116715_0002_m_000001_0 dst=null perm=null
[junit] 09/10/12 12:41:58 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=mkdirs src=/tmp/temp1896202947/tmp-1253282919 dst=null perm=hudson:supergroup:rwxr-xr-x
[junit] 09/10/12 12:41:58 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=rename src=/tmp/temp1896202947/tmp-1253282919/_temporary/_attempt_20091012124116715_0002_m_000001_0/part-00001 dst=/tmp/temp1896202947/tmp-1253282919/part-00001 perm=hudson:supergroup:rw-r--r--
[junit] 09/10/12 12:41:58 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/tmp/temp1896202947/tmp-1253282919/_temporary/_attempt_20091012124116715_0002_m_000001_0 dst=null perm=null
[junit] 09/10/12 12:41:58 INFO mapred.TaskTracker: attempt_20091012124116715_0002_m_000001_0 1.0%
[junit] 09/10/12 12:41:58 INFO mapred.TaskTracker: Task attempt_20091012124116715_0002_m_000001_0 is done.
[junit] 09/10/12 12:41:58 INFO mapred.TaskTracker: reported output size for attempt_20091012124116715_0002_m_000001_0 was 0
[junit] 09/10/12 12:41:58 INFO mapred.TaskTracker: addFreeSlot : current free slots : 2
[junit] 09/10/12 12:41:58 INFO mapred.JvmManager: JVM : jvm_20091012124116715_0002_m_230818407 exited. Number of tasks it ran: 1
[junit] 09/10/12 12:42:00 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find taskTracker/jobcache/job_20091012124116715_0002/attempt_20091012124116715_0002_m_000000_0/output/file.out in any of the configured local directories
[junit] 09/10/12 12:42:00 INFO mapred.JobInProgress: Task 'attempt_20091012124116715_0002_m_000000_0' has completed task_20091012124116715_0002_m_000000 successfully.
[junit] 09/10/12 12:42:00 INFO mapReduceLayer.MapReduceLauncher: 25% complete
[junit] 09/10/12 12:42:00 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find taskTracker/jobcache/job_20091012124116715_0002/attempt_20091012124116715_0002_m_000001_0/output/file.out in any of the configured local directories
[junit] 09/10/12 12:42:00 INFO mapred.JobInProgress: Task 'attempt_20091012124116715_0002_m_000001_0' has completed task_20091012124116715_0002_m_000001 successfully.
[junit] 09/10/12 12:42:00 INFO mapred.JobTracker: Adding task 'attempt_20091012124116715_0002_m_000002_0' to tip task_20091012124116715_0002_m_000002, for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:50522'
[junit] 09/10/12 12:42:00 INFO mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_20091012124116715_0002_m_000002_0 task's state:UNASSIGNED
[junit] 09/10/12 12:42:00 INFO mapred.TaskTracker: Trying to launch : attempt_20091012124116715_0002_m_000002_0
[junit] 09/10/12 12:42:00 INFO mapred.TaskTracker: In TaskLauncher, current free slots : 2 and trying to launch attempt_20091012124116715_0002_m_000002_0
[junit] 09/10/12 12:42:00 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_20091012124116715_0002_m_845688942
[junit] 09/10/12 12:42:00 INFO mapred.JvmManager: JVM Runner jvm_20091012124116715_0002_m_845688942 spawned.
[junit] 09/10/12 12:42:01 INFO mapReduceLayer.MapReduceLauncher: 50% complete
[junit] 09/10/12 12:42:01 INFO mapred.TaskTracker: JVM with ID: jvm_20091012124116715_0002_m_845688942 given task: attempt_20091012124116715_0002_m_000002_0
[junit] 09/10/12 12:42:01 INFO mapred.TaskTracker: attempt_20091012124116715_0002_m_000002_0 0.0%
[junit] 09/10/12 12:42:01 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/tmp/temp1896202947/tmp-1253282919/_temporary dst=null perm=null
[junit] 09/10/12 12:42:01 INFO mapred.TaskTracker: attempt_20091012124116715_0002_m_000002_0 0.0% cleanup
[junit] 09/10/12 12:42:01 INFO mapred.TaskTracker: Task attempt_20091012124116715_0002_m_000002_0 is done.
[junit] 09/10/12 12:42:01 INFO mapred.TaskTracker: reported output size for attempt_20091012124116715_0002_m_000002_0 was 0
[junit] 09/10/12 12:42:01 INFO mapred.TaskTracker: addFreeSlot : current free slots : 2
[junit] 09/10/12 12:42:01 INFO mapred.JvmManager: JVM : jvm_20091012124116715_0002_m_845688942 exited. Number of tasks it ran: 1
[junit] 09/10/12 12:42:03 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find taskTracker/jobcache/job_20091012124116715_0002/attempt_20091012124116715_0002_m_000002_0/output/file.out in any of the configured local directories
[junit] 09/10/12 12:42:03 INFO mapred.JobInProgress: Task 'attempt_20091012124116715_0002_m_000002_0' has completed task_20091012124116715_0002_m_000002 successfully.
[junit] 09/10/12 12:42:03 INFO mapred.JobInProgress: Job job_20091012124116715_0002 has completed successfully.
[junit] 09/10/12 12:42:03 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/temp1896202947/tmp-1253282919/_logs/history/localhost_1255351276736_job_20091012124116715_0002_hudson_Job841759538738982609.jar. blk_-6200621081134523711_1019
[junit] 09/10/12 12:42:03 INFO datanode.DataNode: Receiving block blk_-6200621081134523711_1019 src: /127.0.0.1:54173 dest: /127.0.0.1:55754
[junit] 09/10/12 12:42:03 INFO datanode.DataNode: Receiving block blk_-6200621081134523711_1019 src: /127.0.0.1:43282 dest: /127.0.0.1:47521
[junit] 09/10/12 12:42:03 INFO datanode.DataNode: Receiving block blk_-6200621081134523711_1019 src: /127.0.0.1:50459 dest: /127.0.0.1:52350
[junit] 09/10/12 12:42:03 INFO DataNode.clienttrace: src: /127.0.0.1:50459, dest: /127.0.0.1:52350, bytes: 6116, op: HDFS_WRITE, cliID: DFSClient_-928526854, srvID: DS-1188159356-127.0.1.1-52350-1255351275463, blockid: blk_-6200621081134523711_1019
[junit] 09/10/12 12:42:03 INFO datanode.DataNode: PacketResponder 0 for block blk_-6200621081134523711_1019 terminating
[junit] 09/10/12 12:42:03 INFO DataNode.clienttrace: src: /127.0.0.1:43282, dest: /127.0.0.1:47521, bytes: 6116, op: HDFS_WRITE, cliID: DFSClient_-928526854, srvID: DS-1256327855-127.0.1.1-47521-1255351276624, blockid: blk_-6200621081134523711_1019
[junit] 09/10/12 12:42:03 INFO datanode.DataNode: PacketResponder 1 for block blk_-6200621081134523711_1019 terminating
[junit] 09/10/12 12:42:03 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:52350 is added to blk_-6200621081134523711_1019 size 6116
[junit] 09/10/12 12:42:03 INFO DataNode.clienttrace: src: /127.0.0.1:54173, dest: /127.0.0.1:55754, bytes: 6116, op: HDFS_WRITE, cliID: DFSClient_-928526854, srvID: DS-108433573-127.0.1.1-55754-1255351274841, blockid: blk_-6200621081134523711_1019
[junit] 09/10/12 12:42:03 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:47521 is added to blk_-6200621081134523711_1019 size 6116
[junit] 09/10/12 12:42:03 INFO datanode.DataNode: PacketResponder 2 for block blk_-6200621081134523711_1019 terminating
[junit] 09/10/12 12:42:03 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:55754 is added to blk_-6200621081134523711_1019 size 6116
[junit] 09/10/12 12:42:03 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/temp1896202947/tmp-1253282919/_logs/history/localhost_1255351276736_job_20091012124116715_0002_hudson_Job841759538738982609.jar is closed by DFSClient_-928526854
[junit] 09/10/12 12:42:03 INFO mapred.JobTracker: Removed completed task 'attempt_20091012124116715_0002_m_000001_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:50522'
[junit] 09/10/12 12:42:03 INFO mapred.JobTracker: Removed completed task 'attempt_20091012124116715_0002_m_000002_0' from 'tracker_host1.foo.com:localhost/127.0.0.1:50522'
[junit] 09/10/12 12:42:03 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_8897466993134543700 is added to invalidSet of 127.0.0.1:52350
[junit] 09/10/12 12:42:03 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_8897466993134543700 is added to invalidSet of 127.0.0.1:55754
[junit] 09/10/12 12:42:03 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_8897466993134543700 is added to invalidSet of 127.0.0.1:47521
[junit] 09/10/12 12:42:03 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-2880930421464948328 is added to invalidSet of 127.0.0.1:52350
[junit] 09/10/12 12:42:03 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-2880930421464948328 is added to invalidSet of 127.0.0.1:48402
[junit] 09/10/12 12:42:03 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-2880930421464948328 is added to invalidSet of 127.0.0.1:55754
[junit] 09/10/12 12:42:03 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_64099637709780241 is added to invalidSet of 127.0.0.1:48402
[junit] 09/10/12 12:42:03 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_64099637709780241 is added to invalidSet of 127.0.0.1:47521
[junit] 09/10/12 12:42:03 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_64099637709780241 is added to invalidSet of 127.0.0.1:55754
[junit] 09/10/12 12:42:03 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_20091012124116715_0002
[junit] 09/10/12 12:42:03 INFO mapred.TaskRunner: attempt_20091012124116715_0002_m_000001_0 done; removing files.
[junit] 09/10/12 12:42:03 INFO mapred.IndexCache: Map ID attempt_20091012124116715_0002_m_000001_0 not found in cache
[junit] 09/10/12 12:42:03 INFO mapred.TaskRunner: attempt_20091012124116715_0002_m_000002_0 done; removing files.
[junit] 09/10/12 12:42:03 INFO mapred.IndexCache: Map ID attempt_20091012124116715_0002_m_000002_0 not found in cache
[junit] 09/10/12 12:42:03 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/tmp/hadoop-hudson/mapred/system/job_20091012124116715_0002 dst=null perm=null
[junit] 09/10/12 12:42:04 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_20091012124116715_0002
[junit] 09/10/12 12:42:04 WARN mapred.TaskTracker: Unknown job job_20091012124116715_0002 being deleted.
[junit] 09/10/12 12:42:04 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_20091012124116715_0002
[junit] 09/10/12 12:42:04 WARN mapred.TaskTracker: Unknown job job_20091012124116715_0002 being deleted.
[junit] 09/10/12 12:42:05 INFO mapReduceLayer.MapReduceLauncher: 100% complete
[junit] 09/10/12 12:42:05 INFO mapReduceLayer.MapReduceLauncher: Successfully stored result in: "hdfs://localhost:51091/tmp/temp1896202947/tmp-1253282919"
[junit] 09/10/12 12:42:05 INFO mapReduceLayer.MapReduceLauncher: Records written : 2
[junit] 09/10/12 12:42:05 INFO mapReduceLayer.MapReduceLauncher: Bytes written : 78
[junit] 09/10/12 12:42:05 INFO mapReduceLayer.MapReduceLauncher: Success!
[junit] 09/10/12 12:42:05 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=listStatus src=/tmp/temp1896202947/tmp-1253282919 dst=null perm=null
[junit] 09/10/12 12:42:05 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/temp1896202947/tmp-1253282919/part-00000 dst=null perm=null
[junit] 09/10/12 12:42:05 INFO DataNode.clienttrace: src: /127.0.0.1:52350, dest: /127.0.0.1:50460, bytes: 43, op: HDFS_READ, cliID: DFSClient_-928526854, srvID: DS-1188159356-127.0.1.1-52350-1255351275463, blockid: blk_672430965767855373_1018
[junit] 09/10/12 12:42:05 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/tmp/temp1896202947/tmp-1253282919/part-00001 dst=null perm=null
[junit] 09/10/12 12:42:05 INFO DataNode.clienttrace: src: /127.0.0.1:52350, dest: /127.0.0.1:50461, bytes: 43, op: HDFS_READ, cliID: DFSClient_-928526854, srvID: DS-1188159356-127.0.1.1-52350-1255351275463, blockid: blk_5914217004738264773_1019
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 45.211 sec
BUILD FAILED
<http://hudson.zones.apache.org/hudson/job/Pig-trunk/ws/trunk/build.xml>:496: The following error occurred while executing this line:
<http://hudson.zones.apache.org/hudson/job/Pig-trunk/ws/trunk/build.xml>:430: The following error occurred while executing this line:
<http://hudson.zones.apache.org/hudson/job/Pig-trunk/ws/trunk/build.xml>:491: Tests failed!
Total time: 152 minutes 24 seconds
Publishing Javadoc
Archiving artifacts
Recording test results
Recording fingerprints
Publishing Clover coverage report...
No Clover report will be published due to a Build Failure