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/08/10 16:43:50 UTC
Build failed in Hudson: Pig-trunk #518
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...
Hudson build is back to normal: Pig-trunk #519
Posted by Apache Hudson Server <hu...@hudson.zones.apache.org>.
See http://hudson.zones.apache.org/hudson/job/Pig-trunk/519/