See http://hudson.zones.apache.org/hudson/job/Pig-trunk/514/changes
Changes:
[pradeepkth] PIG-901: InputSplit (SliceWrapper) created by Pig is big in size
due to serialized PigContext (pradeepkth)
------------------------------------------
[...truncated 104965 lines...]
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK* NameSystem.delete:
blk_-8120952403598744369 is added to invalidSet of 127.0.0.1:60802
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK* NameSystem.delete:
blk_9096751694584793699 is added to invalidSet of 127.0.0.1:33494
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK* NameSystem.delete:
blk_9096751694584793699 is added to invalidSet of 127.0.0.1:60802
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK* NameSystem.delete:
blk_9096751694584793699 is added to invalidSet of 127.0.0.1:43578
[junit] 09/08/06 17:49:55 INFO mapred.JobInProgress: Job
job_200908061749_0001 has completed successfully.
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK*
NameSystem.allocateBlock:
/tmp/temp-168142045/tmp-1447977177/_logs/history/localhost_1249580955802_job_200908061749_0001_hudson_Job2122827364781574180.jar.
blk_1849437138125061018_1009
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Receiving block
blk_1849437138125061018_1009 src: /127.0.0.1:56785 dest: /127.0.0.1:60802
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Receiving block
blk_1849437138125061018_1009 src: /127.0.0.1:50272 dest: /127.0.0.1:43578
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Receiving block
blk_1849437138125061018_1009 src: /127.0.0.1:51071 dest: /127.0.0.1:33494
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Received block
blk_1849437138125061018_1009 of size 5095 from /127.0.0.1
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: PacketResponder 0 for block
blk_1849437138125061018_1009 terminating
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33494 is added to
blk_1849437138125061018_1009 size 5095
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Received block
blk_1849437138125061018_1009 of size 5095 from /127.0.0.1
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:43578 is added to
blk_1849437138125061018_1009 size 5095
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: PacketResponder 1 for block
blk_1849437138125061018_1009 terminating
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Received block
blk_1849437138125061018_1009 of size 5095 from /127.0.0.1
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: PacketResponder 2 for block
blk_1849437138125061018_1009 terminating
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:60802 is added to
blk_1849437138125061018_1009 size 5095
[junit] 09/08/06 17:49:55 INFO mapred.JobTracker: Removed completed task
'attempt_200908061749_0001_m_000000_0' from
'tracker_host0.foo.com:localhost/127.0.0.1:37702'
[junit] 09/08/06 17:49:55 INFO mapred.TaskTracker: Received 'KillJobAction'
for job: job_200908061749_0001
[junit] 09/08/06 17:49:55 INFO mapred.TaskRunner:
attempt_200908061749_0001_m_000000_0 done; removing files.
[junit] 09/08/06 17:49:55 INFO mapred.JobTracker: Removed completed task
'attempt_200908061749_0001_m_000001_0' from
'tracker_host2.foo.com:localhost/127.0.0.1:60936'
[junit] 09/08/06 17:49:55 INFO mapred.TaskTracker: Received 'KillJobAction'
for job: job_200908061749_0001
[junit] 09/08/06 17:49:55 INFO mapred.TaskRunner:
attempt_200908061749_0001_m_000001_0 done; removing files.
[junit] 09/08/06 17:49:55 INFO mapred.JobTracker: Removed completed task
'attempt_200908061749_0001_m_000002_0' from
'tracker_host1.foo.com:localhost/127.0.0.1:46880'
[junit] 09/08/06 17:49:55 INFO mapred.TaskTracker: Received 'KillJobAction'
for job: job_200908061749_0001
[junit] 09/08/06 17:49:55 INFO mapred.TaskRunner:
attempt_200908061749_0001_m_000002_0 done; removing files.
[junit] 09/08/06 17:49:55 INFO mapReduceLayer.MapReduceLauncher: 100%
complete
[junit] 09/08/06 17:49:55 INFO mapReduceLayer.MapReduceLauncher:
Successfully stored result in:
"hdfs://localhost:55054/tmp/temp-168142045/tmp-1447977177"
[junit] 09/08/06 17:49:55 INFO mapReduceLayer.MapReduceLauncher: Records
written : 1
[junit] 09/08/06 17:49:55 INFO mapReduceLayer.MapReduceLauncher: Bytes
written : 107
[junit] 09/08/06 17:49:55 INFO mapReduceLayer.MapReduceLauncher: Success!
[junit] 09/08/06 17:49:55 INFO dfs.DataNode:
DatanodeRegistration(127.0.0.1:43578,
storageID=DS-766824271-67.195.138.8-43578-1249580949547, infoPort=60131,
ipcPort=44257) Served block blk_-6329747787385258393_1009 to /127.0.0.1
[junit] 09/08/06 17:49:55 INFO executionengine.HExecutionEngine: Connecting
to hadoop file system at: file:///
[junit] 09/08/06 17:49:55 INFO jvm.JvmMetrics: Cannot initialize JVM
Metrics with processName=JobTracker, sessionId= - already initialized
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK*
NameSystem.allocateBlock: /user/hudson/input1.txt. blk_-4775973519683222245_1010
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Receiving block
blk_-4775973519683222245_1010 src: /127.0.0.1:51073 dest: /127.0.0.1:33494
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Receiving block
blk_-4775973519683222245_1010 src: /127.0.0.1:56790 dest: /127.0.0.1:60802
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Receiving block
blk_-4775973519683222245_1010 src: /127.0.0.1:50277 dest: /127.0.0.1:43578
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Received block
blk_-4775973519683222245_1010 of size 6 from /127.0.0.1
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:43578 is added to
blk_-4775973519683222245_1010 size 6
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: PacketResponder 0 for block
blk_-4775973519683222245_1010 terminating
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Received block
blk_-4775973519683222245_1010 of size 6 from /127.0.0.1
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:60802 is added to
blk_-4775973519683222245_1010 size 6
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: PacketResponder 1 for block
blk_-4775973519683222245_1010 terminating
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Received block
blk_-4775973519683222245_1010 of size 6 from /127.0.0.1
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33494 is added to
blk_-4775973519683222245_1010 size 6
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: PacketResponder 2 for block
blk_-4775973519683222245_1010 terminating
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK*
NameSystem.allocateBlock: /user/hudson/input2.txt. blk_466717348025503100_1011
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Receiving block
blk_466717348025503100_1011 src: /127.0.0.1:59627 dest: /127.0.0.1:33326
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Receiving block
blk_466717348025503100_1011 src: /127.0.0.1:56793 dest: /127.0.0.1:60802
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Receiving block
blk_466717348025503100_1011 src: /127.0.0.1:51078 dest: /127.0.0.1:33494
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Received block
blk_466717348025503100_1011 of size 6 from /127.0.0.1
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: PacketResponder 0 for block
blk_466717348025503100_1011 terminating
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33494 is added to
blk_466717348025503100_1011 size 6
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Received block
blk_466717348025503100_1011 of size 6 from /127.0.0.1
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:60802 is added to
blk_466717348025503100_1011 size 6
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: PacketResponder 1 for block
blk_466717348025503100_1011 terminating
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: Received block
blk_466717348025503100_1011 of size 6 from /127.0.0.1
[junit] 09/08/06 17:49:55 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33326 is added to
blk_466717348025503100_1011 size 6
[junit] 09/08/06 17:49:55 INFO dfs.DataNode: PacketResponder 2 for block
blk_466717348025503100_1011 terminating
[junit] 09/08/06 17:49:55 INFO executionengine.HExecutionEngine: Connecting
to hadoop file system at: hdfs://localhost:55054
[junit] 09/08/06 17:49:55 INFO executionengine.HExecutionEngine: Connecting
to map-reduce job tracker at: localhost:56252
[junit] 09/08/06 17:49:55 INFO mapReduceLayer.MultiQueryOptimizer: MR plan
size before optimization: 1
[junit] 09/08/06 17:49:55 INFO mapReduceLayer.MultiQueryOptimizer: MR plan
size after optimization: 1
[junit] 09/08/06 17:49:56 INFO dfs.StateChange: BLOCK* ask 127.0.0.1:33494
to delete blk_-8120952403598744369_1005 blk_9096751694584793699_1006
blk_6087170260588245956_1004
[junit] 09/08/06 17:49:56 INFO dfs.StateChange: BLOCK* ask 127.0.0.1:60802
to delete blk_-8120952403598744369_1005 blk_9096751694584793699_1006
[junit] 09/08/06 17:49:57 INFO mapReduceLayer.JobControlCompiler: Setting
up single store job
[junit] 09/08/06 17:49:57 WARN mapred.JobClient: Use GenericOptionsParser
for parsing the arguments. Applications should implement Tool for the same.
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.allocateBlock:
/tmp/hadoop-hudson/mapred/system/job_200908061749_0002/job.jar.
blk_8097980703732539356_1012
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Receiving block
blk_8097980703732539356_1012 src: /127.0.0.1:56795 dest: /127.0.0.1:60802
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Receiving block
blk_8097980703732539356_1012 src: /127.0.0.1:50282 dest: /127.0.0.1:43578
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Receiving block
blk_8097980703732539356_1012 src: /127.0.0.1:59632 dest: /127.0.0.1:33326
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Received block
blk_8097980703732539356_1012 of size 2632771 from /127.0.0.1
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: PacketResponder 0 for block
blk_8097980703732539356_1012 terminating
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33326 is added to
blk_8097980703732539356_1012 size 2632771
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Received block
blk_8097980703732539356_1012 of size 2632771 from /127.0.0.1
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: PacketResponder 1 for block
blk_8097980703732539356_1012 terminating
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:43578 is added to
blk_8097980703732539356_1012 size 2632771
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Received block
blk_8097980703732539356_1012 of size 2632771 from /127.0.0.1
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: PacketResponder 2 for block
blk_8097980703732539356_1012 terminating
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:60802 is added to
blk_8097980703732539356_1012 size 2632771
[junit] 09/08/06 17:49:57 INFO fs.FSNamesystem: Increasing replication for
file /tmp/hadoop-hudson/mapred/system/job_200908061749_0002/job.jar. New
replication is 2
[junit] 09/08/06 17:49:57 INFO fs.FSNamesystem: Reducing replication for
file /tmp/hadoop-hudson/mapred/system/job_200908061749_0002/job.jar. New
replication is 2
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.allocateBlock:
/tmp/hadoop-hudson/mapred/system/job_200908061749_0002/job.split.
blk_2504540678845942825_1013
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Receiving block
blk_2504540678845942825_1013 src: /127.0.0.1:50284 dest: /127.0.0.1:43578
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Receiving block
blk_2504540678845942825_1013 src: /127.0.0.1:56799 dest: /127.0.0.1:60802
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Receiving block
blk_2504540678845942825_1013 src: /127.0.0.1:59635 dest: /127.0.0.1:33326
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Received block
blk_2504540678845942825_1013 of size 1837 from /127.0.0.1
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33326 is added to
blk_2504540678845942825_1013 size 1837
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: PacketResponder 0 for block
blk_2504540678845942825_1013 terminating
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Received block
blk_2504540678845942825_1013 of size 1837 from /127.0.0.1
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: PacketResponder 1 for block
blk_2504540678845942825_1013 terminating
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:60802 is added to
blk_2504540678845942825_1013 size 1837
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Received block
blk_2504540678845942825_1013 of size 1837 from /127.0.0.1
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:43578 is added to
blk_2504540678845942825_1013 size 1837
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: PacketResponder 2 for block
blk_2504540678845942825_1013 terminating
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.allocateBlock:
/tmp/hadoop-hudson/mapred/system/job_200908061749_0002/job.xml.
blk_-1117414003112049208_1014
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Receiving block
blk_-1117414003112049208_1014 src: /127.0.0.1:51085 dest: /127.0.0.1:33494
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Receiving block
blk_-1117414003112049208_1014 src: /127.0.0.1:56802 dest: /127.0.0.1:60802
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Receiving block
blk_-1117414003112049208_1014 src: /127.0.0.1:50289 dest: /127.0.0.1:43578
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Received block
blk_-1117414003112049208_1014 of size 41546 from /127.0.0.1
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: PacketResponder 0 for block
blk_-1117414003112049208_1014 terminating
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:43578 is added to
blk_-1117414003112049208_1014 size 41546
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Received block
blk_-1117414003112049208_1014 of size 41546 from /127.0.0.1
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: PacketResponder 1 for block
blk_-1117414003112049208_1014 terminating
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:60802 is added to
blk_-1117414003112049208_1014 size 41546
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Received block
blk_-1117414003112049208_1014 of size 41546 from /127.0.0.1
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33494 is added to
blk_-1117414003112049208_1014 size 41546
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: PacketResponder 2 for block
blk_-1117414003112049208_1014 terminating
[junit] 09/08/06 17:49:57 INFO dfs.DataNode:
DatanodeRegistration(127.0.0.1:43578,
storageID=DS-766824271-67.195.138.8-43578-1249580949547, infoPort=60131,
ipcPort=44257) Served block blk_-1117414003112049208_1014 to /127.0.0.1
[junit] 09/08/06 17:49:57 INFO dfs.DataNode:
DatanodeRegistration(127.0.0.1:60802,
storageID=DS-2095923018-67.195.138.8-60802-1249580939100, infoPort=40198,
ipcPort=33413) Served block blk_8097980703732539356_1012 to /127.0.0.1
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.allocateBlock:
/tmp/temp-168142045/tmp-673669212/_logs/history/localhost_1249580955802_job_200908061749_0002_conf.xml.
blk_5080812042334684739_1016
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Receiving block
blk_5080812042334684739_1016 src: /127.0.0.1:51090 dest: /127.0.0.1:33494
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Receiving block
blk_5080812042334684739_1016 src: /127.0.0.1:59642 dest: /127.0.0.1:33326
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Receiving block
blk_5080812042334684739_1016 src: /127.0.0.1:50294 dest: /127.0.0.1:43578
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Received block
blk_5080812042334684739_1016 of size 41522 from /127.0.0.1
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: PacketResponder 0 for block
blk_5080812042334684739_1016 terminating
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:43578 is added to
blk_5080812042334684739_1016 size 41522
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Received block
blk_5080812042334684739_1016 of size 41522 from /127.0.0.1
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: PacketResponder 1 for block
blk_5080812042334684739_1016 terminating
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33326 is added to
blk_5080812042334684739_1016 size 41522
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: Received block
blk_5080812042334684739_1016 of size 41522 from /127.0.0.1
[junit] 09/08/06 17:49:57 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33494 is added to
blk_5080812042334684739_1016 size 41522
[junit] 09/08/06 17:49:57 INFO dfs.DataNode: PacketResponder 2 for block
blk_5080812042334684739_1016 terminating
[junit] 09/08/06 17:49:57 INFO mapReduceLayer.MapReduceLauncher: 0% complete
[junit] 09/08/06 17:49:57 INFO mapred.JobInProgress: Split info for
job:job_200908061749_0002
[junit] 09/08/06 17:49:57 INFO dfs.DataNode:
DatanodeRegistration(127.0.0.1:60802,
storageID=DS-2095923018-67.195.138.8-60802-1249580939100, infoPort=40198,
ipcPort=33413) Served block blk_2504540678845942825_1013 to /127.0.0.1
[junit] 09/08/06 17:49:57 INFO mapred.JobInProgress:
tip:task_200908061749_0002_m_000000 has split on
node:/default-rack/minerva.apache.org
[junit] 09/08/06 17:49:57 INFO mapred.JobInProgress:
tip:task_200908061749_0002_m_000001 has split on
node:/default-rack/minerva.apache.org
[junit] 09/08/06 17:49:58 INFO mapred.JobInProgress: Choosing rack-local
task task_200908061749_0002_m_000000
[junit] 09/08/06 17:49:58 INFO mapred.JobTracker: Adding task
'attempt_200908061749_0002_m_000000_0' to tip task_200908061749_0002_m_000000,
for tracker 'tracker_host3.foo.com:localhost/127.0.0.1:50828'
[junit] 09/08/06 17:49:58 INFO mapred.JobTracker: Removed completed task
'attempt_200908061749_0001_r_000000_0' from
'tracker_host3.foo.com:localhost/127.0.0.1:50828'
[junit] 09/08/06 17:49:58 INFO mapred.JobInProgress: Choosing rack-local
task task_200908061749_0002_m_000001
[junit] 09/08/06 17:49:58 INFO mapred.TaskTracker: LaunchTaskAction:
attempt_200908061749_0002_m_000000_0
[junit] 09/08/06 17:49:58 INFO mapred.JobTracker: Adding task
'attempt_200908061749_0002_m_000001_0' to tip task_200908061749_0002_m_000001,
for tracker 'tracker_host0.foo.com:localhost/127.0.0.1:37702'
[junit] 09/08/06 17:49:58 INFO mapred.TaskTracker: LaunchTaskAction:
attempt_200908061749_0002_m_000001_0
[junit] 09/08/06 17:49:58 INFO dfs.DataNode:
DatanodeRegistration(127.0.0.1:33494,
storageID=DS-1393126610-67.195.138.8-33494-1249580954756, infoPort=42502,
ipcPort=39179) Served block blk_-1117414003112049208_1014 to /127.0.0.1
[junit] 09/08/06 17:49:58 INFO dfs.DataNode:
DatanodeRegistration(127.0.0.1:43578,
storageID=DS-766824271-67.195.138.8-43578-1249580949547, infoPort=60131,
ipcPort=44257) Served block blk_-1117414003112049208_1014 to /127.0.0.1
[junit] 09/08/06 17:49:58 INFO dfs.DataNode:
DatanodeRegistration(127.0.0.1:60802,
storageID=DS-2095923018-67.195.138.8-60802-1249580939100, infoPort=40198,
ipcPort=33413) Served block blk_8097980703732539356_1012 to /127.0.0.1
[junit] 09/08/06 17:49:58 INFO dfs.DataNode:
DatanodeRegistration(127.0.0.1:43578,
storageID=DS-766824271-67.195.138.8-43578-1249580949547, infoPort=60131,
ipcPort=44257) Served block blk_8097980703732539356_1012 to /127.0.0.1
[junit] 09/08/06 17:49:58 INFO mapred.TaskTracker: Received 'KillJobAction'
for job: job_200908061749_0001
[junit] 09/08/06 17:49:58 INFO mapred.TaskRunner:
attempt_200908061749_0001_r_000000_0 done; removing files.
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Deleting block
blk_-8120952403598744369_1005 file
dfs/data/data1/current/blk_-8120952403598744369
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Deleting block
blk_9096751694584793699_1006 file dfs/data/data2/current/blk_9096751694584793699
[junit] 09/08/06 17:49:59 INFO dfs.DataNode:
DatanodeRegistration(127.0.0.1:33494,
storageID=DS-1393126610-67.195.138.8-33494-1249580954756, infoPort=42502,
ipcPort=39179) Served block blk_-4775973519683222245_1010 to /127.0.0.1
[junit] 09/08/06 17:49:59 INFO dfs.StateChange: BLOCK*
NameSystem.allocateBlock:
/tmp/temp-168142045/tmp-673669212/_temporary/_attempt_200908061749_0002_m_000001_0/part-00001.
blk_365528146675102902_1018
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Receiving block
blk_365528146675102902_1018 src: /127.0.0.1:51105 dest: /127.0.0.1:33494
[junit] 09/08/06 17:49:59 INFO dfs.DataNode:
DatanodeRegistration(127.0.0.1:60802,
storageID=DS-2095923018-67.195.138.8-60802-1249580939100, infoPort=40198,
ipcPort=33413) Served block blk_466717348025503100_1011 to /127.0.0.1
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Receiving block
blk_365528146675102902_1018 src: /127.0.0.1:56823 dest: /127.0.0.1:60802
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Receiving block
blk_365528146675102902_1018 src: /127.0.0.1:50310 dest: /127.0.0.1:43578
[junit] 09/08/06 17:49:59 INFO dfs.StateChange: BLOCK*
NameSystem.allocateBlock:
/tmp/temp-168142045/tmp-673669212/_temporary/_attempt_200908061749_0002_m_000000_0/part-00000.
blk_7874365544154477584_1018
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Receiving block
blk_7874365544154477584_1018 src: /127.0.0.1:56825 dest: /127.0.0.1:60802
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Receiving block
blk_7874365544154477584_1018 src: /127.0.0.1:59661 dest: /127.0.0.1:33326
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Received block
blk_365528146675102902_1018 of size 39 from /127.0.0.1
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: PacketResponder 0 for block
blk_365528146675102902_1018 terminating
[junit] 09/08/06 17:49:59 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:43578 is added to
blk_365528146675102902_1018 size 39
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Received block
blk_365528146675102902_1018 of size 39 from /127.0.0.1
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: PacketResponder 1 for block
blk_365528146675102902_1018 terminating
[junit] 09/08/06 17:49:59 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:60802 is added to
blk_365528146675102902_1018 size 39
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Received block
blk_365528146675102902_1018 of size 39 from /127.0.0.1
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: PacketResponder 2 for block
blk_365528146675102902_1018 terminating
[junit] 09/08/06 17:49:59 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33494 is added to
blk_365528146675102902_1018 size 39
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Receiving block
blk_7874365544154477584_1018 src: /127.0.0.1:51111 dest: /127.0.0.1:33494
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Received block
blk_7874365544154477584_1018 of size 39 from /127.0.0.1
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: PacketResponder 0 for block
blk_7874365544154477584_1018 terminating
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Received block
blk_7874365544154477584_1018 of size 39 from /127.0.0.1
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: PacketResponder 1 for block
blk_7874365544154477584_1018 terminating
[junit] 09/08/06 17:49:59 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33494 is added to
blk_7874365544154477584_1018 size 39
[junit] 09/08/06 17:49:59 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33326 is added to
blk_7874365544154477584_1018 size 39
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Received block
blk_7874365544154477584_1018 of size 39 from /127.0.0.1
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: PacketResponder 2 for block
blk_7874365544154477584_1018 terminating
[junit] 09/08/06 17:49:59 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:60802 is added to
blk_7874365544154477584_1018 size 39
[junit] 09/08/06 17:49:59 INFO mapred.TaskTracker:
attempt_200908061749_0002_m_000001_0 1.0%
[junit] 09/08/06 17:49:59 INFO mapred.TaskTracker: Task
attempt_200908061749_0002_m_000001_0 is done.
[junit] 09/08/06 17:49:59 INFO mapred.TaskTracker:
attempt_200908061749_0002_m_000000_0 1.0%
[junit] 09/08/06 17:49:59 INFO mapred.TaskTracker: Task
attempt_200908061749_0002_m_000000_0 is done.
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Deleting block
blk_-8120952403598744369_1005 file
dfs/data/data8/current/blk_-8120952403598744369
[junit] 09/08/06 17:49:59 WARN dfs.DataNode: Unexpected error trying to
delete block blk_6087170260588245956_1004. BlockInfo not found in volumeMap.
[junit] 09/08/06 17:49:59 INFO dfs.DataNode: Deleting block
blk_9096751694584793699_1006 file dfs/data/data7/current/blk_9096751694584793699
[junit] 09/08/06 17:49:59 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/06 17:49:59 INFO dfs.StateChange: BLOCK* ask 127.0.0.1:33326
to delete blk_-8120952403598744369_1005 blk_6087170260588245956_1004
[junit] 09/08/06 17:49:59 INFO dfs.StateChange: BLOCK* ask 127.0.0.1:43578
to delete blk_8097980703732539356_1012 blk_9096751694584793699_1006
blk_6087170260588245956_1004
[junit] 09/08/06 17:50:00 INFO mapred.TaskRunner: Saved output of task
'attempt_200908061749_0002_m_000000_0' to
hdfs://localhost:55054/tmp/temp-168142045/tmp-673669212
[junit] 09/08/06 17:50:00 INFO mapred.JobInProgress: Task
'attempt_200908061749_0002_m_000000_0' has completed
task_200908061749_0002_m_000000 successfully.
[junit] 09/08/06 17:50:00 INFO mapred.TaskRunner: Saved output of task
'attempt_200908061749_0002_m_000001_0' to
hdfs://localhost:55054/tmp/temp-168142045/tmp-673669212
[junit] 09/08/06 17:50:00 INFO mapred.JobInProgress: Task
'attempt_200908061749_0002_m_000001_0' has completed
task_200908061749_0002_m_000001 successfully.
[junit] 09/08/06 17:50:00 INFO dfs.StateChange: BLOCK* NameSystem.delete:
blk_8097980703732539356 is added to invalidSet of 127.0.0.1:33326
[junit] 09/08/06 17:50:00 INFO dfs.StateChange: BLOCK* NameSystem.delete:
blk_8097980703732539356 is added to invalidSet of 127.0.0.1:43578
[junit] 09/08/06 17:50:00 INFO dfs.StateChange: BLOCK* NameSystem.delete:
blk_8097980703732539356 is added to invalidSet of 127.0.0.1:60802
[junit] 09/08/06 17:50:00 INFO dfs.StateChange: BLOCK* NameSystem.delete:
blk_2504540678845942825 is added to invalidSet of 127.0.0.1:33326
[junit] 09/08/06 17:50:00 INFO dfs.StateChange: BLOCK* NameSystem.delete:
blk_2504540678845942825 is added to invalidSet of 127.0.0.1:60802
[junit] 09/08/06 17:50:00 INFO dfs.StateChange: BLOCK* NameSystem.delete:
blk_2504540678845942825 is added to invalidSet of 127.0.0.1:43578
[junit] 09/08/06 17:50:00 INFO dfs.StateChange: BLOCK* NameSystem.delete:
blk_-1117414003112049208 is added to invalidSet of 127.0.0.1:43578
[junit] 09/08/06 17:50:00 INFO dfs.StateChange: BLOCK* NameSystem.delete:
blk_-1117414003112049208 is added to invalidSet of 127.0.0.1:60802
[junit] 09/08/06 17:50:00 INFO dfs.StateChange: BLOCK* NameSystem.delete:
blk_-1117414003112049208 is added to invalidSet of 127.0.0.1:33494
[junit] 09/08/06 17:50:00 INFO mapred.JobInProgress: Job
job_200908061749_0002 has completed successfully.
[junit] 09/08/06 17:50:00 INFO dfs.StateChange: BLOCK*
NameSystem.allocateBlock:
/tmp/temp-168142045/tmp-673669212/_logs/history/localhost_1249580955802_job_200908061749_0002_hudson_Job8425825850302130032.jar.
blk_-6436833846146933403_1018
[junit] 09/08/06 17:50:00 INFO dfs.DataNode: Receiving block
blk_-6436833846146933403_1018 src: /127.0.0.1:50314 dest: /127.0.0.1:43578
[junit] 09/08/06 17:50:00 INFO dfs.DataNode: Receiving block
blk_-6436833846146933403_1018 src: /127.0.0.1:51113 dest: /127.0.0.1:33494
[junit] 09/08/06 17:50:00 INFO dfs.DataNode: Receiving block
blk_-6436833846146933403_1018 src: /127.0.0.1:59665 dest: /127.0.0.1:33326
[junit] 09/08/06 17:50:00 INFO dfs.DataNode: Received block
blk_-6436833846146933403_1018 of size 2430 from /127.0.0.1
[junit] 09/08/06 17:50:00 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33326 is added to
blk_-6436833846146933403_1018 size 2430
[junit] 09/08/06 17:50:00 INFO dfs.DataNode: PacketResponder 0 for block
blk_-6436833846146933403_1018 terminating
[junit] 09/08/06 17:50:00 INFO dfs.DataNode: Received block
blk_-6436833846146933403_1018 of size 2430 from /127.0.0.1
[junit] 09/08/06 17:50:00 INFO dfs.DataNode: PacketResponder 1 for block
blk_-6436833846146933403_1018 terminating
[junit] 09/08/06 17:50:00 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33494 is added to
blk_-6436833846146933403_1018 size 2430
[junit] 09/08/06 17:50:00 INFO dfs.DataNode: Received block
blk_-6436833846146933403_1018 of size 2430 from /127.0.0.1
[junit] 09/08/06 17:50:00 INFO dfs.StateChange: BLOCK*
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:43578 is added to
blk_-6436833846146933403_1018 size 2430
[junit] 09/08/06 17:50:00 INFO dfs.DataNode: PacketResponder 2 for block
blk_-6436833846146933403_1018 terminating
[junit] 09/08/06 17:50:00 INFO mapred.JobTracker: Removed completed task
'attempt_200908061749_0002_m_000001_0' from
'tracker_host0.foo.com:localhost/127.0.0.1:37702'
[junit] 09/08/06 17:50:00 INFO mapred.TaskTracker: Received 'KillJobAction'
for job: job_200908061749_0002
[junit] 09/08/06 17:50:00 INFO mapred.TaskRunner:
attempt_200908061749_0002_m_000001_0 done; removing files.
[junit] 09/08/06 17:50:00 INFO mapred.JobTracker: Removed completed task
'attempt_200908061749_0002_m_000000_0' from
'tracker_host3.foo.com:localhost/127.0.0.1:50828'
[junit] 09/08/06 17:50:00 INFO mapred.TaskTracker: Received 'KillJobAction'
for job: job_200908061749_0002
[junit] 09/08/06 17:50:00 INFO mapred.TaskRunner:
attempt_200908061749_0002_m_000000_0 done; removing files.
[junit] 09/08/06 17:50:00 INFO dfs.DataNode: Deleting block
blk_6087170260588245956_1004 file dfs/data/data6/current/blk_6087170260588245956
[junit] 09/08/06 17:50:00 INFO dfs.DataNode: Deleting block
blk_8097980703732539356_1012 file dfs/data/data6/current/blk_8097980703732539356
[junit] 09/08/06 17:50:00 INFO dfs.DataNode: Deleting block
blk_9096751694584793699_1006 file dfs/data/data5/current/blk_9096751694584793699
[junit] 09/08/06 17:50:01 INFO dfs.DataNode: Deleting block
blk_-8120952403598744369_1005 file
dfs/data/data4/current/blk_-8120952403598744369
[junit] 09/08/06 17:50:01 INFO dfs.DataNode: Deleting block
blk_6087170260588245956_1004 file dfs/data/data3/current/blk_6087170260588245956
[junit] 09/08/06 17:50:02 INFO mapReduceLayer.MapReduceLauncher: 100%
complete
[junit] 09/08/06 17:50:02 INFO mapReduceLayer.MapReduceLauncher:
Successfully stored result in:
"hdfs://localhost:55054/tmp/temp-168142045/tmp-673669212"
[junit] 09/08/06 17:50:02 INFO mapReduceLayer.MapReduceLauncher: Records
written : 2
[junit] 09/08/06 17:50:02 INFO mapReduceLayer.MapReduceLauncher: Bytes
written : 78
[junit] 09/08/06 17:50:02 INFO mapReduceLayer.MapReduceLauncher: Success!
[junit] 09/08/06 17:50:02 INFO dfs.StateChange: BLOCK* ask 127.0.0.1:33494
to delete blk_-1117414003112049208_1014
[junit] 09/08/06 17:50:02 INFO dfs.StateChange: BLOCK* ask 127.0.0.1:60802
to delete blk_8097980703732539356_1012 blk_2504540678845942825_1013
blk_-1117414003112049208_1014
[junit] 09/08/06 17:50:02 INFO dfs.DataNode:
DatanodeRegistration(127.0.0.1:33326,
storageID=DS-460580835-67.195.138.8-33326-1249580944357, infoPort=44833,
ipcPort=46823) Served block blk_7874365544154477584_1018 to /127.0.0.1
[junit] 09/08/06 17:50:02 INFO dfs.DataNode:
DatanodeRegistration(127.0.0.1:60802,
storageID=DS-2095923018-67.195.138.8-60802-1249580939100, infoPort=40198,
ipcPort=33413) Served block blk_365528146675102902_1018 to /127.0.0.1
[junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 25.438 sec
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 0 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...
