See http://hudson.zones.apache.org/hudson/job/Pig-trunk/518/

------------------------------------------
[...truncated 86842 lines...]
    [junit] 09/08/10 14:42:20 INFO mapred.JobInProgress: Task 
'attempt_200908101441_0001_r_000000_0' has completed 
task_200908101441_0001_r_000000 successfully.
    [junit] 09/08/10 14:42:20 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_-6264389947015309622 is added to invalidSet of 127.0.0.1:41255
    [junit] 09/08/10 14:42:20 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_-6264389947015309622 is added to invalidSet of 127.0.0.1:38778
    [junit] 09/08/10 14:42:20 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_-6264389947015309622 is added to invalidSet of 127.0.0.1:57995
    [junit] 09/08/10 14:42:20 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_5765850477736280749 is added to invalidSet of 127.0.0.1:57995
    [junit] 09/08/10 14:42:20 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_5765850477736280749 is added to invalidSet of 127.0.0.1:38778
    [junit] 09/08/10 14:42:20 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_5765850477736280749 is added to invalidSet of 127.0.0.1:41255
    [junit] 09/08/10 14:42:20 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_7559869483135611448 is added to invalidSet of 127.0.0.1:41255
    [junit] 09/08/10 14:42:20 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_7559869483135611448 is added to invalidSet of 127.0.0.1:56802
    [junit] 09/08/10 14:42:20 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_7559869483135611448 is added to invalidSet of 127.0.0.1:57995
    [junit] 09/08/10 14:42:20 INFO mapred.JobInProgress: Job 
job_200908101441_0001 has completed successfully.
    [junit] 09/08/10 14:42:20 INFO dfs.StateChange: BLOCK* 
NameSystem.allocateBlock: 
/tmp/temp-1684136488/tmp1187787419/_logs/history/localhost_1249915296024_job_200908101441_0001_hudson_Job8913032530943062158.jar.
 blk_9039513662785461979_1009
    [junit] 09/08/10 14:42:20 INFO dfs.DataNode: Receiving block 
blk_9039513662785461979_1009 src: /127.0.0.1:33493 dest: /127.0.0.1:57995
    [junit] 09/08/10 14:42:20 INFO dfs.DataNode: Receiving block 
blk_9039513662785461979_1009 src: /127.0.0.1:35971 dest: /127.0.0.1:41255
    [junit] 09/08/10 14:42:20 INFO dfs.DataNode: Receiving block 
blk_9039513662785461979_1009 src: /127.0.0.1:44847 dest: /127.0.0.1:56802
    [junit] 09/08/10 14:42:20 INFO dfs.DataNode: Received block 
blk_9039513662785461979_1009 of size 5095 from /127.0.0.1
    [junit] 09/08/10 14:42:20 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:56802 is added to 
blk_9039513662785461979_1009 size 5095
    [junit] 09/08/10 14:42:20 INFO dfs.DataNode: PacketResponder 0 for block 
blk_9039513662785461979_1009 terminating
    [junit] 09/08/10 14:42:20 INFO dfs.DataNode: Received block 
blk_9039513662785461979_1009 of size 5095 from /127.0.0.1
    [junit] 09/08/10 14:42:20 INFO dfs.DataNode: PacketResponder 1 for block 
blk_9039513662785461979_1009 terminating
    [junit] 09/08/10 14:42:20 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:41255 is added to 
blk_9039513662785461979_1009 size 5095
    [junit] 09/08/10 14:42:20 INFO dfs.DataNode: Received block 
blk_9039513662785461979_1009 of size 5095 from /127.0.0.1
    [junit] 09/08/10 14:42:20 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57995 is added to 
blk_9039513662785461979_1009 size 5095
    [junit] 09/08/10 14:42:20 INFO dfs.DataNode: PacketResponder 2 for block 
blk_9039513662785461979_1009 terminating
    [junit] 09/08/10 14:42:20 INFO mapReduceLayer.MapReduceLauncher: 100% 
complete
    [junit] 09/08/10 14:42:20 INFO mapReduceLayer.MapReduceLauncher: 
Successfully stored result in: 
"hdfs://localhost:48231/tmp/temp-1684136488/tmp1187787419"
    [junit] 09/08/10 14:42:20 INFO mapReduceLayer.MapReduceLauncher: Records 
written : 1
    [junit] 09/08/10 14:42:20 INFO mapReduceLayer.MapReduceLauncher: Bytes 
written : 107
    [junit] 09/08/10 14:42:20 INFO mapReduceLayer.MapReduceLauncher: Success!
    [junit] 09/08/10 14:42:20 INFO dfs.DataNode: 
DatanodeRegistration(127.0.0.1:56802, 
storageID=DS-641934704-67.195.138.8-56802-1249915294946, infoPort=57860, 
ipcPort=35751) Served block blk_-8213206887175561647_1009 to /127.0.0.1
    [junit] 09/08/10 14:42:20 INFO executionengine.HExecutionEngine: Connecting 
to hadoop file system at: file:///
    [junit] 09/08/10 14:42:20 INFO jvm.JvmMetrics: Cannot initialize JVM 
Metrics with processName=JobTracker, sessionId= - already initialized
    [junit] 09/08/10 14:42:21 INFO dfs.StateChange: BLOCK* 
NameSystem.allocateBlock: /user/hudson/input1.txt. blk_-7512886654948818052_1010
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: Receiving block 
blk_-7512886654948818052_1010 src: /127.0.0.1:35974 dest: /127.0.0.1:41255
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: Receiving block 
blk_-7512886654948818052_1010 src: /127.0.0.1:33498 dest: /127.0.0.1:57995
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: Receiving block 
blk_-7512886654948818052_1010 src: /127.0.0.1:44851 dest: /127.0.0.1:56802
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: Received block 
blk_-7512886654948818052_1010 of size 6 from /127.0.0.1
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: PacketResponder 0 for block 
blk_-7512886654948818052_1010 terminating
    [junit] 09/08/10 14:42:21 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:56802 is added to 
blk_-7512886654948818052_1010 size 6
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: Received block 
blk_-7512886654948818052_1010 of size 6 from /127.0.0.1
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: PacketResponder 1 for block 
blk_-7512886654948818052_1010 terminating
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: Received block 
blk_-7512886654948818052_1010 of size 6 from /127.0.0.1
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: PacketResponder 2 for block 
blk_-7512886654948818052_1010 terminating
    [junit] 09/08/10 14:42:21 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57995 is added to 
blk_-7512886654948818052_1010 size 6
    [junit] 09/08/10 14:42:21 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:41255 is added to 
blk_-7512886654948818052_1010 size 6
    [junit] 09/08/10 14:42:21 INFO dfs.StateChange: BLOCK* 
NameSystem.allocateBlock: /user/hudson/input2.txt. blk_-7824982651833471896_1011
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: Receiving block 
blk_-7824982651833471896_1011 src: /127.0.0.1:35977 dest: /127.0.0.1:41255
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: Receiving block 
blk_-7824982651833471896_1011 src: /127.0.0.1:60572 dest: /127.0.0.1:38778
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: Receiving block 
blk_-7824982651833471896_1011 src: /127.0.0.1:33502 dest: /127.0.0.1:57995
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: Received block 
blk_-7824982651833471896_1011 of size 6 from /127.0.0.1
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: PacketResponder 0 for block 
blk_-7824982651833471896_1011 terminating
    [junit] 09/08/10 14:42:21 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57995 is added to 
blk_-7824982651833471896_1011 size 6
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: Received block 
blk_-7824982651833471896_1011 of size 6 from /127.0.0.1
    [junit] 09/08/10 14:42:21 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:38778 is added to 
blk_-7824982651833471896_1011 size 6
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: PacketResponder 1 for block 
blk_-7824982651833471896_1011 terminating
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: Received block 
blk_-7824982651833471896_1011 of size 6 from /127.0.0.1
    [junit] 09/08/10 14:42:21 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:41255 is added to 
blk_-7824982651833471896_1011 size 6
    [junit] 09/08/10 14:42:21 INFO dfs.DataNode: PacketResponder 2 for block 
blk_-7824982651833471896_1011 terminating
    [junit] 09/08/10 14:42:21 INFO executionengine.HExecutionEngine: Connecting 
to hadoop file system at: hdfs://localhost:48231
    [junit] 09/08/10 14:42:21 INFO executionengine.HExecutionEngine: Connecting 
to map-reduce job tracker at: localhost:45602
    [junit] 09/08/10 14:42:21 INFO mapReduceLayer.MultiQueryOptimizer: MR plan 
size before optimization: 1
    [junit] 09/08/10 14:42:21 INFO mapReduceLayer.MultiQueryOptimizer: MR plan 
size after optimization: 1
    [junit] 09/08/10 14:42:22 INFO mapReduceLayer.JobControlCompiler: Setting 
up single store job
    [junit] 09/08/10 14:42:22 WARN mapred.JobClient: Use GenericOptionsParser 
for parsing the arguments. Applications should implement Tool for the same.
    [junit] 09/08/10 14:42:22 INFO dfs.StateChange: BLOCK* 
NameSystem.allocateBlock: 
/tmp/hadoop-hudson/mapred/system/job_200908101441_0002/job.jar. 
blk_-7105650169008305754_1012
    [junit] 09/08/10 14:42:22 INFO dfs.DataNode: Receiving block 
blk_-7105650169008305754_1012 src: /127.0.0.1:35980 dest: /127.0.0.1:41255
    [junit] 09/08/10 14:42:22 INFO dfs.DataNode: Receiving block 
blk_-7105650169008305754_1012 src: /127.0.0.1:60575 dest: /127.0.0.1:38778
    [junit] 09/08/10 14:42:22 INFO dfs.DataNode: Receiving block 
blk_-7105650169008305754_1012 src: /127.0.0.1:33505 dest: /127.0.0.1:57995
    [junit] 09/08/10 14:42:22 INFO dfs.DataNode: Received block 
blk_-7105650169008305754_1012 of size 2621831 from /127.0.0.1
    [junit] 09/08/10 14:42:22 INFO dfs.StateChange: BLOCK* ask 127.0.0.1:38778 
to delete  blk_5765850477736280749_1005 blk_-6264389947015309622_1004
    [junit] 09/08/10 14:42:22 INFO dfs.DataNode: PacketResponder 0 for block 
blk_-7105650169008305754_1012 terminating
    [junit] 09/08/10 14:42:22 INFO dfs.StateChange: BLOCK* ask 127.0.0.1:41255 
to delete  blk_5765850477736280749_1005 blk_7559869483135611448_1006 
blk_-6264389947015309622_1004
    [junit] 09/08/10 14:42:22 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57995 is added to 
blk_-7105650169008305754_1012 size 2621831
    [junit] 09/08/10 14:42:22 INFO dfs.DataNode: Received block 
blk_-7105650169008305754_1012 of size 2621831 from /127.0.0.1
    [junit] 09/08/10 14:42:22 INFO dfs.DataNode: PacketResponder 1 for block 
blk_-7105650169008305754_1012 terminating
    [junit] 09/08/10 14:42:22 INFO dfs.DataNode: Received block 
blk_-7105650169008305754_1012 of size 2621831 from /127.0.0.1
    [junit] 09/08/10 14:42:22 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:38778 is added to 
blk_-7105650169008305754_1012 size 2621831
    [junit] 09/08/10 14:42:22 INFO dfs.DataNode: PacketResponder 2 for block 
blk_-7105650169008305754_1012 terminating
    [junit] 09/08/10 14:42:22 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:41255 is added to 
blk_-7105650169008305754_1012 size 2621831
    [junit] 09/08/10 14:42:22 INFO fs.FSNamesystem: Increasing replication for 
file /tmp/hadoop-hudson/mapred/system/job_200908101441_0002/job.jar. New 
replication is 2
    [junit] 09/08/10 14:42:22 INFO fs.FSNamesystem: Reducing replication for 
file /tmp/hadoop-hudson/mapred/system/job_200908101441_0002/job.jar. New 
replication is 2
    [junit] 09/08/10 14:42:23 INFO mapReduceLayer.MapReduceLauncher: 0% complete
    [junit] 09/08/10 14:42:23 INFO dfs.StateChange: BLOCK* 
NameSystem.allocateBlock: 
/tmp/hadoop-hudson/mapred/system/job_200908101441_0002/job.split. 
blk_-8046316802797514402_1013
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Receiving block 
blk_-8046316802797514402_1013 src: /127.0.0.1:60577 dest: /127.0.0.1:38778
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Receiving block 
blk_-8046316802797514402_1013 src: /127.0.0.1:44859 dest: /127.0.0.1:56802
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Receiving block 
blk_-8046316802797514402_1013 src: /127.0.0.1:35985 dest: /127.0.0.1:41255
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Received block 
blk_-8046316802797514402_1013 of size 1837 from /127.0.0.1
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: PacketResponder 0 for block 
blk_-8046316802797514402_1013 terminating
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Received block 
blk_-8046316802797514402_1013 of size 1837 from /127.0.0.1
    [junit] 09/08/10 14:42:23 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:41255 is added to 
blk_-8046316802797514402_1013 size 1837
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: PacketResponder 1 for block 
blk_-8046316802797514402_1013 terminating
    [junit] 09/08/10 14:42:23 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:56802 is added to 
blk_-8046316802797514402_1013 size 1837
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Received block 
blk_-8046316802797514402_1013 of size 1837 from /127.0.0.1
    [junit] 09/08/10 14:42:23 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:38778 is added to 
blk_-8046316802797514402_1013 size 1837
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: PacketResponder 2 for block 
blk_-8046316802797514402_1013 terminating
    [junit] 09/08/10 14:42:23 INFO mapred.JobTracker: Removed completed task 
'attempt_200908101441_0001_m_000000_0' from 
'tracker_host0.foo.com:localhost/127.0.0.1:37428'
    [junit] 09/08/10 14:42:23 INFO mapred.TaskTracker: Received 'KillJobAction' 
for job: job_200908101441_0001
    [junit] 09/08/10 14:42:23 INFO mapred.TaskRunner: 
attempt_200908101441_0001_m_000000_0 done; removing files.
    [junit] 09/08/10 14:42:23 INFO dfs.StateChange: BLOCK* 
NameSystem.allocateBlock: 
/tmp/hadoop-hudson/mapred/system/job_200908101441_0002/job.xml. 
blk_7040848714553746500_1014
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Receiving block 
blk_7040848714553746500_1014 src: /127.0.0.1:44861 dest: /127.0.0.1:56802
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Receiving block 
blk_7040848714553746500_1014 src: /127.0.0.1:33510 dest: /127.0.0.1:57995
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Receiving block 
blk_7040848714553746500_1014 src: /127.0.0.1:35988 dest: /127.0.0.1:41255
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Received block 
blk_7040848714553746500_1014 of size 41546 from /127.0.0.1
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: PacketResponder 0 for block 
blk_7040848714553746500_1014 terminating
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Received block 
blk_7040848714553746500_1014 of size 41546 from /127.0.0.1
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: PacketResponder 1 for block 
blk_7040848714553746500_1014 terminating
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Received block 
blk_7040848714553746500_1014 of size 41546 from /127.0.0.1
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: PacketResponder 2 for block 
blk_7040848714553746500_1014 terminating
    [junit] 09/08/10 14:42:23 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:41255 is added to 
blk_7040848714553746500_1014 size 41546
    [junit] 09/08/10 14:42:23 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57995 is added to 
blk_7040848714553746500_1014 size 41546
    [junit] 09/08/10 14:42:23 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:56802 is added to 
blk_7040848714553746500_1014 size 41546
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: 
DatanodeRegistration(127.0.0.1:41255, 
storageID=DS-1510265123-67.195.138.8-41255-1249915279250, infoPort=37227, 
ipcPort=59786) Served block blk_7040848714553746500_1014 to /127.0.0.1
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: 
DatanodeRegistration(127.0.0.1:57995, 
storageID=DS-2111438217-67.195.138.8-57995-1249915289727, infoPort=37549, 
ipcPort=45729) Served block blk_-7105650169008305754_1012 to /127.0.0.1
    [junit] 09/08/10 14:42:23 INFO dfs.StateChange: BLOCK* 
NameSystem.allocateBlock: 
/tmp/temp-1684136488/tmp-77125168/_logs/history/localhost_1249915296024_job_200908101441_0002_conf.xml.
 blk_-4516189612117361948_1016
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Receiving block 
blk_-4516189612117361948_1016 src: /127.0.0.1:33514 dest: /127.0.0.1:57995
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Receiving block 
blk_-4516189612117361948_1016 src: /127.0.0.1:44867 dest: /127.0.0.1:56802
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Receiving block 
blk_-4516189612117361948_1016 src: /127.0.0.1:60587 dest: /127.0.0.1:38778
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Received block 
blk_-4516189612117361948_1016 of size 41522 from /127.0.0.1
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: PacketResponder 0 for block 
blk_-4516189612117361948_1016 terminating
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Received block 
blk_-4516189612117361948_1016 of size 41522 from /127.0.0.1
    [junit] 09/08/10 14:42:23 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:38778 is added to 
blk_-4516189612117361948_1016 size 41522
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: Received block 
blk_-4516189612117361948_1016 of size 41522 from /127.0.0.1
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: PacketResponder 1 for block 
blk_-4516189612117361948_1016 terminating
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: PacketResponder 2 for block 
blk_-4516189612117361948_1016 terminating
    [junit] 09/08/10 14:42:23 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:56802 is added to 
blk_-4516189612117361948_1016 size 41522
    [junit] 09/08/10 14:42:23 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57995 is added to 
blk_-4516189612117361948_1016 size 41522
    [junit] 09/08/10 14:42:23 INFO mapred.JobTracker: Removed completed task 
'attempt_200908101441_0001_m_000002_0' from 
'tracker_host3.foo.com:localhost/127.0.0.1:44645'
    [junit] 09/08/10 14:42:23 INFO mapred.TaskTracker: Received 'KillJobAction' 
for job: job_200908101441_0001
    [junit] 09/08/10 14:42:23 INFO mapred.JobTracker: Removed completed task 
'attempt_200908101441_0001_r_000000_0' from 
'tracker_host2.foo.com:localhost/127.0.0.1:46222'
    [junit] 09/08/10 14:42:23 INFO mapred.TaskRunner: 
attempt_200908101441_0001_m_000002_0 done; removing files.
    [junit] 09/08/10 14:42:23 INFO mapred.JobTracker: Removed completed task 
'attempt_200908101441_0001_m_000001_0' from 
'tracker_host1.foo.com:localhost/127.0.0.1:33918'
    [junit] 09/08/10 14:42:23 INFO mapred.TaskTracker: Received 'KillJobAction' 
for job: job_200908101441_0001
    [junit] 09/08/10 14:42:23 INFO mapred.TaskRunner: 
attempt_200908101441_0001_r_000000_0 done; removing files.
    [junit] 09/08/10 14:42:23 INFO mapred.JobInProgress: Split info for 
job:job_200908101441_0002
    [junit] 09/08/10 14:42:23 INFO dfs.DataNode: 
DatanodeRegistration(127.0.0.1:38778, 
storageID=DS-1234262549-67.195.138.8-38778-1249915284514, infoPort=43625, 
ipcPort=59357) Served block blk_-8046316802797514402_1013 to /127.0.0.1
    [junit] 09/08/10 14:42:23 INFO mapred.JobInProgress: 
tip:task_200908101441_0002_m_000000 has split on 
node:/default-rack/minerva.apache.org
    [junit] 09/08/10 14:42:23 INFO mapred.JobInProgress: 
tip:task_200908101441_0002_m_000001 has split on 
node:/default-rack/minerva.apache.org
    [junit] 09/08/10 14:42:23 INFO mapred.TaskTracker: Received 'KillJobAction' 
for job: job_200908101441_0001
    [junit] 09/08/10 14:42:23 INFO mapred.TaskRunner: 
attempt_200908101441_0001_m_000001_0 done; removing files.
    [junit] 09/08/10 14:42:24 INFO dfs.DataNode: Deleting block 
blk_-6264389947015309622_1004 file 
dfs/data/data3/current/blk_-6264389947015309622
    [junit] 09/08/10 14:42:24 INFO dfs.DataNode: Deleting block 
blk_5765850477736280749_1005 file dfs/data/data4/current/blk_5765850477736280749
    [junit] 09/08/10 14:42:25 INFO mapred.JobInProgress: Choosing rack-local 
task task_200908101441_0002_m_000000
    [junit] 09/08/10 14:42:25 INFO mapred.JobTracker: Adding task 
'attempt_200908101441_0002_m_000000_0' to tip task_200908101441_0002_m_000000, 
for tracker 'tracker_host0.foo.com:localhost/127.0.0.1:37428'
    [junit] 09/08/10 14:42:25 INFO mapred.TaskTracker: LaunchTaskAction: 
attempt_200908101441_0002_m_000000_0
    [junit] 09/08/10 14:42:25 INFO dfs.DataNode: 
DatanodeRegistration(127.0.0.1:41255, 
storageID=DS-1510265123-67.195.138.8-41255-1249915279250, infoPort=37227, 
ipcPort=59786) Served block blk_7040848714553746500_1014 to /127.0.0.1
    [junit] 09/08/10 14:42:25 INFO dfs.DataNode: 
DatanodeRegistration(127.0.0.1:41255, 
storageID=DS-1510265123-67.195.138.8-41255-1249915279250, infoPort=37227, 
ipcPort=59786) Served block blk_-7105650169008305754_1012 to /127.0.0.1
    [junit] 09/08/10 14:42:25 INFO mapred.JobInProgress: Choosing rack-local 
task task_200908101441_0002_m_000001
    [junit] 09/08/10 14:42:25 INFO mapred.JobTracker: Adding task 
'attempt_200908101441_0002_m_000001_0' to tip task_200908101441_0002_m_000001, 
for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:33918'
    [junit] 09/08/10 14:42:25 INFO mapred.TaskTracker: LaunchTaskAction: 
attempt_200908101441_0002_m_000001_0
    [junit] 09/08/10 14:42:25 INFO dfs.DataNode: 
DatanodeRegistration(127.0.0.1:56802, 
storageID=DS-641934704-67.195.138.8-56802-1249915294946, infoPort=57860, 
ipcPort=35751) Served block blk_7040848714553746500_1014 to /127.0.0.1
    [junit] 09/08/10 14:42:25 INFO dfs.DataNode: Deleting block 
blk_-6264389947015309622_1004 file 
dfs/data/data2/current/blk_-6264389947015309622
    [junit] 09/08/10 14:42:25 INFO dfs.DataNode: Deleting block 
blk_5765850477736280749_1005 file dfs/data/data1/current/blk_5765850477736280749
    [junit] 09/08/10 14:42:25 INFO dfs.DataNode: Deleting block 
blk_7559869483135611448_1006 file dfs/data/data2/current/blk_7559869483135611448
    [junit] 09/08/10 14:42:25 INFO dfs.DataNode: 
DatanodeRegistration(127.0.0.1:41255, 
storageID=DS-1510265123-67.195.138.8-41255-1249915279250, infoPort=37227, 
ipcPort=59786) Served block blk_-7105650169008305754_1012 to /127.0.0.1
    [junit] 09/08/10 14:42:25 INFO dfs.StateChange: BLOCK* ask 127.0.0.1:41255 
to delete  blk_-7105650169008305754_1012
    [junit] 09/08/10 14:42:25 INFO dfs.StateChange: BLOCK* ask 127.0.0.1:57995 
to delete  blk_5765850477736280749_1005 blk_7559869483135611448_1006 
blk_-6264389947015309622_1004
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: 
DatanodeRegistration(127.0.0.1:38778, 
storageID=DS-1234262549-67.195.138.8-38778-1249915284514, infoPort=43625, 
ipcPort=59357) Served block blk_-7824982651833471896_1011 to /127.0.0.1
    [junit] 09/08/10 14:42:26 INFO dfs.StateChange: BLOCK* 
NameSystem.allocateBlock: 
/tmp/temp-1684136488/tmp-77125168/_temporary/_attempt_200908101441_0002_m_000000_0/part-00000.
 blk_-2544217646066673000_1017
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: Receiving block 
blk_-2544217646066673000_1017 src: /127.0.0.1:44880 dest: /127.0.0.1:56802
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: Receiving block 
blk_-2544217646066673000_1017 src: /127.0.0.1:60601 dest: /127.0.0.1:38778
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: Receiving block 
blk_-2544217646066673000_1017 src: /127.0.0.1:36008 dest: /127.0.0.1:41255
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: Received block 
blk_-2544217646066673000_1017 of size 39 from /127.0.0.1
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: PacketResponder 0 for block 
blk_-2544217646066673000_1017 terminating
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: Received block 
blk_-2544217646066673000_1017 of size 39 from /127.0.0.1
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: PacketResponder 1 for block 
blk_-2544217646066673000_1017 terminating
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: Received block 
blk_-2544217646066673000_1017 of size 39 from /127.0.0.1
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: PacketResponder 2 for block 
blk_-2544217646066673000_1017 terminating
    [junit] 09/08/10 14:42:26 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:38778 is added to 
blk_-2544217646066673000_1017 size 39
    [junit] 09/08/10 14:42:26 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:56802 is added to 
blk_-2544217646066673000_1017 size 39
    [junit] 09/08/10 14:42:26 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:41255 is added to 
blk_-2544217646066673000_1017 size 39
    [junit] 09/08/10 14:42:26 INFO mapred.TaskTracker: 
attempt_200908101441_0002_m_000000_0 1.0% 
    [junit] 09/08/10 14:42:26 INFO mapred.TaskTracker: Task 
attempt_200908101441_0002_m_000000_0 is done.
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: 
DatanodeRegistration(127.0.0.1:57995, 
storageID=DS-2111438217-67.195.138.8-57995-1249915289727, infoPort=37549, 
ipcPort=45729) Served block blk_-7512886654948818052_1010 to /127.0.0.1
    [junit] 09/08/10 14:42:26 INFO dfs.StateChange: BLOCK* 
NameSystem.allocateBlock: 
/tmp/temp-1684136488/tmp-77125168/_temporary/_attempt_200908101441_0002_m_000001_0/part-00001.
 blk_-2639015314832953496_1018
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: Receiving block 
blk_-2639015314832953496_1018 src: /127.0.0.1:33533 dest: /127.0.0.1:57995
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: Receiving block 
blk_-2639015314832953496_1018 src: /127.0.0.1:44886 dest: /127.0.0.1:56802
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: Receiving block 
blk_-2639015314832953496_1018 src: /127.0.0.1:60606 dest: /127.0.0.1:38778
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: Received block 
blk_-2639015314832953496_1018 of size 39 from /127.0.0.1
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: PacketResponder 0 for block 
blk_-2639015314832953496_1018 terminating
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: Received block 
blk_-2639015314832953496_1018 of size 39 from /127.0.0.1
    [junit] 09/08/10 14:42:26 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:38778 is added to 
blk_-2639015314832953496_1018 size 39
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: Received block 
blk_-2639015314832953496_1018 of size 39 from /127.0.0.1
    [junit] 09/08/10 14:42:26 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:56802 is added to 
blk_-2639015314832953496_1018 size 39
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: PacketResponder 1 for block 
blk_-2639015314832953496_1018 terminating
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: PacketResponder 2 for block 
blk_-2639015314832953496_1018 terminating
    [junit] 09/08/10 14:42:26 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57995 is added to 
blk_-2639015314832953496_1018 size 39
    [junit] 09/08/10 14:42:26 INFO mapred.TaskTracker: 
attempt_200908101441_0002_m_000001_0 1.0% 
    [junit] 09/08/10 14:42:26 INFO mapred.TaskTracker: Task 
attempt_200908101441_0002_m_000001_0 is done.
    [junit] 09/08/10 14:42:26 WARN dfs.DataNode: Unexpected error trying to 
delete block blk_-6264389947015309622_1004. BlockInfo not found in volumeMap.
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: Deleting block 
blk_5765850477736280749_1005 file dfs/data/data6/current/blk_5765850477736280749
    [junit] 09/08/10 14:42:26 INFO dfs.DataNode: Deleting block 
blk_7559869483135611448_1006 file dfs/data/data5/current/blk_7559869483135611448
    [junit] 09/08/10 14:42:26 WARN dfs.DataNode: java.io.IOException: Error in 
deleting blocks.
    [junit]     at 
org.apache.hadoop.dfs.FSDataset.invalidate(FSDataset.java:1146)
    [junit]     at 
org.apache.hadoop.dfs.DataNode.processCommand(DataNode.java:793)
    [junit]     at 
org.apache.hadoop.dfs.DataNode.offerService(DataNode.java:663)
    [junit]     at org.apache.hadoop.dfs.DataNode.run(DataNode.java:2888)
    [junit]     at java.lang.Thread.run(Thread.java:619)
    [junit] 
    [junit] 09/08/10 14:42:27 INFO mapred.TaskRunner: Saved output of task 
'attempt_200908101441_0002_m_000000_0' to 
hdfs://localhost:48231/tmp/temp-1684136488/tmp-77125168
    [junit] 09/08/10 14:42:27 INFO mapred.JobInProgress: Task 
'attempt_200908101441_0002_m_000000_0' has completed 
task_200908101441_0002_m_000000 successfully.
    [junit] 09/08/10 14:42:27 INFO mapReduceLayer.MapReduceLauncher: 25% 
complete
    [junit] 09/08/10 14:42:27 INFO mapred.TaskRunner: Saved output of task 
'attempt_200908101441_0002_m_000001_0' to 
hdfs://localhost:48231/tmp/temp-1684136488/tmp-77125168
    [junit] 09/08/10 14:42:27 INFO mapred.JobInProgress: Task 
'attempt_200908101441_0002_m_000001_0' has completed 
task_200908101441_0002_m_000001 successfully.
    [junit] 09/08/10 14:42:27 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_-7105650169008305754 is added to invalidSet of 127.0.0.1:57995
    [junit] 09/08/10 14:42:27 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_-7105650169008305754 is added to invalidSet of 127.0.0.1:38778
    [junit] 09/08/10 14:42:27 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_-7105650169008305754 is added to invalidSet of 127.0.0.1:41255
    [junit] 09/08/10 14:42:27 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_-8046316802797514402 is added to invalidSet of 127.0.0.1:41255
    [junit] 09/08/10 14:42:27 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_-8046316802797514402 is added to invalidSet of 127.0.0.1:56802
    [junit] 09/08/10 14:42:27 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_-8046316802797514402 is added to invalidSet of 127.0.0.1:38778
    [junit] 09/08/10 14:42:27 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_7040848714553746500 is added to invalidSet of 127.0.0.1:41255
    [junit] 09/08/10 14:42:27 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_7040848714553746500 is added to invalidSet of 127.0.0.1:57995
    [junit] 09/08/10 14:42:27 INFO dfs.StateChange: BLOCK* NameSystem.delete: 
blk_7040848714553746500 is added to invalidSet of 127.0.0.1:56802
    [junit] 09/08/10 14:42:27 INFO mapred.JobInProgress: Job 
job_200908101441_0002 has completed successfully.
    [junit] 09/08/10 14:42:27 INFO dfs.StateChange: BLOCK* 
NameSystem.allocateBlock: 
/tmp/temp-1684136488/tmp-77125168/_logs/history/localhost_1249915296024_job_200908101441_0002_hudson_Job4742965055062003601.jar.
 blk_6638214393658200114_1018
    [junit] 09/08/10 14:42:27 INFO dfs.DataNode: Receiving block 
blk_6638214393658200114_1018 src: /127.0.0.1:36013 dest: /127.0.0.1:41255
    [junit] 09/08/10 14:42:27 INFO dfs.DataNode: Receiving block 
blk_6638214393658200114_1018 src: /127.0.0.1:33537 dest: /127.0.0.1:57995
    [junit] 09/08/10 14:42:27 INFO dfs.DataNode: Receiving block 
blk_6638214393658200114_1018 src: /127.0.0.1:60609 dest: /127.0.0.1:38778
    [junit] 09/08/10 14:42:27 INFO dfs.DataNode: Received block 
blk_6638214393658200114_1018 of size 2430 from /127.0.0.1
    [junit] 09/08/10 14:42:27 INFO dfs.DataNode: Received block 
blk_6638214393658200114_1018 of size 2430 from /127.0.0.1
    [junit] 09/08/10 14:42:27 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:38778 is added to 
blk_6638214393658200114_1018 size 2430
    [junit] 09/08/10 14:42:27 INFO dfs.DataNode: PacketResponder 0 for block 
blk_6638214393658200114_1018 terminating
    [junit] 09/08/10 14:42:27 INFO dfs.DataNode: Received block 
blk_6638214393658200114_1018 of size 2430 from /127.0.0.1
    [junit] 09/08/10 14:42:27 INFO dfs.DataNode: PacketResponder 1 for block 
blk_6638214393658200114_1018 terminating
    [junit] 09/08/10 14:42:27 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57995 is added to 
blk_6638214393658200114_1018 size 2430
    [junit] 09/08/10 14:42:27 INFO dfs.DataNode: PacketResponder 2 for block 
blk_6638214393658200114_1018 terminating
    [junit] 09/08/10 14:42:27 INFO dfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:41255 is added to 
blk_6638214393658200114_1018 size 2430
    [junit] 09/08/10 14:42:28 INFO dfs.DataNode: Deleting block 
blk_-7105650169008305754_1012 file 
dfs/data/data1/current/blk_-7105650169008305754
    [junit] 09/08/10 14:42:28 INFO mapReduceLayer.MapReduceLauncher: 100% 
complete
    [junit] 09/08/10 14:42:28 INFO mapReduceLayer.MapReduceLauncher: 
Successfully stored result in: 
"hdfs://localhost:48231/tmp/temp-1684136488/tmp-77125168"
    [junit] 09/08/10 14:42:28 INFO mapReduceLayer.MapReduceLauncher: Records 
written : 2
    [junit] 09/08/10 14:42:28 INFO mapReduceLayer.MapReduceLauncher: Bytes 
written : 78
    [junit] 09/08/10 14:42:28 INFO mapReduceLayer.MapReduceLauncher: Success!
    [junit] 09/08/10 14:42:28 INFO dfs.DataNode: 
DatanodeRegistration(127.0.0.1:56802, 
storageID=DS-641934704-67.195.138.8-56802-1249915294946, infoPort=57860, 
ipcPort=35751) Served block blk_-2544217646066673000_1017 to /127.0.0.1
    [junit] 09/08/10 14:42:28 INFO dfs.DataNode: 
DatanodeRegistration(127.0.0.1:57995, 
storageID=DS-2111438217-67.195.138.8-57995-1249915289727, infoPort=37549, 
ipcPort=45729) Served block blk_-2639015314832953496_1018 to /127.0.0.1
    [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 31.122 sec
    [junit] 09/08/10 14:42:28 INFO dfs.StateChange: BLOCK* ask 127.0.0.1:38778 
to delete  blk_-8046316802797514402_1013 blk_-7105650169008305754_1012
    [junit] 09/08/10 14:42:28 INFO dfs.StateChange: BLOCK* ask 127.0.0.1:41255 
to delete  blk_-8046316802797514402_1013 blk_-7105650169008305754_1012 
blk_7040848714553746500_1014

BUILD FAILED
http://hudson.zones.apache.org/hudson/job/Pig-trunk/ws/trunk/build.xml :469: 
The following error occurred while executing this line:
http://hudson.zones.apache.org/hudson/job/Pig-trunk/ws/trunk/build.xml :465: 
Tests failed!

Total time: 110 minutes 59 seconds
[locks-and-latches] Releasing all the locks
[locks-and-latches] All the locks released
Publishing Javadoc
Recording test results
Recording fingerprints
Publishing Clover coverage report...

Reply via email to