See <http://hudson.zones.apache.org/hudson/job/Pig-trunk/657/changes>

Changes:

[daijy] PIG-1146: Inconsistent column pruning in LOUnion

[daijy] PIG-761: ERROR 2086 on simple JOIN

[olga] committed missing file

[olga] PIG-1102: Collect number of spills per job (sriranjan via olgan)

------------------------------------------
[...truncated 237588 lines...]
    [junit] 09/12/25 14:33:05 INFO datanode.DataNode: Receiving block 
blk_5815478782712360138_1015 src: /127.0.0.1:40940 dest: /127.0.0.1:46725
    [junit] 09/12/25 14:33:05 INFO DataNode.clienttrace: src: /127.0.0.1:40940, 
dest: /127.0.0.1:46725, bytes: 48832, op: HDFS_WRITE, cliID: 
DFSClient_-693295477, srvID: DS-775249731-127.0.1.1-46725-1261751552442, 
blockid: blk_5815478782712360138_1015
    [junit] 09/12/25 14:33:05 INFO datanode.DataNode: PacketResponder 0 for 
block blk_5815478782712360138_1015 terminating
    [junit] 09/12/25 14:33:05 INFO DataNode.clienttrace: src: /127.0.0.1:58212, 
dest: /127.0.0.1:39127, bytes: 48832, op: HDFS_WRITE, cliID: 
DFSClient_-693295477, srvID: DS-1783368968-127.0.1.1-39127-1261751551939, 
blockid: blk_5815478782712360138_1015
    [junit] 09/12/25 14:33:05 INFO datanode.DataNode: PacketResponder 1 for 
block blk_5815478782712360138_1015 terminating
    [junit] 09/12/25 14:33:05 INFO DataNode.clienttrace: src: /127.0.0.1:56182, 
dest: /127.0.0.1:50836, bytes: 48832, op: HDFS_WRITE, cliID: 
DFSClient_-693295477, srvID: DS-176134573-127.0.1.1-50836-1261751552905, 
blockid: blk_5815478782712360138_1015
    [junit] 09/12/25 14:33:05 INFO hdfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:46725 is added to 
blk_5815478782712360138_1015 size 48832
    [junit] 09/12/25 14:33:05 INFO datanode.DataNode: PacketResponder 2 for 
block blk_5815478782712360138_1015 terminating
    [junit] 09/12/25 14:33:05 INFO hdfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:50836 is added to 
blk_5815478782712360138_1015 size 48832
    [junit] 09/12/25 14:33:05 INFO hdfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:39127 is added to 
blk_5815478782712360138_1015 size 48832
    [junit] 09/12/25 14:33:05 INFO hdfs.StateChange: DIR* 
NameSystem.completeFile: file 
/tmp/hadoop-hudson/mapred/system/job_20091225143233421_0002/job.xml is closed 
by DFSClient_-693295477
    [junit] 09/12/25 14:33:05 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=open        
src=/tmp/hadoop-hudson/mapred/system/job_20091225143233421_0002/job.xml 
dst=null        perm=null
    [junit] 09/12/25 14:33:05 INFO DataNode.clienttrace: src: /127.0.0.1:46725, 
dest: /127.0.0.1:40941, bytes: 49216, op: HDFS_READ, cliID: 
DFSClient_-693295477, srvID: DS-775249731-127.0.1.1-46725-1261751552442, 
blockid: blk_5815478782712360138_1015
    [junit] 09/12/25 14:33:05 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=open        
src=/tmp/hadoop-hudson/mapred/system/job_20091225143233421_0002/job.jar 
dst=null        perm=null
    [junit] 09/12/25 14:33:05 INFO DataNode.clienttrace: src: /127.0.0.1:46725, 
dest: /127.0.0.1:40942, bytes: 2710429, op: HDFS_READ, cliID: 
DFSClient_-693295477, srvID: DS-775249731-127.0.1.1-46725-1261751552442, 
blockid: blk_6589178399666852537_1013
    [junit] 09/12/25 14:33:05 INFO mapred.JobTracker: Initializing 
job_20091225143233421_0002
    [junit] 09/12/25 14:33:05 INFO mapred.JobInProgress: Initializing 
job_20091225143233421_0002
    [junit] 09/12/25 14:33:05 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=create      
src=/tmp/temp-1071212225/tmp-1682484629/_logs/history/localhost_1261751553444_job_20091225143233421_0002_hudson_Job5209043222621598367.jar
      dst=null        perm=hudson:supergroup:rw-r--r--
    [junit] 09/12/25 14:33:05 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=create      
src=/tmp/temp-1071212225/tmp-1682484629/_logs/history/localhost_1261751553444_job_20091225143233421_0002_conf.xml
       dst=null        perm=hudson:supergroup:rw-r--r--
    [junit] 09/12/25 14:33:05 INFO hdfs.StateChange: BLOCK* 
NameSystem.allocateBlock: 
/tmp/temp-1071212225/tmp-1682484629/_logs/history/localhost_1261751553444_job_20091225143233421_0002_conf.xml.
 blk_-4464720979699986993_1017
    [junit] 09/12/25 14:33:05 INFO datanode.DataNode: Receiving block 
blk_-4464720979699986993_1017 src: /127.0.0.1:40943 dest: /127.0.0.1:46725
    [junit] 09/12/25 14:33:05 INFO datanode.DataNode: Receiving block 
blk_-4464720979699986993_1017 src: /127.0.0.1:56188 dest: /127.0.0.1:50836
    [junit] 09/12/25 14:33:05 INFO datanode.DataNode: Receiving block 
blk_-4464720979699986993_1017 src: /127.0.0.1:55755 dest: /127.0.0.1:57042
    [junit] 09/12/25 14:33:05 INFO DataNode.clienttrace: src: /127.0.0.1:55755, 
dest: /127.0.0.1:57042, bytes: 48862, op: HDFS_WRITE, cliID: 
DFSClient_-693295477, srvID: DS-1060151078-127.0.1.1-57042-1261751553351, 
blockid: blk_-4464720979699986993_1017
    [junit] 09/12/25 14:33:05 INFO datanode.DataNode: PacketResponder 0 for 
block blk_-4464720979699986993_1017 terminating
    [junit] 09/12/25 14:33:05 INFO hdfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57042 is added to 
blk_-4464720979699986993_1017 size 48862
    [junit] 09/12/25 14:33:05 INFO DataNode.clienttrace: src: /127.0.0.1:56188, 
dest: /127.0.0.1:50836, bytes: 48862, op: HDFS_WRITE, cliID: 
DFSClient_-693295477, srvID: DS-176134573-127.0.1.1-50836-1261751552905, 
blockid: blk_-4464720979699986993_1017
    [junit] 09/12/25 14:33:05 INFO hdfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:50836 is added to 
blk_-4464720979699986993_1017 size 48862
    [junit] 09/12/25 14:33:05 INFO datanode.DataNode: PacketResponder 1 for 
block blk_-4464720979699986993_1017 terminating
    [junit] 09/12/25 14:33:05 INFO DataNode.clienttrace: src: /127.0.0.1:40943, 
dest: /127.0.0.1:46725, bytes: 48862, op: HDFS_WRITE, cliID: 
DFSClient_-693295477, srvID: DS-775249731-127.0.1.1-46725-1261751552442, 
blockid: blk_-4464720979699986993_1017
    [junit] 09/12/25 14:33:05 INFO hdfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:46725 is added to 
blk_-4464720979699986993_1017 size 48862
    [junit] 09/12/25 14:33:05 INFO datanode.DataNode: PacketResponder 2 for 
block blk_-4464720979699986993_1017 terminating
    [junit] 09/12/25 14:33:05 INFO hdfs.StateChange: DIR* 
NameSystem.completeFile: file 
/tmp/temp-1071212225/tmp-1682484629/_logs/history/localhost_1261751553444_job_20091225143233421_0002_conf.xml
 is closed by DFSClient_-693295477
    [junit] 09/12/25 14:33:05 INFO datanode.DataNode: Deleting block 
blk_-7163446602810167708_1006 file 
build/test/data/dfs/data/data4/current/blk_-7163446602810167708
    [junit] 09/12/25 14:33:05 INFO datanode.DataNode: Deleting block 
blk_6000923207330783768_1007 file 
build/test/data/dfs/data/data3/current/blk_6000923207330783768
    [junit] 09/12/25 14:33:05 INFO mapReduceLayer.MapReduceLauncher: Submitting 
job: job_20091225143233421_0002 to execution engine.
    [junit] 09/12/25 14:33:05 INFO mapReduceLayer.MapReduceLauncher: More 
information at: 
http://localhost:49734/jobdetails.jsp?jobid=job_20091225143233421_0002
    [junit] 09/12/25 14:33:05 INFO mapReduceLayer.MapReduceLauncher: To kill 
this job, use: kill job_20091225143233421_0002
    [junit] 09/12/25 14:33:05 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=open        
src=/tmp/hadoop-hudson/mapred/system/job_20091225143233421_0002/job.split       
dst=null        perm=null
    [junit] 09/12/25 14:33:05 INFO DataNode.clienttrace: src: /127.0.0.1:57042, 
dest: /127.0.0.1:55756, bytes: 1605, op: HDFS_READ, cliID: 
DFSClient_-693295477, srvID: DS-1060151078-127.0.1.1-57042-1261751553351, 
blockid: blk_120984146150836362_1014
    [junit] 09/12/25 14:33:05 INFO mapred.JobInProgress: Input size for job 
job_20091225143233421_0002 = 12. Number of splits = 2
    [junit] 09/12/25 14:33:05 INFO mapred.JobInProgress: 
tip:task_20091225143233421_0002_m_000000 has split on 
node:/default-rack/h7.grid.sp2.yahoo.net
    [junit] 09/12/25 14:33:05 INFO mapred.JobInProgress: 
tip:task_20091225143233421_0002_m_000001 has split on 
node:/default-rack/h7.grid.sp2.yahoo.net
    [junit] 09/12/25 14:33:05 INFO mapred.JobTracker: Adding task 
'attempt_20091225143233421_0002_m_000003_0' to tip 
task_20091225143233421_0002_m_000003, for tracker 
'tracker_host2.foo.com:localhost/127.0.0.1:33303'
    [junit] 09/12/25 14:33:05 INFO mapred.TaskTracker: LaunchTaskAction 
(registerTask): attempt_20091225143233421_0002_m_000003_0 task's 
state:UNASSIGNED
    [junit] 09/12/25 14:33:05 INFO mapred.TaskTracker: Trying to launch : 
attempt_20091225143233421_0002_m_000003_0
    [junit] 09/12/25 14:33:05 INFO mapred.TaskTracker: In TaskLauncher, current 
free slots : 2 and trying to launch attempt_20091225143233421_0002_m_000003_0
    [junit] 09/12/25 14:33:05 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=open        
src=/tmp/hadoop-hudson/mapred/system/job_20091225143233421_0002/job.xml 
dst=null        perm=null
    [junit] 09/12/25 14:33:05 INFO DataNode.clienttrace: src: /127.0.0.1:46725, 
dest: /127.0.0.1:40947, bytes: 49216, op: HDFS_READ, cliID: 
DFSClient_-693295477, srvID: DS-775249731-127.0.1.1-46725-1261751552442, 
blockid: blk_5815478782712360138_1015
    [junit] 09/12/25 14:33:05 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=open        
src=/tmp/hadoop-hudson/mapred/system/job_20091225143233421_0002/job.jar 
dst=null        perm=null
    [junit] 09/12/25 14:33:05 INFO DataNode.clienttrace: src: /127.0.0.1:39127, 
dest: /127.0.0.1:58221, bytes: 2710429, op: HDFS_READ, cliID: 
DFSClient_-693295477, srvID: DS-1783368968-127.0.1.1-39127-1261751551939, 
blockid: blk_6589178399666852537_1013
    [junit] 09/12/25 14:33:06 INFO mapReduceLayer.MapReduceLauncher: 0% complete
    [junit] 09/12/25 14:33:06 INFO mapred.JvmManager: In JvmRunner constructed 
JVM ID: jvm_20091225143233421_0002_m_1398746713
    [junit] 09/12/25 14:33:06 INFO mapred.JvmManager: JVM Runner 
jvm_20091225143233421_0002_m_1398746713 spawned.
    [junit] 09/12/25 14:33:06 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:57042 
to delete  blk_6589178399666852537_1013
    [junit] 09/12/25 14:33:06 INFO mapred.TaskTracker: JVM with ID: 
jvm_20091225143233421_0002_m_1398746713 given task: 
attempt_20091225143233421_0002_m_000003_0
    [junit] 09/12/25 14:33:06 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=mkdirs      
src=/tmp/temp-1071212225/tmp-1682484629/_temporary      dst=null        
perm=hudson:supergroup:rwxr-xr-x
    [junit] 09/12/25 14:33:06 INFO mapred.TaskTracker: 
attempt_20091225143233421_0002_m_000003_0 0.0% setup
    [junit] 09/12/25 14:33:06 INFO mapred.TaskTracker: Task 
attempt_20091225143233421_0002_m_000003_0 is done.
    [junit] 09/12/25 14:33:06 INFO mapred.TaskTracker: reported output size for 
attempt_20091225143233421_0002_m_000003_0  was 0
    [junit] 09/12/25 14:33:06 INFO mapred.TaskTracker: addFreeSlot : current 
free slots : 2
    [junit] 09/12/25 14:33:07 INFO mapred.JvmManager: JVM : 
jvm_20091225143233421_0002_m_1398746713 exited. Number of tasks it ran: 1
    [junit] 09/12/25 14:33:08 INFO mapred.TaskTracker: 
org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find 
taskTracker/jobcache/job_20091225143233421_0002/attempt_20091225143233421_0002_m_000003_0/output/file.out
 in any of the configured local directories
    [junit] 09/12/25 14:33:08 INFO mapred.JobInProgress: Task 
'attempt_20091225143233421_0002_m_000003_0' has completed 
task_20091225143233421_0002_m_000003 successfully.
    [junit] 09/12/25 14:33:08 INFO mapred.JobTracker: Adding task 
'attempt_20091225143233421_0002_m_000000_0' to tip 
task_20091225143233421_0002_m_000000, for tracker 
'tracker_host2.foo.com:localhost/127.0.0.1:33303'
    [junit] 09/12/25 14:33:08 INFO mapred.JobInProgress: Choosing rack-local 
task task_20091225143233421_0002_m_000000
    [junit] 09/12/25 14:33:08 INFO mapred.TaskTracker: LaunchTaskAction 
(registerTask): attempt_20091225143233421_0002_m_000000_0 task's 
state:UNASSIGNED
    [junit] 09/12/25 14:33:08 INFO mapred.TaskTracker: Trying to launch : 
attempt_20091225143233421_0002_m_000000_0
    [junit] 09/12/25 14:33:08 INFO mapred.TaskTracker: Received KillTaskAction 
for task: attempt_20091225143233421_0002_m_000003_0
    [junit] 09/12/25 14:33:08 INFO mapred.TaskTracker: In TaskLauncher, current 
free slots : 2 and trying to launch attempt_20091225143233421_0002_m_000000_0
    [junit] 09/12/25 14:33:08 INFO mapred.TaskTracker: About to purge task: 
attempt_20091225143233421_0002_m_000003_0
    [junit] 09/12/25 14:33:08 INFO mapred.TaskRunner: 
attempt_20091225143233421_0002_m_000003_0 done; removing files.
    [junit] 09/12/25 14:33:08 INFO mapred.IndexCache: Map ID 
attempt_20091225143233421_0002_m_000003_0 not found in cache
    [junit] 09/12/25 14:33:08 INFO mapred.JvmManager: In JvmRunner constructed 
JVM ID: jvm_20091225143233421_0002_m_2060868689
    [junit] 09/12/25 14:33:08 INFO mapred.JvmManager: JVM Runner 
jvm_20091225143233421_0002_m_2060868689 spawned.
    [junit] 09/12/25 14:33:09 INFO mapred.JobTracker: Adding task 
'attempt_20091225143233421_0002_m_000001_0' to tip 
task_20091225143233421_0002_m_000001, for tracker 
'tracker_host3.foo.com:localhost/127.0.0.1:44856'
    [junit] 09/12/25 14:33:09 INFO mapred.JobInProgress: Choosing rack-local 
task task_20091225143233421_0002_m_000001
    [junit] 09/12/25 14:33:09 INFO mapred.TaskTracker: LaunchTaskAction 
(registerTask): attempt_20091225143233421_0002_m_000001_0 task's 
state:UNASSIGNED
    [junit] 09/12/25 14:33:09 INFO mapred.TaskTracker: Trying to launch : 
attempt_20091225143233421_0002_m_000001_0
    [junit] 09/12/25 14:33:09 INFO mapred.TaskTracker: In TaskLauncher, current 
free slots : 2 and trying to launch attempt_20091225143233421_0002_m_000001_0
    [junit] 09/12/25 14:33:09 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=open        
src=/tmp/hadoop-hudson/mapred/system/job_20091225143233421_0002/job.xml 
dst=null        perm=null
    [junit] 09/12/25 14:33:09 INFO DataNode.clienttrace: src: /127.0.0.1:50836, 
dest: /127.0.0.1:56200, bytes: 49216, op: HDFS_READ, cliID: 
DFSClient_-693295477, srvID: DS-176134573-127.0.1.1-50836-1261751552905, 
blockid: blk_5815478782712360138_1015
    [junit] 09/12/25 14:33:09 INFO mapred.TaskTracker: JVM with ID: 
jvm_20091225143233421_0002_m_2060868689 given task: 
attempt_20091225143233421_0002_m_000000_0
    [junit] 09/12/25 14:33:09 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=open        
src=/tmp/hadoop-hudson/mapred/system/job_20091225143233421_0002/job.jar 
dst=null        perm=null
    [junit] 09/12/25 14:33:09 INFO DataNode.clienttrace: src: /127.0.0.1:39127, 
dest: /127.0.0.1:58231, bytes: 2710429, op: HDFS_READ, cliID: 
DFSClient_-693295477, srvID: DS-1783368968-127.0.1.1-39127-1261751551939, 
blockid: blk_6589178399666852537_1013
    [junit] 09/12/25 14:33:09 INFO datanode.DataNode: Deleting block 
blk_6589178399666852537_1013 file 
build/test/data/dfs/data/data7/current/blk_6589178399666852537
    [junit] 09/12/25 14:33:09 INFO mapred.JvmManager: In JvmRunner constructed 
JVM ID: jvm_20091225143233421_0002_m_1646742193
    [junit] 09/12/25 14:33:09 INFO mapred.JvmManager: JVM Runner 
jvm_20091225143233421_0002_m_1646742193 spawned.
    [junit] 09/12/25 14:33:09 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=open        src=/user/hudson/input2.txt     dst=null        
perm=null
    [junit] 09/12/25 14:33:09 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=create      
src=/tmp/temp-1071212225/tmp-1682484629/_temporary/_attempt_20091225143233421_0002_m_000000_0/part-00000
        dst=null        perm=hudson:supergroup:rw-r--r--
    [junit] 09/12/25 14:33:09 INFO DataNode.clienttrace: src: /127.0.0.1:57042, 
dest: /127.0.0.1:55771, bytes: 10, op: HDFS_READ, cliID: 
DFSClient_attempt_20091225143233421_0002_m_000000_0, srvID: 
DS-1060151078-127.0.1.1-57042-1261751553351, blockid: 
blk_-3487280937736509986_1012
    [junit] 09/12/25 14:33:09 INFO hdfs.StateChange: BLOCK* 
NameSystem.allocateBlock: 
/tmp/temp-1071212225/tmp-1682484629/_temporary/_attempt_20091225143233421_0002_m_000000_0/part-00000.
 blk_-3273610814172960303_1018
    [junit] 09/12/25 14:33:09 INFO datanode.DataNode: Receiving block 
blk_-3273610814172960303_1018 src: /127.0.0.1:56206 dest: /127.0.0.1:50836
    [junit] 09/12/25 14:33:09 INFO datanode.DataNode: Receiving block 
blk_-3273610814172960303_1018 src: /127.0.0.1:58236 dest: /127.0.0.1:39127
    [junit] 09/12/25 14:33:09 INFO datanode.DataNode: Receiving block 
blk_-3273610814172960303_1018 src: /127.0.0.1:40964 dest: /127.0.0.1:46725
    [junit] 09/12/25 14:33:09 INFO DataNode.clienttrace: src: /127.0.0.1:40964, 
dest: /127.0.0.1:46725, bytes: 39, op: HDFS_WRITE, cliID: 
DFSClient_attempt_20091225143233421_0002_m_000000_0, srvID: 
DS-775249731-127.0.1.1-46725-1261751552442, blockid: 
blk_-3273610814172960303_1018
    [junit] 09/12/25 14:33:09 INFO datanode.DataNode: PacketResponder 0 for 
block blk_-3273610814172960303_1018 terminating
    [junit] 09/12/25 14:33:09 INFO DataNode.clienttrace: src: /127.0.0.1:58236, 
dest: /127.0.0.1:39127, bytes: 39, op: HDFS_WRITE, cliID: 
DFSClient_attempt_20091225143233421_0002_m_000000_0, srvID: 
DS-1783368968-127.0.1.1-39127-1261751551939, blockid: 
blk_-3273610814172960303_1018
    [junit] 09/12/25 14:33:09 INFO hdfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:46725 is added to 
blk_-3273610814172960303_1018 size 39
    [junit] 09/12/25 14:33:09 INFO datanode.DataNode: PacketResponder 1 for 
block blk_-3273610814172960303_1018 terminating
    [junit] 09/12/25 14:33:09 INFO hdfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:39127 is added to 
blk_-3273610814172960303_1018 size 39
    [junit] 09/12/25 14:33:09 INFO DataNode.clienttrace: src: /127.0.0.1:56206, 
dest: /127.0.0.1:50836, bytes: 39, op: HDFS_WRITE, cliID: 
DFSClient_attempt_20091225143233421_0002_m_000000_0, srvID: 
DS-176134573-127.0.1.1-50836-1261751552905, blockid: 
blk_-3273610814172960303_1018
    [junit] 09/12/25 14:33:09 INFO hdfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:50836 is added to 
blk_-3273610814172960303_1018 size 39
    [junit] 09/12/25 14:33:09 INFO datanode.DataNode: PacketResponder 2 for 
block blk_-3273610814172960303_1018 terminating
    [junit] 09/12/25 14:33:09 INFO hdfs.StateChange: DIR* 
NameSystem.completeFile: file 
/tmp/temp-1071212225/tmp-1682484629/_temporary/_attempt_20091225143233421_0002_m_000000_0/part-00000
 is closed by DFSClient_attempt_20091225143233421_0002_m_000000_0
    [junit] 09/12/25 14:33:10 INFO mapred.TaskTracker: JVM with ID: 
jvm_20091225143233421_0002_m_1646742193 given task: 
attempt_20091225143233421_0002_m_000001_0
    [junit] 09/12/25 14:33:10 INFO mapred.TaskTracker: Task 
attempt_20091225143233421_0002_m_000000_0 is in commit-pending, task 
state:COMMIT_PENDING
    [junit] 09/12/25 14:33:10 INFO mapred.TaskTracker: 
attempt_20091225143233421_0002_m_000000_0 0.0% 
    [junit] 09/12/25 14:33:10 INFO datanode.DataBlockScanner: Verification 
succeeded for blk_-4464720979699986993_1017
    [junit] 09/12/25 14:33:10 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=open        src=/user/hudson/input1.txt     dst=null        
perm=null
    [junit] 09/12/25 14:33:10 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=create      
src=/tmp/temp-1071212225/tmp-1682484629/_temporary/_attempt_20091225143233421_0002_m_000001_0/part-00001
        dst=null        perm=hudson:supergroup:rw-r--r--
    [junit] 09/12/25 14:33:10 INFO DataNode.clienttrace: src: /127.0.0.1:57042, 
dest: /127.0.0.1:55780, bytes: 10, op: HDFS_READ, cliID: 
DFSClient_attempt_20091225143233421_0002_m_000001_0, srvID: 
DS-1060151078-127.0.1.1-57042-1261751553351, blockid: 
blk_-2330451921785990751_1011
    [junit] 09/12/25 14:33:10 INFO hdfs.StateChange: BLOCK* 
NameSystem.allocateBlock: 
/tmp/temp-1071212225/tmp-1682484629/_temporary/_attempt_20091225143233421_0002_m_000001_0/part-00001.
 blk_-1774488489287495887_1019
    [junit] 09/12/25 14:33:10 INFO datanode.DataNode: Receiving block 
blk_-1774488489287495887_1019 src: /127.0.0.1:56215 dest: /127.0.0.1:50836
    [junit] 09/12/25 14:33:10 INFO datanode.DataNode: Receiving block 
blk_-1774488489287495887_1019 src: /127.0.0.1:40972 dest: /127.0.0.1:46725
    [junit] 09/12/25 14:33:10 INFO datanode.DataNode: Receiving block 
blk_-1774488489287495887_1019 src: /127.0.0.1:58246 dest: /127.0.0.1:39127
    [junit] 09/12/25 14:33:10 INFO DataNode.clienttrace: src: /127.0.0.1:58246, 
dest: /127.0.0.1:39127, bytes: 39, op: HDFS_WRITE, cliID: 
DFSClient_attempt_20091225143233421_0002_m_000001_0, srvID: 
DS-1783368968-127.0.1.1-39127-1261751551939, blockid: 
blk_-1774488489287495887_1019
    [junit] 09/12/25 14:33:10 INFO datanode.DataNode: PacketResponder 0 for 
block blk_-1774488489287495887_1019 terminating
    [junit] 09/12/25 14:33:10 INFO hdfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:39127 is added to 
blk_-1774488489287495887_1019 size 39
    [junit] 09/12/25 14:33:10 INFO DataNode.clienttrace: src: /127.0.0.1:40972, 
dest: /127.0.0.1:46725, bytes: 39, op: HDFS_WRITE, cliID: 
DFSClient_attempt_20091225143233421_0002_m_000001_0, srvID: 
DS-775249731-127.0.1.1-46725-1261751552442, blockid: 
blk_-1774488489287495887_1019
    [junit] 09/12/25 14:33:10 INFO hdfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:46725 is added to 
blk_-1774488489287495887_1019 size 39
    [junit] 09/12/25 14:33:10 INFO datanode.DataNode: PacketResponder 1 for 
block blk_-1774488489287495887_1019 terminating
    [junit] 09/12/25 14:33:10 INFO DataNode.clienttrace: src: /127.0.0.1:56215, 
dest: /127.0.0.1:50836, bytes: 39, op: HDFS_WRITE, cliID: 
DFSClient_attempt_20091225143233421_0002_m_000001_0, srvID: 
DS-176134573-127.0.1.1-50836-1261751552905, blockid: 
blk_-1774488489287495887_1019
    [junit] 09/12/25 14:33:10 INFO hdfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:50836 is added to 
blk_-1774488489287495887_1019 size 39
    [junit] 09/12/25 14:33:10 INFO datanode.DataNode: PacketResponder 2 for 
block blk_-1774488489287495887_1019 terminating
    [junit] 09/12/25 14:33:10 INFO hdfs.StateChange: DIR* 
NameSystem.completeFile: file 
/tmp/temp-1071212225/tmp-1682484629/_temporary/_attempt_20091225143233421_0002_m_000001_0/part-00001
 is closed by DFSClient_attempt_20091225143233421_0002_m_000001_0
    [junit] 09/12/25 14:33:10 INFO mapred.TaskTracker: Task 
attempt_20091225143233421_0002_m_000001_0 is in commit-pending, task 
state:COMMIT_PENDING
    [junit] 09/12/25 14:33:10 INFO mapred.TaskTracker: 
attempt_20091225143233421_0002_m_000001_0 0.0% 
    [junit] 09/12/25 14:33:11 INFO mapred.TaskTracker: Received commit task 
action for attempt_20091225143233421_0002_m_000000_0
    [junit] 09/12/25 14:33:12 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=listStatus  
src=/tmp/temp-1071212225/tmp-1682484629/_temporary/_attempt_20091225143233421_0002_m_000000_0
   dst=null        perm=null
    [junit] 09/12/25 14:33:12 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=mkdirs      src=/tmp/temp-1071212225/tmp-1682484629 
dst=null        perm=hudson:supergroup:rwxr-xr-x
    [junit] 09/12/25 14:33:12 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=rename      
src=/tmp/temp-1071212225/tmp-1682484629/_temporary/_attempt_20091225143233421_0002_m_000000_0/part-00000
        dst=/tmp/temp-1071212225/tmp-1682484629/part-00000      
perm=hudson:supergroup:rw-r--r--
    [junit] 09/12/25 14:33:12 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=delete      
src=/tmp/temp-1071212225/tmp-1682484629/_temporary/_attempt_20091225143233421_0002_m_000000_0
   dst=null        perm=null
    [junit] 09/12/25 14:33:12 INFO mapred.TaskTracker: 
attempt_20091225143233421_0002_m_000000_0 1.0% 
    [junit] 09/12/25 14:33:12 INFO mapred.TaskTracker: Task 
attempt_20091225143233421_0002_m_000000_0 is done.
    [junit] 09/12/25 14:33:12 INFO mapred.TaskTracker: reported output size for 
attempt_20091225143233421_0002_m_000000_0  was 0
    [junit] 09/12/25 14:33:12 INFO mapred.TaskTracker: addFreeSlot : current 
free slots : 2
    [junit] 09/12/25 14:33:12 INFO mapred.TaskTracker: Received commit task 
action for attempt_20091225143233421_0002_m_000001_0
    [junit] 09/12/25 14:33:12 INFO mapred.JvmManager: JVM : 
jvm_20091225143233421_0002_m_2060868689 exited. Number of tasks it ran: 1
    [junit] 09/12/25 14:33:12 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=listStatus  
src=/tmp/temp-1071212225/tmp-1682484629/_temporary/_attempt_20091225143233421_0002_m_000001_0
   dst=null        perm=null
    [junit] 09/12/25 14:33:12 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=mkdirs      src=/tmp/temp-1071212225/tmp-1682484629 
dst=null        perm=hudson:supergroup:rwxr-xr-x
    [junit] 09/12/25 14:33:12 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=rename      
src=/tmp/temp-1071212225/tmp-1682484629/_temporary/_attempt_20091225143233421_0002_m_000001_0/part-00001
        dst=/tmp/temp-1071212225/tmp-1682484629/part-00001      
perm=hudson:supergroup:rw-r--r--
    [junit] 09/12/25 14:33:12 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=delete      
src=/tmp/temp-1071212225/tmp-1682484629/_temporary/_attempt_20091225143233421_0002_m_000001_0
   dst=null        perm=null
    [junit] 09/12/25 14:33:12 INFO mapred.TaskTracker: 
attempt_20091225143233421_0002_m_000001_0 1.0% 
    [junit] 09/12/25 14:33:12 INFO mapred.TaskTracker: Task 
attempt_20091225143233421_0002_m_000001_0 is done.
    [junit] 09/12/25 14:33:12 INFO mapred.TaskTracker: reported output size for 
attempt_20091225143233421_0002_m_000001_0  was 0
    [junit] 09/12/25 14:33:12 INFO mapred.TaskTracker: addFreeSlot : current 
free slots : 2
    [junit] 09/12/25 14:33:12 INFO mapred.JvmManager: JVM : 
jvm_20091225143233421_0002_m_1646742193 exited. Number of tasks it ran: 1
    [junit] 09/12/25 14:33:14 INFO mapred.TaskTracker: 
org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find 
taskTracker/jobcache/job_20091225143233421_0002/attempt_20091225143233421_0002_m_000000_0/output/file.out
 in any of the configured local directories
    [junit] 09/12/25 14:33:14 INFO mapred.JobInProgress: Task 
'attempt_20091225143233421_0002_m_000000_0' has completed 
task_20091225143233421_0002_m_000000 successfully.
    [junit] 09/12/25 14:33:15 INFO mapReduceLayer.MapReduceLauncher: 25% 
complete
    [junit] 09/12/25 14:33:15 INFO mapred.TaskTracker: 
org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find 
taskTracker/jobcache/job_20091225143233421_0002/attempt_20091225143233421_0002_m_000001_0/output/file.out
 in any of the configured local directories
    [junit] 09/12/25 14:33:15 INFO mapred.JobInProgress: Task 
'attempt_20091225143233421_0002_m_000001_0' has completed 
task_20091225143233421_0002_m_000001 successfully.
    [junit] 09/12/25 14:33:15 INFO mapred.JobTracker: Adding task 
'attempt_20091225143233421_0002_m_000002_0' to tip 
task_20091225143233421_0002_m_000002, for tracker 
'tracker_host3.foo.com:localhost/127.0.0.1:44856'
    [junit] 09/12/25 14:33:15 INFO mapred.TaskTracker: LaunchTaskAction 
(registerTask): attempt_20091225143233421_0002_m_000002_0 task's 
state:UNASSIGNED
    [junit] 09/12/25 14:33:15 INFO mapred.TaskTracker: Trying to launch : 
attempt_20091225143233421_0002_m_000002_0
    [junit] 09/12/25 14:33:15 INFO mapred.TaskTracker: In TaskLauncher, current 
free slots : 2 and trying to launch attempt_20091225143233421_0002_m_000002_0
    [junit] 09/12/25 14:33:15 INFO mapred.JvmManager: In JvmRunner constructed 
JVM ID: jvm_20091225143233421_0002_m_722445583
    [junit] 09/12/25 14:33:15 INFO mapred.JvmManager: JVM Runner 
jvm_20091225143233421_0002_m_722445583 spawned.
    [junit] 09/12/25 14:33:15 INFO mapReduceLayer.MapReduceLauncher: 50% 
complete
    [junit] 09/12/25 14:33:15 INFO mapred.TaskTracker: JVM with ID: 
jvm_20091225143233421_0002_m_722445583 given task: 
attempt_20091225143233421_0002_m_000002_0
    [junit] 09/12/25 14:33:16 INFO mapred.TaskTracker: 
attempt_20091225143233421_0002_m_000002_0 0.0% 
    [junit] 09/12/25 14:33:16 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=delete      
src=/tmp/temp-1071212225/tmp-1682484629/_temporary      dst=null        
perm=null
    [junit] 09/12/25 14:33:16 INFO mapred.TaskTracker: 
attempt_20091225143233421_0002_m_000002_0 0.0% cleanup
    [junit] 09/12/25 14:33:16 INFO mapred.TaskTracker: Task 
attempt_20091225143233421_0002_m_000002_0 is done.
    [junit] 09/12/25 14:33:16 INFO mapred.TaskTracker: reported output size for 
attempt_20091225143233421_0002_m_000002_0  was 0
    [junit] 09/12/25 14:33:16 INFO mapred.TaskTracker: addFreeSlot : current 
free slots : 2
    [junit] 09/12/25 14:33:16 INFO mapred.JvmManager: JVM : 
jvm_20091225143233421_0002_m_722445583 exited. Number of tasks it ran: 1
    [junit] 09/12/25 14:33:18 INFO mapred.TaskTracker: 
org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find 
taskTracker/jobcache/job_20091225143233421_0002/attempt_20091225143233421_0002_m_000002_0/output/file.out
 in any of the configured local directories
    [junit] 09/12/25 14:33:18 INFO mapred.JobInProgress: Task 
'attempt_20091225143233421_0002_m_000002_0' has completed 
task_20091225143233421_0002_m_000002 successfully.
    [junit] 09/12/25 14:33:18 INFO mapred.JobInProgress: Job 
job_20091225143233421_0002 has completed successfully.
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: BLOCK* 
NameSystem.allocateBlock: 
/tmp/temp-1071212225/tmp-1682484629/_logs/history/localhost_1261751553444_job_20091225143233421_0002_hudson_Job5209043222621598367.jar.
 blk_-3731730233166094500_1019
    [junit] 09/12/25 14:33:18 INFO datanode.DataNode: Receiving block 
blk_-3731730233166094500_1019 src: /127.0.0.1:40979 dest: /127.0.0.1:46725
    [junit] 09/12/25 14:33:18 INFO datanode.DataNode: Receiving block 
blk_-3731730233166094500_1019 src: /127.0.0.1:55790 dest: /127.0.0.1:57042
    [junit] 09/12/25 14:33:18 INFO datanode.DataNode: Receiving block 
blk_-3731730233166094500_1019 src: /127.0.0.1:58254 dest: /127.0.0.1:39127
    [junit] 09/12/25 14:33:18 INFO DataNode.clienttrace: src: /127.0.0.1:58254, 
dest: /127.0.0.1:39127, bytes: 6117, op: HDFS_WRITE, cliID: 
DFSClient_-693295477, srvID: DS-1783368968-127.0.1.1-39127-1261751551939, 
blockid: blk_-3731730233166094500_1019
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:39127 is added to 
blk_-3731730233166094500_1019 size 6117
    [junit] 09/12/25 14:33:18 INFO datanode.DataNode: PacketResponder 0 for 
block blk_-3731730233166094500_1019 terminating
    [junit] 09/12/25 14:33:18 INFO DataNode.clienttrace: src: /127.0.0.1:55790, 
dest: /127.0.0.1:57042, bytes: 6117, op: HDFS_WRITE, cliID: 
DFSClient_-693295477, srvID: DS-1060151078-127.0.1.1-57042-1261751553351, 
blockid: blk_-3731730233166094500_1019
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:57042 is added to 
blk_-3731730233166094500_1019 size 6117
    [junit] 09/12/25 14:33:18 INFO datanode.DataNode: PacketResponder 1 for 
block blk_-3731730233166094500_1019 terminating
    [junit] 09/12/25 14:33:18 INFO DataNode.clienttrace: src: /127.0.0.1:40979, 
dest: /127.0.0.1:46725, bytes: 6117, op: HDFS_WRITE, cliID: 
DFSClient_-693295477, srvID: DS-775249731-127.0.1.1-46725-1261751552442, 
blockid: blk_-3731730233166094500_1019
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: BLOCK* 
NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:46725 is added to 
blk_-3731730233166094500_1019 size 6117
    [junit] 09/12/25 14:33:18 INFO datanode.DataNode: PacketResponder 2 for 
block blk_-3731730233166094500_1019 terminating
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: DIR* 
NameSystem.completeFile: file 
/tmp/temp-1071212225/tmp-1682484629/_logs/history/localhost_1261751553444_job_20091225143233421_0002_hudson_Job5209043222621598367.jar
 is closed by DFSClient_-693295477
    [junit] 09/12/25 14:33:18 INFO mapred.JobTracker: Removed completed task 
'attempt_20091225143233421_0002_m_000001_0' from 
'tracker_host3.foo.com:localhost/127.0.0.1:44856'
    [junit] 09/12/25 14:33:18 INFO mapred.JobTracker: Removed completed task 
'attempt_20091225143233421_0002_m_000002_0' from 
'tracker_host3.foo.com:localhost/127.0.0.1:44856'
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: BLOCK* 
NameSystem.addToInvalidates: blk_6589178399666852537 is added to invalidSet of 
127.0.0.1:46725
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: BLOCK* 
NameSystem.addToInvalidates: blk_6589178399666852537 is added to invalidSet of 
127.0.0.1:39127
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: BLOCK* 
NameSystem.addToInvalidates: blk_6589178399666852537 is added to invalidSet of 
127.0.0.1:57042
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: BLOCK* 
NameSystem.addToInvalidates: blk_120984146150836362 is added to invalidSet of 
127.0.0.1:46725
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: BLOCK* 
NameSystem.addToInvalidates: blk_120984146150836362 is added to invalidSet of 
127.0.0.1:57042
    [junit] 09/12/25 14:33:18 INFO mapred.TaskTracker: Received 'KillJobAction' 
for job: job_20091225143233421_0002
    [junit] 09/12/25 14:33:18 INFO mapred.TaskRunner: 
attempt_20091225143233421_0002_m_000001_0 done; removing files.
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: BLOCK* 
NameSystem.addToInvalidates: blk_120984146150836362 is added to invalidSet of 
127.0.0.1:39127
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: BLOCK* 
NameSystem.addToInvalidates: blk_5815478782712360138 is added to invalidSet of 
127.0.0.1:46725
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: BLOCK* 
NameSystem.addToInvalidates: blk_5815478782712360138 is added to invalidSet of 
127.0.0.1:50836
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: BLOCK* 
NameSystem.addToInvalidates: blk_5815478782712360138 is added to invalidSet of 
127.0.0.1:39127
    [junit] 09/12/25 14:33:18 INFO mapred.IndexCache: Map ID 
attempt_20091225143233421_0002_m_000001_0 not found in cache
    [junit] 09/12/25 14:33:18 INFO mapred.TaskRunner: 
attempt_20091225143233421_0002_m_000002_0 done; removing files.
    [junit] 09/12/25 14:33:18 INFO mapred.IndexCache: Map ID 
attempt_20091225143233421_0002_m_000002_0 not found in cache
    [junit] 09/12/25 14:33:18 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=delete      
src=/tmp/hadoop-hudson/mapred/system/job_20091225143233421_0002 dst=null        
perm=null
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:57042 
to delete  blk_120984146150836362_1014 blk_6589178399666852537_1013
    [junit] 09/12/25 14:33:18 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:50836 
to delete  blk_5815478782712360138_1015
    [junit] 09/12/25 14:33:18 INFO datanode.DataNode: Deleting block 
blk_120984146150836362_1014 file 
build/test/data/dfs/data/data8/current/blk_120984146150836362
    [junit] 09/12/25 14:33:18 WARN datanode.DataNode: Unexpected error trying 
to delete block blk_6589178399666852537_1013. BlockInfo not found in volumeMap.
    [junit] 09/12/25 14:33:18 WARN datanode.DataNode: Error processing datanode 
Command
    [junit] java.io.IOException: Error in deleting blocks.
    [junit]     at 
org.apache.hadoop.hdfs.server.datanode.FSDataset.invalidate(FSDataset.java:1361)
    [junit]     at 
org.apache.hadoop.hdfs.server.datanode.DataNode.processCommand(DataNode.java:868)
    [junit]     at 
org.apache.hadoop.hdfs.server.datanode.DataNode.processCommand(DataNode.java:830)
    [junit]     at 
org.apache.hadoop.hdfs.server.datanode.DataNode.offerService(DataNode.java:710)
    [junit]     at 
org.apache.hadoop.hdfs.server.datanode.DataNode.run(DataNode.java:1186)
    [junit]     at java.lang.Thread.run(Thread.java:619)
    [junit] 09/12/25 14:33:19 INFO mapred.TaskTracker: Received 'KillJobAction' 
for job: job_20091225143233421_0002
    [junit] 09/12/25 14:33:19 WARN mapred.TaskTracker: Unknown job 
job_20091225143233421_0002 being deleted.
    [junit] 09/12/25 14:33:20 INFO mapred.TaskTracker: Received 'KillJobAction' 
for job: job_20091225143233421_0002
    [junit] 09/12/25 14:33:20 WARN mapred.TaskTracker: Unknown job 
job_20091225143233421_0002 being deleted.
    [junit] 09/12/25 14:33:20 INFO mapReduceLayer.MapReduceLauncher: 100% 
complete
    [junit] 09/12/25 14:33:20 INFO mapReduceLayer.MapReduceLauncher: 
Successfully stored result in: 
"hdfs://localhost:56870/tmp/temp-1071212225/tmp-1682484629"
    [junit] 09/12/25 14:33:20 INFO mapReduceLayer.MapReduceLauncher: Records 
written : 2
    [junit] 09/12/25 14:33:20 INFO mapReduceLayer.MapReduceLauncher: Bytes 
written : 78
    [junit] 09/12/25 14:33:20 INFO mapReduceLayer.MapReduceLauncher: Success!
    [junit] 09/12/25 14:33:20 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=listStatus  src=/tmp/temp-1071212225/tmp-1682484629 
dst=null        perm=null
    [junit] 09/12/25 14:33:20 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=open        
src=/tmp/temp-1071212225/tmp-1682484629/part-00000      dst=null        
perm=null
    [junit] 09/12/25 14:33:20 INFO DataNode.clienttrace: src: /127.0.0.1:50836, 
dest: /127.0.0.1:56226, bytes: 43, op: HDFS_READ, cliID: DFSClient_-693295477, 
srvID: DS-176134573-127.0.1.1-50836-1261751552905, blockid: 
blk_-3273610814172960303_1018
    [junit] 09/12/25 14:33:20 INFO FSNamesystem.audit: ugi=hudson,hudson        
ip=/127.0.0.1   cmd=open        
src=/tmp/temp-1071212225/tmp-1682484629/part-00001      dst=null        
perm=null
    [junit] 09/12/25 14:33:20 INFO DataNode.clienttrace: src: /127.0.0.1:50836, 
dest: /127.0.0.1:56227, bytes: 43, op: HDFS_READ, cliID: DFSClient_-693295477, 
srvID: DS-176134573-127.0.1.1-50836-1261751552905, blockid: 
blk_-1774488489287495887_1019
    [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 44.477 sec
    [junit] 09/12/25 14:33:20 INFO mapred.JobTracker: Removed completed task 
'attempt_20091225143233421_0002_m_000000_0' from 
'tracker_host2.foo.com:localhost/127.0.0.1:33303'
    [junit] 09/12/25 14:33:20 INFO mapred.JobTracker: Removed completed task 
'attempt_20091225143233421_0002_m_000003_0' from 
'tracker_host2.foo.com:localhost/127.0.0.1:33303'
    [junit] 09/12/25 14:33:20 INFO mapred.TaskTracker: Received 'KillJobAction' 
for job: job_20091225143233421_0002
    [junit] 09/12/25 14:33:20 INFO mapred.TaskRunner: 
attempt_20091225143233421_0002_m_000000_0 done; removing files.
    [junit] 09/12/25 14:33:20 INFO mapred.IndexCache: Map ID 
attempt_20091225143233421_0002_m_000000_0 not found in cache
    [junit] 09/12/25 14:33:20 WARN mapred.CleanupQueue: Error deleting 
pathfile:/tmp/hadoop-hudson/mapred/local/2_0/taskTracker/jobcache/job_20091225143233421_0002/attempt_20091225143233421_0002_m_000000_0
    [junit] 09/12/25 14:33:20 WARN mapred.CleanupQueue: Error deleting 
pathfile:/tmp/hadoop-hudson/mapred/local/2_0/taskTracker/jobcache/job_20091225143233421_0002

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

Total time: 254 minutes 9 seconds
Publishing Javadoc
Archiving artifacts
Recording test results
Recording fingerprints
Publishing Clover coverage report...
No Clover report will be published due to a Build Failure

Reply via email to