hadoop-pig-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Hudson Server <hud...@hudson.zones.apache.org>
Subject Build failed in Hudson: Pig-trunk #590
Date Fri, 16 Oct 2009 01:53:13 GMT
See <http://hudson.zones.apache.org/hudson/job/Pig-trunk/590/changes>

Changes:

[olga] PIG-1008: FINDBUGS: NP_TOSTRING_COULD_RETURN_NULL (olgan)

[olga] PIG-1018: FINDBUGS: NM_FIELD_NAMING_CONVENTION: Field names should start with
a lower case letter (olgan)

[gates] PIG-992 Separate schema related files into a schema package.

[daijy] PIG-1024: Script contains nested limit fail due to "LOLimit does not support multiple
outputs"

------------------------------------------
[...truncated 166932 lines...]
    [junit] 09/10/16 01:51:45 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=open
src=/tmp/hadoop-hudson/mapred/system/job_20091016015113228_0002/job.xml	dst=null	perm=null
    [junit] 09/10/16 01:51:45 INFO DataNode.clienttrace: src: /127.0.0.1:37481, dest: /127.0.0.1:54172,
bytes: 48624, op: HDFS_READ, cliID: DFSClient_976177328, srvID: DS-44083095-127.0.1.1-37481-1255657871758,
blockid: blk_3720997685828605371_1015
    [junit] 09/10/16 01:51:45 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=open
src=/tmp/hadoop-hudson/mapred/system/job_20091016015113228_0002/job.jar	dst=null	perm=null
    [junit] 09/10/16 01:51:45 INFO datanode.DataNode: Deleting block blk_-7015366915787233442_1007
file build/test/data/dfs/data/data3/current/blk_-7015366915787233442
    [junit] 09/10/16 01:51:45 INFO datanode.DataNode: Deleting block blk_460961930326432757_1006
file build/test/data/dfs/data/data4/current/blk_460961930326432757
    [junit] 09/10/16 01:51:45 INFO datanode.DataNode: Deleting block blk_6187000532415719696_1005
file build/test/data/dfs/data/data3/current/blk_6187000532415719696
    [junit] 09/10/16 01:51:45 INFO DataNode.clienttrace: src: /127.0.0.1:37481, dest: /127.0.0.1:54173,
bytes: 2478425, op: HDFS_READ, cliID: DFSClient_976177328, srvID: DS-44083095-127.0.1.1-37481-1255657871758,
blockid: blk_-1513737899645236710_1013
    [junit] 09/10/16 01:51:45 INFO mapReduceLayer.MapReduceLauncher: Submitting job: job_20091016015113228_0002
to execution engine.
    [junit] 09/10/16 01:51:45 INFO mapReduceLayer.MapReduceLauncher: More information at:
http://localhost:38689/jobdetails.jsp?jobid=job_20091016015113228_0002
    [junit] 09/10/16 01:51:45 INFO mapReduceLayer.MapReduceLauncher: To kill this job, use:
kill job_20091016015113228_0002
    [junit] 09/10/16 01:51:45 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_20091016015113228_0002_m_-160838137
    [junit] 09/10/16 01:51:45 INFO mapred.JvmManager: JVM Runner jvm_20091016015113228_0002_m_-160838137
spawned.
    [junit] 09/10/16 01:51:46 INFO mapred.TaskTracker: JVM with ID: jvm_20091016015113228_0002_m_-160838137
given task: attempt_20091016015113228_0002_m_000003_0
    [junit] 09/10/16 01:51:46 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:40694 to delete
 blk_-1513737899645236710_1013
    [junit] 09/10/16 01:51:46 INFO mapReduceLayer.MapReduceLauncher: 0% complete
    [junit] 09/10/16 01:51:46 INFO datanode.DataNode: Deleting block blk_-1513737899645236710_1013
file build/test/data/dfs/data/data8/current/blk_-1513737899645236710
    [junit] 09/10/16 01:51:46 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=mkdirs
src=/tmp/temp146726316/tmp-938456787/_temporary	dst=null	perm=hudson:supergroup:rwxr-xr-x
    [junit] 09/10/16 01:51:46 INFO mapred.TaskTracker: attempt_20091016015113228_0002_m_000003_0
0.0% setup
    [junit] 09/10/16 01:51:46 INFO mapred.TaskTracker: Task attempt_20091016015113228_0002_m_000003_0
is done.
    [junit] 09/10/16 01:51:46 INFO mapred.TaskTracker: reported output size for attempt_20091016015113228_0002_m_000003_0
 was 0
    [junit] 09/10/16 01:51:46 INFO mapred.TaskTracker: addFreeSlot : current free slots :
2
    [junit] 09/10/16 01:51:46 INFO mapred.JvmManager: JVM : jvm_20091016015113228_0002_m_-160838137
exited. Number of tasks it ran: 1
    [junit] 09/10/16 01:51:48 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException:
Could not find taskTracker/jobcache/job_20091016015113228_0002/attempt_20091016015113228_0002_m_000003_0/output/file.out
in any of the configured local directories
    [junit] 09/10/16 01:51:48 INFO mapred.JobInProgress: Task 'attempt_20091016015113228_0002_m_000003_0'
has completed task_20091016015113228_0002_m_000003 successfully.
    [junit] 09/10/16 01:51:48 INFO mapred.JobTracker: Adding task 'attempt_20091016015113228_0002_m_000000_0'
to tip task_20091016015113228_0002_m_000000, for tracker 'tracker_host1.foo.com:localhost/127.0.0.1:40211'
    [junit] 09/10/16 01:51:48 INFO mapred.JobInProgress: Choosing rack-local task task_20091016015113228_0002_m_000000
    [junit] 09/10/16 01:51:48 INFO mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_20091016015113228_0002_m_000000_0
task's state:UNASSIGNED
    [junit] 09/10/16 01:51:48 INFO mapred.TaskTracker: Trying to launch : attempt_20091016015113228_0002_m_000000_0
    [junit] 09/10/16 01:51:48 INFO mapred.TaskTracker: Received KillTaskAction for task: attempt_20091016015113228_0002_m_000003_0
    [junit] 09/10/16 01:51:48 INFO mapred.TaskTracker: In TaskLauncher, current free slots
: 2 and trying to launch attempt_20091016015113228_0002_m_000000_0
    [junit] 09/10/16 01:51:48 INFO mapred.TaskTracker: About to purge task: attempt_20091016015113228_0002_m_000003_0
    [junit] 09/10/16 01:51:48 INFO mapred.TaskRunner: attempt_20091016015113228_0002_m_000003_0
done; removing files.
    [junit] 09/10/16 01:51:48 INFO mapred.IndexCache: Map ID attempt_20091016015113228_0002_m_000003_0
not found in cache
    [junit] 09/10/16 01:51:48 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_20091016015113228_0002_m_1016372160
    [junit] 09/10/16 01:51:48 INFO mapred.JvmManager: JVM Runner jvm_20091016015113228_0002_m_1016372160
spawned.
    [junit] 09/10/16 01:51:48 INFO mapred.JobTracker: Adding task 'attempt_20091016015113228_0002_m_000001_0'
to tip task_20091016015113228_0002_m_000001, for tracker 'tracker_host2.foo.com:localhost/127.0.0.1:60110'
    [junit] 09/10/16 01:51:48 INFO mapred.JobInProgress: Choosing rack-local task task_20091016015113228_0002_m_000001
    [junit] 09/10/16 01:51:48 INFO mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_20091016015113228_0002_m_000001_0
task's state:UNASSIGNED
    [junit] 09/10/16 01:51:48 INFO mapred.TaskTracker: Trying to launch : attempt_20091016015113228_0002_m_000001_0
    [junit] 09/10/16 01:51:48 INFO mapred.TaskTracker: In TaskLauncher, current free slots
: 2 and trying to launch attempt_20091016015113228_0002_m_000001_0
    [junit] 09/10/16 01:51:48 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=open
src=/tmp/hadoop-hudson/mapred/system/job_20091016015113228_0002/job.xml	dst=null	perm=null
    [junit] 09/10/16 01:51:48 INFO DataNode.clienttrace: src: /127.0.0.1:44175, dest: /127.0.0.1:55764,
bytes: 48624, op: HDFS_READ, cliID: DFSClient_976177328, srvID: DS-1485018716-127.0.1.1-44175-1255657872727,
blockid: blk_3720997685828605371_1015
    [junit] 09/10/16 01:51:48 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=open
src=/tmp/hadoop-hudson/mapred/system/job_20091016015113228_0002/job.jar	dst=null	perm=null
    [junit] 09/10/16 01:51:48 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:40694,
storageID=DS-425274245-127.0.1.1-40694-1255657873167, infoPort=34656, ipcPort=56747):Got exception
while serving blk_-1513737899645236710_1013 to /127.0.0.1:
    [junit] java.io.IOException: Block blk_-1513737899645236710_1013 is not valid.
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.FSDataset.getBlockFile(FSDataset.java:734)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.FSDataset.getLength(FSDataset.java:722)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockSender.<init>(BlockSender.java:92)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:172)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:95)
    [junit] 	at java.lang.Thread.run(Thread.java:619)
    [junit] 
    [junit] 09/10/16 01:51:48 ERROR datanode.DataNode: DatanodeRegistration(127.0.0.1:40694,
storageID=DS-425274245-127.0.1.1-40694-1255657873167, infoPort=34656, ipcPort=56747):DataXceiver
    [junit] java.io.IOException: Block blk_-1513737899645236710_1013 is not valid.
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.FSDataset.getBlockFile(FSDataset.java:734)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.FSDataset.getLength(FSDataset.java:722)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.BlockSender.<init>(BlockSender.java:92)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.DataXceiver.readBlock(DataXceiver.java:172)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.DataXceiver.run(DataXceiver.java:95)
    [junit] 	at java.lang.Thread.run(Thread.java:619)
    [junit] 09/10/16 01:51:48 INFO DataNode.clienttrace: src: /127.0.0.1:44175, dest: /127.0.0.1:55766,
bytes: 2478425, op: HDFS_READ, cliID: DFSClient_976177328, srvID: DS-1485018716-127.0.1.1-44175-1255657872727,
blockid: blk_-1513737899645236710_1013
    [junit] 09/10/16 01:51:48 INFO mapred.TaskTracker: JVM with ID: jvm_20091016015113228_0002_m_1016372160
given task: attempt_20091016015113228_0002_m_000000_0
    [junit] 09/10/16 01:51:48 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_20091016015113228_0002_m_967886279
    [junit] 09/10/16 01:51:48 INFO mapred.JvmManager: JVM Runner jvm_20091016015113228_0002_m_967886279
spawned.
    [junit] 09/10/16 01:51:49 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=open
src=/user/hudson/input2.txt	dst=null	perm=null
    [junit] 09/10/16 01:51:49 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=create
src=/tmp/temp146726316/tmp-938456787/_temporary/_attempt_20091016015113228_0002_m_000000_0/part-00000
dst=null	perm=hudson:supergroup:rw-r--r--
    [junit] 09/10/16 01:51:49 INFO DataNode.clienttrace: src: /127.0.0.1:44175, dest: /127.0.0.1:55772,
bytes: 10, op: HDFS_READ, cliID: DFSClient_attempt_20091016015113228_0002_m_000000_0, srvID:
DS-1485018716-127.0.1.1-44175-1255657872727, blockid: blk_-4708828433662922615_1012
    [junit] 09/10/16 01:51:49 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/temp146726316/tmp-938456787/_temporary/_attempt_20091016015113228_0002_m_000000_0/part-00000.
blk_-3781470518734314825_1018
    [junit] 09/10/16 01:51:49 INFO datanode.DataNode: Receiving block blk_-3781470518734314825_1018
src: /127.0.0.1:55773 dest: /127.0.0.1:44175
    [junit] 09/10/16 01:51:49 INFO datanode.DataNode: Receiving block blk_-3781470518734314825_1018
src: /127.0.0.1:58371 dest: /127.0.0.1:40694
    [junit] 09/10/16 01:51:49 INFO datanode.DataNode: Receiving block blk_-3781470518734314825_1018
src: /127.0.0.1:54192 dest: /127.0.0.1:37481
    [junit] 09/10/16 01:51:49 INFO DataNode.clienttrace: src: /127.0.0.1:54192, dest: /127.0.0.1:37481,
bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091016015113228_0002_m_000000_0, srvID:
DS-44083095-127.0.1.1-37481-1255657871758, blockid: blk_-3781470518734314825_1018
    [junit] 09/10/16 01:51:49 INFO datanode.DataNode: PacketResponder 0 for block blk_-3781470518734314825_1018
terminating
    [junit] 09/10/16 01:51:49 INFO DataNode.clienttrace: src: /127.0.0.1:58371, dest: /127.0.0.1:40694,
bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091016015113228_0002_m_000000_0, srvID:
DS-425274245-127.0.1.1-40694-1255657873167, blockid: blk_-3781470518734314825_1018
    [junit] 09/10/16 01:51:49 INFO datanode.DataNode: PacketResponder 1 for block blk_-3781470518734314825_1018
terminating
    [junit] 09/10/16 01:51:49 INFO DataNode.clienttrace: src: /127.0.0.1:55773, dest: /127.0.0.1:44175,
bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091016015113228_0002_m_000000_0, srvID:
DS-1485018716-127.0.1.1-44175-1255657872727, blockid: blk_-3781470518734314825_1018
    [junit] 09/10/16 01:51:49 INFO datanode.DataNode: PacketResponder 2 for block blk_-3781470518734314825_1018
terminating
    [junit] 09/10/16 01:51:49 INFO mapred.TaskTracker: JVM with ID: jvm_20091016015113228_0002_m_967886279
given task: attempt_20091016015113228_0002_m_000001_0
    [junit] 09/10/16 01:51:49 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap
updated: 127.0.0.1:37481 is added to blk_-3781470518734314825_1018 size 39
    [junit] 09/10/16 01:51:49 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/temp146726316/tmp-938456787/_temporary/_attempt_20091016015113228_0002_m_000000_0/part-00000
is closed by DFSClient_attempt_20091016015113228_0002_m_000000_0
    [junit] 09/10/16 01:51:49 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap
updated: 127.0.0.1:44175 is added to blk_-3781470518734314825_1018 size 39
    [junit] 09/10/16 01:51:49 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap
updated: 127.0.0.1:40694 is added to blk_-3781470518734314825_1018 size 39
    [junit] 09/10/16 01:51:49 INFO mapred.TaskTracker: Task attempt_20091016015113228_0002_m_000000_0
is in commit-pending, task state:COMMIT_PENDING
    [junit] 09/10/16 01:51:49 INFO mapred.TaskTracker: attempt_20091016015113228_0002_m_000000_0
0.0% 
    [junit] 09/10/16 01:51:49 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=open
src=/user/hudson/input1.txt	dst=null	perm=null
    [junit] 09/10/16 01:51:49 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=create
src=/tmp/temp146726316/tmp-938456787/_temporary/_attempt_20091016015113228_0002_m_000001_0/part-00001
dst=null	perm=hudson:supergroup:rw-r--r--
    [junit] 09/10/16 01:51:49 INFO DataNode.clienttrace: src: /127.0.0.1:44175, dest: /127.0.0.1:55781,
bytes: 10, op: HDFS_READ, cliID: DFSClient_attempt_20091016015113228_0002_m_000001_0, srvID:
DS-1485018716-127.0.1.1-44175-1255657872727, blockid: blk_-6171357951036791597_1011
    [junit] 09/10/16 01:51:50 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/temp146726316/tmp-938456787/_temporary/_attempt_20091016015113228_0002_m_000001_0/part-00001.
blk_-5234253442808821729_1019
    [junit] 09/10/16 01:51:50 INFO datanode.DataNode: Receiving block blk_-5234253442808821729_1019
src: /127.0.0.1:58377 dest: /127.0.0.1:40694
    [junit] 09/10/16 01:51:50 INFO datanode.DataNode: Receiving block blk_-5234253442808821729_1019
src: /127.0.0.1:55783 dest: /127.0.0.1:44175
    [junit] 09/10/16 01:51:50 INFO datanode.DataNode: Receiving block blk_-5234253442808821729_1019
src: /127.0.0.1:54199 dest: /127.0.0.1:37481
    [junit] 09/10/16 01:51:50 INFO DataNode.clienttrace: src: /127.0.0.1:54199, dest: /127.0.0.1:37481,
bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091016015113228_0002_m_000001_0, srvID:
DS-44083095-127.0.1.1-37481-1255657871758, blockid: blk_-5234253442808821729_1019
    [junit] 09/10/16 01:51:50 INFO datanode.DataNode: PacketResponder 0 for block blk_-5234253442808821729_1019
terminating
    [junit] 09/10/16 01:51:50 INFO DataNode.clienttrace: src: /127.0.0.1:55783, dest: /127.0.0.1:44175,
bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091016015113228_0002_m_000001_0, srvID:
DS-1485018716-127.0.1.1-44175-1255657872727, blockid: blk_-5234253442808821729_1019
    [junit] 09/10/16 01:51:50 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap
updated: 127.0.0.1:37481 is added to blk_-5234253442808821729_1019 size 39
    [junit] 09/10/16 01:51:50 INFO datanode.DataNode: PacketResponder 1 for block blk_-5234253442808821729_1019
terminating
    [junit] 09/10/16 01:51:50 INFO DataNode.clienttrace: src: /127.0.0.1:58377, dest: /127.0.0.1:40694,
bytes: 39, op: HDFS_WRITE, cliID: DFSClient_attempt_20091016015113228_0002_m_000001_0, srvID:
DS-425274245-127.0.1.1-40694-1255657873167, blockid: blk_-5234253442808821729_1019
    [junit] 09/10/16 01:51:50 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap
updated: 127.0.0.1:44175 is added to blk_-5234253442808821729_1019 size 39
    [junit] 09/10/16 01:51:50 INFO datanode.DataNode: PacketResponder 2 for block blk_-5234253442808821729_1019
terminating
    [junit] 09/10/16 01:51:50 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap
updated: 127.0.0.1:40694 is added to blk_-5234253442808821729_1019 size 39
    [junit] 09/10/16 01:51:50 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/temp146726316/tmp-938456787/_temporary/_attempt_20091016015113228_0002_m_000001_0/part-00001
is closed by DFSClient_attempt_20091016015113228_0002_m_000001_0
    [junit] 09/10/16 01:51:50 INFO mapred.TaskTracker: Task attempt_20091016015113228_0002_m_000001_0
is in commit-pending, task state:COMMIT_PENDING
    [junit] 09/10/16 01:51:50 INFO mapred.TaskTracker: attempt_20091016015113228_0002_m_000001_0
0.0% 
    [junit] 09/10/16 01:51:51 INFO mapred.TaskTracker: Received commit task action for attempt_20091016015113228_0002_m_000000_0
    [junit] 09/10/16 01:51:51 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=listStatus
src=/tmp/temp146726316/tmp-938456787/_temporary/_attempt_20091016015113228_0002_m_000000_0
dst=null	perm=null
    [junit] 09/10/16 01:51:51 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=mkdirs
src=/tmp/temp146726316/tmp-938456787	dst=null	perm=hudson:supergroup:rwxr-xr-x
    [junit] 09/10/16 01:51:51 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=rename
src=/tmp/temp146726316/tmp-938456787/_temporary/_attempt_20091016015113228_0002_m_000000_0/part-00000
dst=/tmp/temp146726316/tmp-938456787/part-00000	perm=hudson:supergroup:rw-r--r--
    [junit] 09/10/16 01:51:51 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=delete
src=/tmp/temp146726316/tmp-938456787/_temporary/_attempt_20091016015113228_0002_m_000000_0
dst=null	perm=null
    [junit] 09/10/16 01:51:51 INFO mapred.TaskTracker: attempt_20091016015113228_0002_m_000000_0
1.0% 
    [junit] 09/10/16 01:51:51 INFO mapred.TaskTracker: Task attempt_20091016015113228_0002_m_000000_0
is done.
    [junit] 09/10/16 01:51:51 INFO mapred.TaskTracker: reported output size for attempt_20091016015113228_0002_m_000000_0
 was 0
    [junit] 09/10/16 01:51:51 INFO mapred.TaskTracker: addFreeSlot : current free slots :
2
    [junit] 09/10/16 01:51:51 INFO mapred.TaskTracker: Received commit task action for attempt_20091016015113228_0002_m_000001_0
    [junit] 09/10/16 01:51:51 INFO mapred.JvmManager: JVM : jvm_20091016015113228_0002_m_1016372160
exited. Number of tasks it ran: 1
    [junit] 09/10/16 01:51:52 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=listStatus
src=/tmp/temp146726316/tmp-938456787/_temporary/_attempt_20091016015113228_0002_m_000001_0
dst=null	perm=null
    [junit] 09/10/16 01:51:52 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=mkdirs
src=/tmp/temp146726316/tmp-938456787	dst=null	perm=hudson:supergroup:rwxr-xr-x
    [junit] 09/10/16 01:51:52 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=rename
src=/tmp/temp146726316/tmp-938456787/_temporary/_attempt_20091016015113228_0002_m_000001_0/part-00001
dst=/tmp/temp146726316/tmp-938456787/part-00001	perm=hudson:supergroup:rw-r--r--
    [junit] 09/10/16 01:51:52 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=delete
src=/tmp/temp146726316/tmp-938456787/_temporary/_attempt_20091016015113228_0002_m_000001_0
dst=null	perm=null
    [junit] 09/10/16 01:51:52 INFO mapred.TaskTracker: attempt_20091016015113228_0002_m_000001_0
1.0% 
    [junit] 09/10/16 01:51:52 INFO mapred.TaskTracker: Task attempt_20091016015113228_0002_m_000001_0
is done.
    [junit] 09/10/16 01:51:52 INFO mapred.TaskTracker: reported output size for attempt_20091016015113228_0002_m_000001_0
 was 0
    [junit] 09/10/16 01:51:52 INFO mapred.TaskTracker: addFreeSlot : current free slots :
2
    [junit] 09/10/16 01:51:52 INFO mapred.JvmManager: JVM : jvm_20091016015113228_0002_m_967886279
exited. Number of tasks it ran: 1
    [junit] 09/10/16 01:51:54 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException:
Could not find taskTracker/jobcache/job_20091016015113228_0002/attempt_20091016015113228_0002_m_000000_0/output/file.out
in any of the configured local directories
    [junit] 09/10/16 01:51:54 INFO mapred.JobInProgress: Task 'attempt_20091016015113228_0002_m_000000_0'
has completed task_20091016015113228_0002_m_000000 successfully.
    [junit] 09/10/16 01:51:54 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException:
Could not find taskTracker/jobcache/job_20091016015113228_0002/attempt_20091016015113228_0002_m_000001_0/output/file.out
in any of the configured local directories
    [junit] 09/10/16 01:51:54 INFO mapred.JobInProgress: Task 'attempt_20091016015113228_0002_m_000001_0'
has completed task_20091016015113228_0002_m_000001 successfully.
    [junit] 09/10/16 01:51:54 INFO mapred.JobTracker: Adding task 'attempt_20091016015113228_0002_m_000002_0'
to tip task_20091016015113228_0002_m_000002, for tracker 'tracker_host2.foo.com:localhost/127.0.0.1:60110'
    [junit] 09/10/16 01:51:54 INFO mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_20091016015113228_0002_m_000002_0
task's state:UNASSIGNED
    [junit] 09/10/16 01:51:54 INFO mapred.TaskTracker: Trying to launch : attempt_20091016015113228_0002_m_000002_0
    [junit] 09/10/16 01:51:54 INFO mapred.TaskTracker: In TaskLauncher, current free slots
: 2 and trying to launch attempt_20091016015113228_0002_m_000002_0
    [junit] 09/10/16 01:51:54 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_20091016015113228_0002_m_-1839959741
    [junit] 09/10/16 01:51:54 INFO mapred.JvmManager: JVM Runner jvm_20091016015113228_0002_m_-1839959741
spawned.
    [junit] 09/10/16 01:51:54 INFO mapReduceLayer.MapReduceLauncher: 50% complete
    [junit] 09/10/16 01:51:55 INFO mapred.TaskTracker: JVM with ID: jvm_20091016015113228_0002_m_-1839959741
given task: attempt_20091016015113228_0002_m_000002_0
    [junit] 09/10/16 01:51:55 INFO mapred.TaskTracker: attempt_20091016015113228_0002_m_000002_0
0.0% 
    [junit] 09/10/16 01:51:55 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=delete
src=/tmp/temp146726316/tmp-938456787/_temporary	dst=null	perm=null
    [junit] 09/10/16 01:51:55 INFO mapred.TaskTracker: attempt_20091016015113228_0002_m_000002_0
0.0% cleanup
    [junit] 09/10/16 01:51:55 INFO mapred.TaskTracker: Task attempt_20091016015113228_0002_m_000002_0
is done.
    [junit] 09/10/16 01:51:55 INFO mapred.TaskTracker: reported output size for attempt_20091016015113228_0002_m_000002_0
 was 0
    [junit] 09/10/16 01:51:55 INFO mapred.TaskTracker: addFreeSlot : current free slots :
2
    [junit] 09/10/16 01:51:55 INFO mapred.JvmManager: JVM : jvm_20091016015113228_0002_m_-1839959741
exited. Number of tasks it ran: 1
    [junit] 09/10/16 01:51:57 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException:
Could not find taskTracker/jobcache/job_20091016015113228_0002/attempt_20091016015113228_0002_m_000002_0/output/file.out
in any of the configured local directories
    [junit] 09/10/16 01:51:57 INFO mapred.JobInProgress: Task 'attempt_20091016015113228_0002_m_000002_0'
has completed task_20091016015113228_0002_m_000002 successfully.
    [junit] 09/10/16 01:51:57 INFO mapred.JobInProgress: Job job_20091016015113228_0002 has
completed successfully.
    [junit] 09/10/16 01:51:57 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /tmp/temp146726316/tmp-938456787/_logs/history/localhost_1255657873260_job_20091016015113228_0002_hudson_Job3907261595650969736.jar.
blk_-4221595204003129219_1019
    [junit] 09/10/16 01:51:57 INFO datanode.DataNode: Receiving block blk_-4221595204003129219_1019
src: /127.0.0.1:46539 dest: /127.0.0.1:60654
    [junit] 09/10/16 01:51:57 INFO datanode.DataNode: Receiving block blk_-4221595204003129219_1019
src: /127.0.0.1:54206 dest: /127.0.0.1:37481
    [junit] 09/10/16 01:51:57 INFO datanode.DataNode: Receiving block blk_-4221595204003129219_1019
src: /127.0.0.1:58387 dest: /127.0.0.1:40694
    [junit] 09/10/16 01:51:57 INFO DataNode.clienttrace: src: /127.0.0.1:58387, dest: /127.0.0.1:40694,
bytes: 6117, op: HDFS_WRITE, cliID: DFSClient_976177328, srvID: DS-425274245-127.0.1.1-40694-1255657873167,
blockid: blk_-4221595204003129219_1019
    [junit] 09/10/16 01:51:57 INFO datanode.DataNode: PacketResponder 0 for block blk_-4221595204003129219_1019
terminating
    [junit] 09/10/16 01:51:57 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap
updated: 127.0.0.1:40694 is added to blk_-4221595204003129219_1019 size 6117
    [junit] 09/10/16 01:51:57 INFO DataNode.clienttrace: src: /127.0.0.1:54206, dest: /127.0.0.1:37481,
bytes: 6117, op: HDFS_WRITE, cliID: DFSClient_976177328, srvID: DS-44083095-127.0.1.1-37481-1255657871758,
blockid: blk_-4221595204003129219_1019
    [junit] 09/10/16 01:51:57 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap
updated: 127.0.0.1:37481 is added to blk_-4221595204003129219_1019 size 6117
    [junit] 09/10/16 01:51:57 INFO datanode.DataNode: PacketResponder 1 for block blk_-4221595204003129219_1019
terminating
    [junit] 09/10/16 01:51:57 INFO DataNode.clienttrace: src: /127.0.0.1:46539, dest: /127.0.0.1:60654,
bytes: 6117, op: HDFS_WRITE, cliID: DFSClient_976177328, srvID: DS-916168355-127.0.1.1-60654-1255657872258,
blockid: blk_-4221595204003129219_1019
    [junit] 09/10/16 01:51:57 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap
updated: 127.0.0.1:60654 is added to blk_-4221595204003129219_1019 size 6117
    [junit] 09/10/16 01:51:57 INFO datanode.DataNode: PacketResponder 2 for block blk_-4221595204003129219_1019
terminating
    [junit] 09/10/16 01:51:57 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /tmp/temp146726316/tmp-938456787/_logs/history/localhost_1255657873260_job_20091016015113228_0002_hudson_Job3907261595650969736.jar
is closed by DFSClient_976177328
    [junit] 09/10/16 01:51:57 INFO mapred.JobTracker: Removed completed task 'attempt_20091016015113228_0002_m_000001_0'
from 'tracker_host2.foo.com:localhost/127.0.0.1:60110'
    [junit] 09/10/16 01:51:57 INFO mapred.JobTracker: Removed completed task 'attempt_20091016015113228_0002_m_000002_0'
from 'tracker_host2.foo.com:localhost/127.0.0.1:60110'
    [junit] 09/10/16 01:51:57 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_20091016015113228_0002
    [junit] 09/10/16 01:51:57 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-1513737899645236710
is added to invalidSet of 127.0.0.1:40694
    [junit] 09/10/16 01:51:57 INFO mapred.TaskRunner: attempt_20091016015113228_0002_m_000001_0
done; removing files.
    [junit] 09/10/16 01:51:57 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-1513737899645236710
is added to invalidSet of 127.0.0.1:44175
    [junit] 09/10/16 01:51:57 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-1513737899645236710
is added to invalidSet of 127.0.0.1:37481
    [junit] 09/10/16 01:51:57 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_2865039871718796523
is added to invalidSet of 127.0.0.1:60654
    [junit] 09/10/16 01:51:57 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_2865039871718796523
is added to invalidSet of 127.0.0.1:40694
    [junit] 09/10/16 01:51:57 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_2865039871718796523
is added to invalidSet of 127.0.0.1:37481
    [junit] 09/10/16 01:51:57 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3720997685828605371
is added to invalidSet of 127.0.0.1:37481
    [junit] 09/10/16 01:51:57 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3720997685828605371
is added to invalidSet of 127.0.0.1:60654
    [junit] 09/10/16 01:51:57 INFO mapred.IndexCache: Map ID attempt_20091016015113228_0002_m_000001_0
not found in cache
    [junit] 09/10/16 01:51:57 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3720997685828605371
is added to invalidSet of 127.0.0.1:44175
    [junit] 09/10/16 01:51:57 INFO mapred.TaskRunner: attempt_20091016015113228_0002_m_000002_0
done; removing files.
    [junit] 09/10/16 01:51:57 INFO mapred.IndexCache: Map ID attempt_20091016015113228_0002_m_000002_0
not found in cache
    [junit] 09/10/16 01:51:57 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=delete
src=/tmp/hadoop-hudson/mapred/system/job_20091016015113228_0002	dst=null	perm=null
    [junit] 09/10/16 01:51:57 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_20091016015113228_0002
    [junit] 09/10/16 01:51:57 WARN mapred.TaskTracker: Unknown job job_20091016015113228_0002
being deleted.
    [junit] 09/10/16 01:51:58 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:44175 to delete
 blk_3720997685828605371_1015 blk_-1513737899645236710_1013
    [junit] 09/10/16 01:51:58 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:40694 to delete
 blk_-1513737899645236710_1013 blk_2865039871718796523_1014
    [junit] 09/10/16 01:51:58 WARN datanode.DataNode: Unexpected error trying to delete block
blk_-1513737899645236710_1013. BlockInfo not found in volumeMap.
    [junit] 09/10/16 01:51:58 INFO datanode.DataNode: Deleting block blk_2865039871718796523_1014
file build/test/data/dfs/data/data7/current/blk_2865039871718796523
    [junit] 09/10/16 01:51:58 WARN datanode.DataNode: Error processing datanode Command
    [junit] java.io.IOException: Error in deleting blocks.
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.FSDataset.invalidate(FSDataset.java:1361)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.DataNode.processCommand(DataNode.java:868)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.DataNode.processCommand(DataNode.java:830)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.DataNode.offerService(DataNode.java:710)
    [junit] 	at org.apache.hadoop.hdfs.server.datanode.DataNode.run(DataNode.java:1186)
    [junit] 	at java.lang.Thread.run(Thread.java:619)
    [junit] 09/10/16 01:51:59 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_20091016015113228_0002
    [junit] 09/10/16 01:51:59 WARN mapred.TaskTracker: Unknown job job_20091016015113228_0002
being deleted.
    [junit] 09/10/16 01:52:00 INFO mapReduceLayer.MapReduceLauncher: 100% complete
    [junit] 09/10/16 01:52:00 INFO mapReduceLayer.MapReduceLauncher: Successfully stored result
in: "hdfs://localhost:54982/tmp/temp146726316/tmp-938456787"
    [junit] 09/10/16 01:52:00 INFO mapReduceLayer.MapReduceLauncher: Records written : 2
    [junit] 09/10/16 01:52:00 INFO mapReduceLayer.MapReduceLauncher: Bytes written : 78
    [junit] 09/10/16 01:52:00 INFO mapReduceLayer.MapReduceLauncher: Success!
    [junit] 09/10/16 01:52:00 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=listStatus
src=/tmp/temp146726316/tmp-938456787	dst=null	perm=null
    [junit] 09/10/16 01:52:00 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=open
src=/tmp/temp146726316/tmp-938456787/part-00000	dst=null	perm=null
    [junit] 09/10/16 01:52:00 INFO DataNode.clienttrace: src: /127.0.0.1:44175, dest: /127.0.0.1:55793,
bytes: 43, op: HDFS_READ, cliID: DFSClient_976177328, srvID: DS-1485018716-127.0.1.1-44175-1255657872727,
blockid: blk_-3781470518734314825_1018
    [junit] 09/10/16 01:52:00 INFO FSNamesystem.audit: ugi=hudson,hudson	ip=/127.0.0.1	cmd=open
src=/tmp/temp146726316/tmp-938456787/part-00001	dst=null	perm=null
    [junit] 09/10/16 01:52:00 INFO DataNode.clienttrace: src: /127.0.0.1:37481, dest: /127.0.0.1:54209,
bytes: 43, op: HDFS_READ, cliID: DFSClient_976177328, srvID: DS-44083095-127.0.1.1-37481-1255657871758,
blockid: blk_-5234253442808821729_1019
    [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 44.2 sec
    [junit] 09/10/16 01:52:00 INFO mapred.JobTracker: Removed completed task 'attempt_20091016015113228_0002_m_000000_0'
from 'tracker_host1.foo.com:localhost/127.0.0.1:40211'
    [junit] 09/10/16 01:52:00 INFO mapred.JobTracker: Removed completed task 'attempt_20091016015113228_0002_m_000003_0'
from 'tracker_host1.foo.com:localhost/127.0.0.1:40211'
    [junit] 09/10/16 01:52:00 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_20091016015113228_0002
    [junit] 09/10/16 01:52:00 INFO mapred.TaskRunner: attempt_20091016015113228_0002_m_000000_0
done; removing files.
    [junit] 09/10/16 01:52:00 INFO mapred.TaskTracker: Error cleaning up task runner: java.lang.IllegalStateException:
Shutdown in progress
    [junit] 	at java.lang.ApplicationShutdownHooks.add(ApplicationShutdownHooks.java:39)
    [junit] 	at java.lang.Runtime.addShutdownHook(Runtime.java:192)
    [junit] 	at org.apache.hadoop.fs.FileSystem$Cache.get(FileSystem.java:1387)
    [junit] 	at org.apache.hadoop.fs.FileSystem.get(FileSystem.java:191)
    [junit] 	at org.apache.hadoop.fs.FileSystem.getLocal(FileSystem.java:167)
    [junit] 	at org.apache.hadoop.mapred.JobConf.deleteLocalFiles(JobConf.java:270)
    [junit] 	at org.apache.hadoop.mapred.MapOutputFile.removeAll(MapOutputFile.java:168)
    [junit] 	at org.apache.hadoop.mapred.MapTaskRunner.close(MapTaskRunner.java:44)
    [junit] 	at org.apache.hadoop.mapred.TaskTracker$TaskInProgress.cleanup(TaskTracker.java:2426)
    [junit] 	at org.apache.hadoop.mapred.TaskTracker$TaskInProgress.jobHasFinished(TaskTracker.java:2318)
    [junit] 	at org.apache.hadoop.mapred.TaskTracker.purgeJob(TaskTracker.java:1351)
    [junit] 	at org.apache.hadoop.mapred.TaskTracker.access$100(TaskTracker.java:97)
    [junit] 	at org.apache.hadoop.mapred.TaskTracker$1.run(TaskTracker.java:319)
    [junit] 	at java.lang.Thread.run(Thread.java:619)
    [junit] 
    [junit] 09/10/16 01:52:00 INFO mapred.IndexCache: Map ID attempt_20091016015113228_0002_m_000000_0
not found in cache
    [junit] 09/10/16 01:52:00 WARN mapred.TaskTracker: java.lang.IllegalStateException: Shutdown
in progress
    [junit] 	at java.lang.ApplicationShutdownHooks.add(ApplicationShutdownHooks.java:39)
    [junit] 	at java.lang.Runtime.addShutdownHook(Runtime.java:192)
    [junit] 	at org.apache.hadoop.fs.FileSystem$Cache.get(FileSystem.java:1387)
    [junit] 	at org.apache.hadoop.fs.FileSystem.get(FileSystem.java:191)
    [junit] 	at org.apache.hadoop.fs.FileSystem.getLocal(FileSystem.java:167)
    [junit] 	at org.apache.hadoop.mapred.TaskTracker.getLocalFiles(TaskTracker.java:2986)
    [junit] 	at org.apache.hadoop.mapred.TaskTracker.purgeJob(TaskTracker.java:1360)
    [junit] 	at org.apache.hadoop.mapred.TaskTracker.access$100(TaskTracker.java:97)
    [junit] 	at org.apache.hadoop.mapred.TaskTracker$1.run(TaskTracker.java:319)
    [junit] 	at java.lang.Thread.run(Thread.java:619)
    [junit] 

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

Total time: 166 minutes 25 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


Mime
View raw message