See <https://builds.apache.org/job/Pig-trunk-commit/863/changes>
Changes: [thejas] PIG-2171: TestScriptLanguage is broken on trunk (daijy and thejas) ------------------------------------------ [...truncated 29087 lines...] [junit] 11/07/19 22:23:00 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /user/hudson/testGetSchema-output.txt/_temporary/_attempt_20110719222148896_0004_m_000000_0/part-m-00000 is closed by DFSClient_attempt_20110719222148896_0004_m_000000_0 [junit] 11/07/19 22:23:00 INFO mapred.TaskTracker: Task attempt_20110719222148896_0004_m_000000_0 is in commit-pending, task state:COMMIT_PENDING [junit] 11/07/19 22:23:00 INFO mapred.TaskTracker: attempt_20110719222148896_0004_m_000000_0 0.0% [junit] 11/07/19 22:23:02 INFO mapred.TaskTracker: Received commit task action for attempt_20110719222148896_0004_m_000000_0 [junit] 11/07/19 22:23:02 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=listStatus src=/user/hudson/testGetSchema-output.txt/_temporary/_attempt_20110719222148896_0004_m_000000_0 dst=null perm=null [junit] 11/07/19 22:23:02 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=mkdirs src=/user/hudson/testGetSchema-output.txt dst=null perm=hudson:supergroup:rwxr-xr-x [junit] 11/07/19 22:23:02 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=rename src=/user/hudson/testGetSchema-output.txt/_temporary/_attempt_20110719222148896_0004_m_000000_0/part-m-00000 dst=/user/hudson/testGetSchema-output.txt/part-m-00000 perm=hudson:supergroup:rw-r--r-- [junit] 11/07/19 22:23:02 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/user/hudson/testGetSchema-output.txt/_temporary/_attempt_20110719222148896_0004_m_000000_0 dst=null perm=null [junit] 11/07/19 22:23:02 INFO mapred.TaskTracker: attempt_20110719222148896_0004_m_000000_0 1.0% [junit] 11/07/19 22:23:02 INFO mapred.TaskTracker: Task attempt_20110719222148896_0004_m_000000_0 is done. [junit] 11/07/19 22:23:02 INFO mapred.TaskTracker: reported output size for attempt_20110719222148896_0004_m_000000_0 was 0 [junit] 11/07/19 22:23:02 INFO mapred.TaskTracker: addFreeSlot : current free slots : 2 [junit] 11/07/19 22:23:02 INFO mapred.JvmManager: JVM : jvm_20110719222148896_0004_m_433982627 exited. Number of tasks it ran: 1 [junit] 11/07/19 22:23:05 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find taskTracker/jobcache/job_20110719222148896_0004/attempt_20110719222148896_0004_m_000000_0/output/file.out in any of the configured local directories [junit] 11/07/19 22:23:05 INFO mapred.JobInProgress: Task 'attempt_20110719222148896_0004_m_000000_0' has completed task_20110719222148896_0004_m_000000 successfully. [junit] 11/07/19 22:23:05 INFO mapred.JobTracker: Adding task 'attempt_20110719222148896_0004_m_000001_0' to tip task_20110719222148896_0004_m_000001, for tracker 'tracker_host0.foo.com:localhost/127.0.0.1:36771' [junit] 11/07/19 22:23:05 INFO mapred.TaskTracker: LaunchTaskAction (registerTask): attempt_20110719222148896_0004_m_000001_0 task's state:UNASSIGNED [junit] 11/07/19 22:23:05 INFO mapred.TaskTracker: Trying to launch : attempt_20110719222148896_0004_m_000001_0 [junit] 11/07/19 22:23:05 INFO mapred.TaskTracker: In TaskLauncher, current free slots : 2 and trying to launch attempt_20110719222148896_0004_m_000001_0 [junit] 11/07/19 22:23:05 INFO mapReduceLayer.MapReduceLauncher: 50% complete [junit] 11/07/19 22:23:05 INFO mapred.JvmManager: In JvmRunner constructed JVM ID: jvm_20110719222148896_0004_m_-614666636 [junit] 11/07/19 22:23:05 INFO mapred.JvmManager: JVM Runner jvm_20110719222148896_0004_m_-614666636 spawned. [junit] 11/07/19 22:23:05 INFO mapred.TaskTracker: JVM with ID: jvm_20110719222148896_0004_m_-614666636 given task: attempt_20110719222148896_0004_m_000001_0 [junit] 11/07/19 22:23:06 INFO mapred.TaskTracker: attempt_20110719222148896_0004_m_000001_0 0.0% [junit] 11/07/19 22:23:06 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/user/hudson/testGetSchema-output.txt/_temporary dst=null perm=null [junit] 11/07/19 22:23:06 INFO mapred.TaskTracker: attempt_20110719222148896_0004_m_000001_0 0.0% cleanup [junit] 11/07/19 22:23:06 INFO mapred.TaskTracker: Task attempt_20110719222148896_0004_m_000001_0 is done. [junit] 11/07/19 22:23:06 INFO mapred.TaskTracker: reported output size for attempt_20110719222148896_0004_m_000001_0 was 0 [junit] 11/07/19 22:23:06 INFO mapred.TaskTracker: addFreeSlot : current free slots : 2 [junit] 11/07/19 22:23:06 INFO mapred.JvmManager: JVM : jvm_20110719222148896_0004_m_-614666636 exited. Number of tasks it ran: 1 [junit] 11/07/19 22:23:08 INFO mapred.TaskTracker: org.apache.hadoop.util.DiskChecker$DiskErrorException: Could not find taskTracker/jobcache/job_20110719222148896_0004/attempt_20110719222148896_0004_m_000001_0/output/file.out in any of the configured local directories [junit] 11/07/19 22:23:08 INFO mapred.JobInProgress: Task 'attempt_20110719222148896_0004_m_000001_0' has completed task_20110719222148896_0004_m_000001 successfully. [junit] 11/07/19 22:23:08 INFO mapred.JobInProgress: Job job_20110719222148896_0004 has completed successfully. [junit] 11/07/19 22:23:08 INFO hdfs.StateChange: BLOCK* NameSystem.allocateBlock: /user/hudson/testGetSchema-output.txt/_logs/history/localhost_1311114108918_job_20110719222148896_0004_hudson_PigLatin%3ADefaultJobName. blk_1386529195495096816_1030 [junit] 11/07/19 22:23:08 INFO datanode.DataNode: Receiving block blk_1386529195495096816_1030 src: /127.0.0.1:60259 dest: /127.0.0.1:33629 [junit] 11/07/19 22:23:08 INFO datanode.DataNode: Receiving block blk_1386529195495096816_1030 src: /127.0.0.1:56093 dest: /127.0.0.1:60594 [junit] 11/07/19 22:23:08 INFO datanode.DataNode: Receiving block blk_1386529195495096816_1030 src: /127.0.0.1:39180 dest: /127.0.0.1:59462 [junit] 11/07/19 22:23:08 INFO DataNode.clienttrace: src: /127.0.0.1:39180, dest: /127.0.0.1:59462, bytes: 4499, op: HDFS_WRITE, cliID: DFSClient_1432658130, srvID: DS-123900249-127.0.1.1-59462-1311114108245, blockid: blk_1386529195495096816_1030 [junit] 11/07/19 22:23:08 INFO datanode.DataNode: PacketResponder 0 for block blk_1386529195495096816_1030 terminating [junit] 11/07/19 22:23:08 INFO DataNode.clienttrace: src: /127.0.0.1:56093, dest: /127.0.0.1:60594, bytes: 4499, op: HDFS_WRITE, cliID: DFSClient_1432658130, srvID: DS-1952867002-127.0.1.1-60594-1311114107920, blockid: blk_1386529195495096816_1030 [junit] 11/07/19 22:23:08 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:59462 is added to blk_1386529195495096816_1030 size 4499 [junit] 11/07/19 22:23:08 INFO datanode.DataNode: PacketResponder 1 for block blk_1386529195495096816_1030 terminating [junit] 11/07/19 22:23:08 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:60594 is added to blk_1386529195495096816_1030 size 4499 [junit] 11/07/19 22:23:08 INFO DataNode.clienttrace: src: /127.0.0.1:60259, dest: /127.0.0.1:33629, bytes: 4499, op: HDFS_WRITE, cliID: DFSClient_1432658130, srvID: DS-680992968-127.0.1.1-33629-1311114108557, blockid: blk_1386529195495096816_1030 [junit] 11/07/19 22:23:08 INFO hdfs.StateChange: BLOCK* NameSystem.addStoredBlock: blockMap updated: 127.0.0.1:33629 is added to blk_1386529195495096816_1030 size 4499 [junit] 11/07/19 22:23:08 INFO datanode.DataNode: PacketResponder 2 for block blk_1386529195495096816_1030 terminating [junit] 11/07/19 22:23:08 INFO hdfs.StateChange: DIR* NameSystem.completeFile: file /user/hudson/testGetSchema-output.txt/_logs/history/localhost_1311114108918_job_20110719222148896_0004_hudson_PigLatin%3ADefaultJobName is closed by DFSClient_1432658130 [junit] 11/07/19 22:23:08 INFO mapred.JobTracker: Removed completed task 'attempt_20110719222148896_0004_m_000000_0' from 'tracker_host0.foo.com:localhost/127.0.0.1:36771' [junit] 11/07/19 22:23:08 INFO mapred.JobTracker: Removed completed task 'attempt_20110719222148896_0004_m_000001_0' from 'tracker_host0.foo.com:localhost/127.0.0.1:36771' [junit] 11/07/19 22:23:08 INFO mapred.JobTracker: Removed completed task 'attempt_20110719222148896_0004_m_000002_0' from 'tracker_host0.foo.com:localhost/127.0.0.1:36771' [junit] 11/07/19 22:23:08 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3255239538673879332 is added to invalidSet of 127.0.0.1:33629 [junit] 11/07/19 22:23:08 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3255239538673879332 is added to invalidSet of 127.0.0.1:59462 [junit] 11/07/19 22:23:08 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3255239538673879332 is added to invalidSet of 127.0.0.1:60594 [junit] 11/07/19 22:23:08 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3691618398698760286 is added to invalidSet of 127.0.0.1:33629 [junit] 11/07/19 22:23:08 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3691618398698760286 is added to invalidSet of 127.0.0.1:60594 [junit] 11/07/19 22:23:08 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_3691618398698760286 is added to invalidSet of 127.0.0.1:59462 [junit] 11/07/19 22:23:08 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-43939495645783604 is added to invalidSet of 127.0.0.1:33629 [junit] 11/07/19 22:23:08 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-43939495645783604 is added to invalidSet of 127.0.0.1:60594 [junit] 11/07/19 22:23:08 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_20110719222148896_0004 [junit] 11/07/19 22:23:08 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-43939495645783604 is added to invalidSet of 127.0.0.1:45658 [junit] 11/07/19 22:23:08 INFO mapred.TaskRunner: attempt_20110719222148896_0004_m_000000_0 done; removing files. [junit] 11/07/19 22:23:08 INFO mapred.IndexCache: Map ID attempt_20110719222148896_0004_m_000000_0 not found in cache [junit] 11/07/19 22:23:08 INFO mapred.TaskRunner: attempt_20110719222148896_0004_m_000001_0 done; removing files. [junit] 11/07/19 22:23:08 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/tmp/hadoop-hudson/mapred/system/job_20110719222148896_0004 dst=null perm=null [junit] 11/07/19 22:23:08 INFO mapred.IndexCache: Map ID attempt_20110719222148896_0004_m_000001_0 not found in cache [junit] 11/07/19 22:23:08 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_20110719222148896_0004 [junit] 11/07/19 22:23:08 WARN mapred.TaskTracker: Unknown job job_20110719222148896_0004 being deleted. [junit] 11/07/19 22:23:08 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_20110719222148896_0004 [junit] 11/07/19 22:23:08 WARN mapred.TaskTracker: Unknown job job_20110719222148896_0004 being deleted. [junit] 11/07/19 22:23:08 INFO mapred.TaskTracker: Received 'KillJobAction' for job: job_20110719222148896_0004 [junit] 11/07/19 22:23:08 WARN mapred.TaskTracker: Unknown job job_20110719222148896_0004 being deleted. [junit] 11/07/19 22:23:09 INFO mapReduceLayer.MapReduceLauncher: 100% complete [junit] 11/07/19 22:23:09 INFO pigstats.SimplePigStats: Script Statistics: [junit] [junit] HadoopVersion PigVersion UserId StartedAt FinishedAt Features [junit] 0.20.2 0.10.0-SNAPSHOT hudson 2011-07-19 22:22:50 2011-07-19 22:23:09 UNKNOWN [junit] [junit] Success! [junit] [junit] Job Stats (time in seconds): [junit] JobId Maps Reduces MaxMapTime MinMapTIme AvgMapTime MaxReduceTime MinReduceTime AvgReduceTime Alias Feature Outputs [junit] job_20110719222148896_0004 1 0 6 6 6 0 0 0 a MAP_ONLY hdfs://localhost:57665/user/hudson/testGetSchema-output.txt, [junit] [junit] Input(s): [junit] Successfully read 2 records (24 bytes) from: "hdfs://localhost:57665/user/hudson/testGetSchema-input.txt" [junit] [junit] Output(s): [junit] Successfully stored 2 records (58 bytes) in: "hdfs://localhost:57665/user/hudson/testGetSchema-output.txt" [junit] [junit] Counters: [junit] Total records written : 2 [junit] Total bytes written : 58 [junit] Spillable Memory Manager spill count : 0 [junit] Total bags proactively spilled: 0 [junit] Total records proactively spilled: 0 [junit] [junit] Job DAG: [junit] job_20110719222148896_0004 [junit] [junit] [junit] 11/07/19 22:23:09 INFO mapReduceLayer.MapReduceLauncher: Success! [junit] 11/07/19 22:23:09 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=listStatus src=/user/hudson/testGetSchema-output.txt dst=null perm=null [junit] 11/07/19 22:23:09 INFO input.FileInputFormat: Total input paths to process : 1 [junit] 11/07/19 22:23:09 INFO util.MapRedUtil: Total input paths to process : 1 [junit] 11/07/19 22:23:09 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/user/hudson/testGetSchema-output.txt/part-m-00000 dst=null perm=null [junit] 11/07/19 22:23:09 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=open src=/user/hudson/testGetSchema-output.txt/part-m-00000 dst=null perm=null [junit] 11/07/19 22:23:09 INFO DataNode.clienttrace: src: /127.0.0.1:33629, dest: /127.0.0.1:60263, bytes: 62, op: HDFS_READ, cliID: DFSClient_1432658130, srvID: DS-680992968-127.0.1.1-33629-1311114108557, blockid: blk_-5516961351262348181_1030 [junit] 11/07/19 22:23:09 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8744433927195270917 is added to invalidSet of 127.0.0.1:59462 [junit] 11/07/19 22:23:09 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8744433927195270917 is added to invalidSet of 127.0.0.1:33629 [junit] 11/07/19 22:23:09 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-8744433927195270917 is added to invalidSet of 127.0.0.1:45658 [junit] 11/07/19 22:23:09 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/user/hudson/testGetSchema-input.txt dst=null perm=null [junit] 11/07/19 22:23:09 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_5238096939891008711 is added to invalidSet of 127.0.0.1:45658 [junit] 11/07/19 22:23:09 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_5238096939891008711 is added to invalidSet of 127.0.0.1:59462 [junit] 11/07/19 22:23:09 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_5238096939891008711 is added to invalidSet of 127.0.0.1:33629 [junit] 11/07/19 22:23:09 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_1386529195495096816 is added to invalidSet of 127.0.0.1:59462 [junit] 11/07/19 22:23:09 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_1386529195495096816 is added to invalidSet of 127.0.0.1:60594 [junit] 11/07/19 22:23:09 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_1386529195495096816 is added to invalidSet of 127.0.0.1:33629 [junit] 11/07/19 22:23:09 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-5516961351262348181 is added to invalidSet of 127.0.0.1:60594 [junit] 11/07/19 22:23:09 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-5516961351262348181 is added to invalidSet of 127.0.0.1:33629 [junit] 11/07/19 22:23:09 INFO hdfs.StateChange: BLOCK* NameSystem.addToInvalidates: blk_-5516961351262348181 is added to invalidSet of 127.0.0.1:45658 [junit] 11/07/19 22:23:09 INFO FSNamesystem.audit: ugi=hudson,hudson ip=/127.0.0.1 cmd=delete src=/user/hudson/testGetSchema-output.txt dst=null perm=null [junit] 11/07/19 22:23:09 FATAL conf.Configuration: error parsing conf file: java.io.FileNotFoundException: /homes/hudson/pigtest/conf/hadoop-site.xml (No such file or directory) [junit] Shutting down the Mini HDFS Cluster [junit] Shutting down DataNode 3 [junit] 11/07/19 22:23:09 INFO ipc.Server: Stopping server on 55921 [junit] 11/07/19 22:23:09 INFO ipc.Server: IPC Server handler 0 on 55921: exiting [junit] 11/07/19 22:23:09 INFO ipc.Server: IPC Server handler 2 on 55921: exiting [junit] 11/07/19 22:23:09 INFO ipc.Server: Stopping IPC Server listener on 55921 [junit] 11/07/19 22:23:09 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1 [junit] 11/07/19 22:23:09 INFO ipc.Server: Stopping IPC Server Responder [junit] 11/07/19 22:23:09 INFO ipc.Server: IPC Server handler 1 on 55921: exiting [junit] 11/07/19 22:23:09 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:45658, storageID=DS-1283972493-127.0.1.1-45658-1311114108845, infoPort=37312, ipcPort=55921):DataXceiveServer: java.nio.channels.AsynchronousCloseException [junit] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:185) [junit] at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:159) [junit] at sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:84) [junit] at org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:130) [junit] at java.lang.Thread.run(Thread.java:662) [junit] [junit] 11/07/19 22:23:10 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:59462 to delete blk_3255239538673879332_1025 blk_1386529195495096816_1030 blk_3691618398698760286_1026 blk_-8744433927195270917_1024 blk_5238096939891008711_1029 [junit] 11/07/19 22:23:10 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:45658 to delete blk_-43939495645783604_1027 blk_-5516961351262348181_1030 blk_-8744433927195270917_1024 blk_5238096939891008711_1029 [junit] 11/07/19 22:23:10 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread. [junit] 11/07/19 22:23:10 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0 [junit] 11/07/19 22:23:10 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:45658, storageID=DS-1283972493-127.0.1.1-45658-1311114108845, infoPort=37312, ipcPort=55921):Finishing DataNode in: FSDataset{dirpath='<https://builds.apache.org/job/Pig-trunk-commit/ws/trunk/build/test/data/dfs/data/data7/current,/grid/0/hudson/hudson-slave/workspace/Pig-trunk-commit/trunk/build/test/data/dfs/data/data8/current'}> [junit] 11/07/19 22:23:10 INFO ipc.Server: Stopping server on 55921 [junit] 11/07/19 22:23:10 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0 [junit] Shutting down DataNode 2 [junit] 11/07/19 22:23:11 INFO ipc.Server: Stopping server on 48364 [junit] 11/07/19 22:23:11 INFO ipc.Server: IPC Server handler 0 on 48364: exiting [junit] 11/07/19 22:23:11 INFO ipc.Server: IPC Server handler 1 on 48364: exiting [junit] 11/07/19 22:23:11 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1 [junit] 11/07/19 22:23:11 INFO ipc.Server: Stopping IPC Server Responder [junit] 11/07/19 22:23:11 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:33629, storageID=DS-680992968-127.0.1.1-33629-1311114108557, infoPort=55418, ipcPort=48364):DataXceiveServer: java.nio.channels.AsynchronousCloseException [junit] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:185) [junit] at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:159) [junit] at sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:84) [junit] at org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:130) [junit] at java.lang.Thread.run(Thread.java:662) [junit] [junit] 11/07/19 22:23:11 INFO ipc.Server: IPC Server handler 2 on 48364: exiting [junit] 11/07/19 22:23:11 INFO ipc.Server: Stopping IPC Server listener on 48364 [junit] 11/07/19 22:23:11 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread. [junit] 11/07/19 22:23:12 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0 [junit] 11/07/19 22:23:12 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:33629, storageID=DS-680992968-127.0.1.1-33629-1311114108557, infoPort=55418, ipcPort=48364):Finishing DataNode in: FSDataset{dirpath='<https://builds.apache.org/job/Pig-trunk-commit/ws/trunk/build/test/data/dfs/data/data5/current,/grid/0/hudson/hudson-slave/workspace/Pig-trunk-commit/trunk/build/test/data/dfs/data/data6/current'}> [junit] 11/07/19 22:23:12 INFO ipc.Server: Stopping server on 48364 [junit] 11/07/19 22:23:12 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0 [junit] Shutting down DataNode 1 [junit] 11/07/19 22:23:12 INFO ipc.Server: Stopping server on 38755 [junit] 11/07/19 22:23:12 INFO ipc.Server: IPC Server handler 0 on 38755: exiting [junit] 11/07/19 22:23:12 INFO ipc.Server: IPC Server handler 1 on 38755: exiting [junit] 11/07/19 22:23:12 INFO ipc.Server: IPC Server handler 2 on 38755: exiting [junit] 11/07/19 22:23:12 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1 [junit] 11/07/19 22:23:12 INFO ipc.Server: Stopping IPC Server listener on 38755 [junit] 11/07/19 22:23:12 INFO ipc.Server: Stopping IPC Server Responder [junit] 11/07/19 22:23:12 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:59462, storageID=DS-123900249-127.0.1.1-59462-1311114108245, infoPort=50189, ipcPort=38755):DataXceiveServer: java.nio.channels.AsynchronousCloseException [junit] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:185) [junit] at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:159) [junit] at sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:84) [junit] at org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:130) [junit] at java.lang.Thread.run(Thread.java:662) [junit] [junit] 11/07/19 22:23:12 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread. [junit] 11/07/19 22:23:12 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:59462, storageID=DS-123900249-127.0.1.1-59462-1311114108245, infoPort=50189, ipcPort=38755):Finishing DataNode in: FSDataset{dirpath='<https://builds.apache.org/job/Pig-trunk-commit/ws/trunk/build/test/data/dfs/data/data3/current,/grid/0/hudson/hudson-slave/workspace/Pig-trunk-commit/trunk/build/test/data/dfs/data/data4/current'}> [junit] 11/07/19 22:23:12 INFO ipc.Server: Stopping server on 38755 [junit] 11/07/19 22:23:12 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0 [junit] 11/07/19 22:23:13 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0 [junit] Shutting down DataNode 0 [junit] 11/07/19 22:23:13 INFO ipc.Server: Stopping server on 36479 [junit] 11/07/19 22:23:13 INFO ipc.Server: IPC Server handler 2 on 36479: exiting [junit] 11/07/19 22:23:13 INFO ipc.Server: Stopping IPC Server listener on 36479 [junit] 11/07/19 22:23:13 INFO ipc.Server: Stopping IPC Server Responder [junit] 11/07/19 22:23:13 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:60594, storageID=DS-1952867002-127.0.1.1-60594-1311114107920, infoPort=43005, ipcPort=36479):DataXceiveServer: java.nio.channels.AsynchronousCloseException [junit] at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:185) [junit] at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:159) [junit] at sun.nio.ch.ServerSocketAdaptor.accept(ServerSocketAdaptor.java:84) [junit] at org.apache.hadoop.hdfs.server.datanode.DataXceiverServer.run(DataXceiverServer.java:130) [junit] at java.lang.Thread.run(Thread.java:662) [junit] [junit] 11/07/19 22:23:13 INFO ipc.Server: IPC Server handler 1 on 36479: exiting [junit] 11/07/19 22:23:13 INFO ipc.Server: IPC Server handler 0 on 36479: exiting [junit] 11/07/19 22:23:13 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1 [junit] 11/07/19 22:23:13 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread. [junit] 11/07/19 22:23:13 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:60594, storageID=DS-1952867002-127.0.1.1-60594-1311114107920, infoPort=43005, ipcPort=36479):Finishing DataNode in: FSDataset{dirpath='<https://builds.apache.org/job/Pig-trunk-commit/ws/trunk/build/test/data/dfs/data/data1/current,/grid/0/hudson/hudson-slave/workspace/Pig-trunk-commit/trunk/build/test/data/dfs/data/data2/current'}> [junit] 11/07/19 22:23:13 INFO ipc.Server: Stopping server on 36479 [junit] 11/07/19 22:23:13 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0 [junit] 11/07/19 22:23:13 WARN namenode.FSNamesystem: ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted [junit] 11/07/19 22:23:13 INFO namenode.DecommissionManager: Interrupted Monitor [junit] java.lang.InterruptedException: sleep interrupted [junit] at java.lang.Thread.sleep(Native Method) [junit] at org.apache.hadoop.hdfs.server.namenode.DecommissionManager$Monitor.run(DecommissionManager.java:65) [junit] at java.lang.Thread.run(Thread.java:662) [junit] 11/07/19 22:23:13 INFO namenode.FSNamesystem: Number of transactions: 167 Total time for transactions(ms): 2Number of transactions batched in Syncs: 13 Number of syncs: 119 SyncTimes(ms): 1972 956 [junit] 11/07/19 22:23:13 INFO ipc.Server: Stopping server on 57665 [junit] 11/07/19 22:23:13 INFO ipc.Server: IPC Server handler 0 on 57665: exiting [junit] 11/07/19 22:23:13 INFO ipc.Server: Stopping IPC Server listener on 57665 [junit] 11/07/19 22:23:13 INFO ipc.Server: IPC Server handler 4 on 57665: exiting [junit] 11/07/19 22:23:13 INFO ipc.Server: IPC Server handler 2 on 57665: exiting [junit] 11/07/19 22:23:13 INFO ipc.Server: IPC Server handler 3 on 57665: exiting [junit] 11/07/19 22:23:13 INFO ipc.Server: IPC Server handler 1 on 57665: exiting [junit] 11/07/19 22:23:13 INFO ipc.Server: Stopping IPC Server Responder [junit] 11/07/19 22:23:13 INFO ipc.Server: IPC Server handler 6 on 57665: exiting [junit] 11/07/19 22:23:13 INFO ipc.Server: IPC Server handler 7 on 57665: exiting [junit] 11/07/19 22:23:13 INFO ipc.Server: IPC Server handler 9 on 57665: exiting [junit] 11/07/19 22:23:13 INFO ipc.Server: IPC Server handler 5 on 57665: exiting [junit] 11/07/19 22:23:13 INFO ipc.Server: IPC Server handler 8 on 57665: exiting [junit] Tests run: 17, Failures: 0, Errors: 22, Time elapsed: 82.22 sec [junit] Test org.apache.pig.test.TestStore FAILED [junit] Running org.apache.pig.test.TestStringUDFs [junit] 11/07/19 22:23:14 WARN builtin.SUBSTRING: java.lang.NullPointerException [junit] 11/07/19 22:23:14 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2 [junit] 11/07/19 22:23:14 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -1 [junit] 11/07/19 22:23:14 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -8 [junit] 11/07/19 22:23:14 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2 [junit] 11/07/19 22:23:14 WARN builtin.INDEXOF: Failed to process input; error - null [junit] 11/07/19 22:23:14 WARN builtin.LAST_INDEX_OF: Failed to process input; error - null [junit] Tests run: 11, Failures: 0, Errors: 0, Time elapsed: 0.121 sec [delete] Deleting directory /tmp/pig_junit_tmp399133850 BUILD FAILED <https://builds.apache.org/job/Pig-trunk-commit/ws/trunk/build.xml>:664: The following error occurred while executing this line: <https://builds.apache.org/job/Pig-trunk-commit/ws/trunk/build.xml>:719: Tests failed! Total time: 15 minutes 28 seconds [FINDBUGS] Skipping publisher since build result is FAILURE Recording test results Publishing Javadoc Archiving artifacts Recording fingerprints Publishing Clover coverage report... No Clover report will be published due to a Build Failure