You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@pig.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2011/07/19 02:29:04 UTC
Build failed in Jenkins: Pig-trunk-commit #861
See <https://builds.apache.org/job/Pig-trunk-commit/861/changes>
Changes:
[daijy] PIG-2159: New logical plan uses incorrect class for SUM causing for ClassCastException
------------------------------------------
[...truncated 40200 lines...]
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit] 11/07/19 00:28:53 ERROR hdfs.DFSClient: Exception closing file /tmp/TestStore-output--8196176233331618344.txt_cleanupOnFailure_succeeded2 : org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output--8196176233331618344.txt_cleanupOnFailure_succeeded2 by DFSClient_1268025084
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output--8196176233331618344.txt_cleanupOnFailure_succeeded2 by DFSClient_1268025084
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] at org.apache.hadoop.ipc.Client.call(Client.java:740)
[junit] at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:3264)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.close(DFSClient.java:3188)
[junit] at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.close(DFSClient.java:1043)
[junit] at org.apache.hadoop.hdfs.DFSClient.close(DFSClient.java:237)
[junit] at org.apache.hadoop.hdfs.DistributedFileSystem.close(DistributedFileSystem.java:269)
[junit] at org.apache.pig.test.MiniCluster.shutdownMiniDfsAndMrClusters(MiniCluster.java:111)
[junit] at org.apache.pig.test.MiniCluster.shutDown(MiniCluster.java:101)
[junit] at org.apache.pig.test.TestStore.oneTimeTearDown(TestStore.java:127)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
[junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
[junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
[junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
[junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
[junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 3
[junit] 11/07/19 00:28:53 INFO ipc.Server: Stopping server on 50954
[junit] 11/07/19 00:28:53 INFO ipc.Server: IPC Server handler 0 on 50954: exiting
[junit] 11/07/19 00:28:53 INFO ipc.Server: IPC Server handler 2 on 50954: exiting
[junit] 11/07/19 00:28:53 INFO ipc.Server: IPC Server handler 1 on 50954: exiting
[junit] 11/07/19 00:28:53 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/19 00:28:53 INFO ipc.Server: Stopping IPC Server listener on 50954
[junit] 11/07/19 00:28:53 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:39274, storageID=DS-773078572-127.0.1.1-39274-1311034971852, infoPort=60635, ipcPort=50954):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 00:28:53 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/19 00:28:53 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/19 00:28:53 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:39274, storageID=DS-773078572-127.0.1.1-39274-1311034971852, infoPort=60635, ipcPort=50954):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 00:28:53 INFO ipc.Server: Stopping server on 50954
[junit] 11/07/19 00:28:53 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 2
[junit] 11/07/19 00:28:53 INFO ipc.Server: Stopping server on 54914
[junit] 11/07/19 00:28:53 INFO ipc.Server: IPC Server handler 0 on 54914: exiting
[junit] 11/07/19 00:28:53 INFO ipc.Server: Stopping IPC Server listener on 54914
[junit] 11/07/19 00:28:53 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/19 00:28:53 INFO ipc.Server: IPC Server handler 1 on 54914: exiting
[junit] 11/07/19 00:28:53 INFO ipc.Server: IPC Server handler 2 on 54914: exiting
[junit] 11/07/19 00:28:53 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:57774, storageID=DS-1537032945-127.0.1.1-57774-1311034971538, infoPort=48988, ipcPort=54914):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 00:28:53 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/19 00:28:53 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/19 00:28:53 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:57774, storageID=DS-1537032945-127.0.1.1-57774-1311034971538, infoPort=48988, ipcPort=54914):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 00:28:53 INFO ipc.Server: Stopping server on 54914
[junit] 11/07/19 00:28:54 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 1
[junit] 11/07/19 00:28:54 INFO ipc.Server: Stopping server on 46027
[junit] 11/07/19 00:28:54 INFO ipc.Server: IPC Server handler 0 on 46027: exiting
[junit] 11/07/19 00:28:54 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/19 00:28:54 INFO ipc.Server: IPC Server handler 1 on 46027: exiting
[junit] 11/07/19 00:28:54 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:52896, storageID=DS-431270005-127.0.1.1-52896-1311034971237, infoPort=58195, ipcPort=46027):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 00:28:54 INFO ipc.Server: Stopping IPC Server listener on 46027
[junit] 11/07/19 00:28:54 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/19 00:28:54 INFO ipc.Server: IPC Server handler 2 on 46027: exiting
[junit] 11/07/19 00:28:54 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/19 00:28:54 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:52896, storageID=DS-431270005-127.0.1.1-52896-1311034971237, infoPort=58195, ipcPort=46027):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 00:28:54 INFO ipc.Server: Stopping server on 46027
[junit] 11/07/19 00:28:54 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 0
[junit] 11/07/19 00:28:54 INFO ipc.Server: Stopping server on 46663
[junit] 11/07/19 00:28:54 INFO ipc.Server: IPC Server handler 0 on 46663: exiting
[junit] 11/07/19 00:28:54 INFO ipc.Server: Stopping IPC Server listener on 46663
[junit] 11/07/19 00:28:54 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/19 00:28:54 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/19 00:28:54 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:34695, storageID=DS-970742581-127.0.1.1-34695-1311034970911, infoPort=49208, ipcPort=46663):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 00:28:54 INFO ipc.Server: IPC Server handler 1 on 46663: exiting
[junit] 11/07/19 00:28:54 INFO ipc.Server: IPC Server handler 2 on 46663: exiting
[junit] 11/07/19 00:28:54 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/19 00:28:55 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/19 00:28:55 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:34695, storageID=DS-970742581-127.0.1.1-34695-1311034970911, infoPort=49208, ipcPort=46663):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 00:28:55 INFO ipc.Server: Stopping server on 46663
[junit] 11/07/19 00:28:55 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/19 00:28:55 INFO namenode.FSNamesystem: Number of transactions: 694 Total time for transactions(ms): 7Number of transactions batched in Syncs: 114 Number of syncs: 484 SyncTimes(ms): 5736 1167
[junit] 11/07/19 00:28:55 WARN namenode.FSNamesystem: ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] 11/07/19 00:28:55 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 00:28:55 INFO ipc.Server: Stopping server on 41693
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping IPC Server listener on 41693
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 0 on 41693: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 2 on 41693: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 9 on 41693: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 8 on 41693: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 4 on 41693: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 1 on 41693: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 3 on 41693: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 5 on 41693: exiting
[junit] 11/07/19 00:28:55 INFO mapred.TaskTracker: Shutting down: Map-events fetcher for all reduce tasks on tracker_host0.foo.com:localhost/127.0.0.1:43822
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 6 on 41693: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 7 on 41693: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping server on 43822
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 0 on 43822: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 1 on 43822: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 3 on 43822: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 2 on 43822: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping IPC Server listener on 43822
[junit] 11/07/19 00:28:55 INFO mapred.TaskTracker: Shutting down StatusHttpServer
[junit] 11/07/19 00:28:55 INFO mapred.TaskTracker: Interrupted. Closing down.
[junit] 11/07/19 00:28:55 INFO mapred.TaskTracker: Shutting down: Map-events fetcher for all reduce tasks on tracker_host1.foo.com:localhost/127.0.0.1:37438
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping server on 37438
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 0 on 37438: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping IPC Server listener on 37438
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 3 on 37438: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 1 on 37438: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 2 on 37438: exiting
[junit] 11/07/19 00:28:55 INFO mapred.TaskTracker: Shutting down StatusHttpServer
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/19 00:28:55 INFO mapred.TaskTracker: Interrupted. Closing down.
[junit] 11/07/19 00:28:55 INFO mapred.TaskTracker: Shutting down: Map-events fetcher for all reduce tasks on tracker_host2.foo.com:localhost/127.0.0.1:51397
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping server on 51397
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 0 on 51397: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping IPC Server listener on 51397
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 3 on 51397: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 2 on 51397: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 1 on 51397: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/19 00:28:55 INFO mapred.TaskTracker: Shutting down StatusHttpServer
[junit] 11/07/19 00:28:55 INFO mapred.TaskTracker: Interrupted. Closing down.
[junit] 11/07/19 00:28:55 INFO mapred.TaskTracker: Shutting down: Map-events fetcher for all reduce tasks on tracker_host3.foo.com:localhost/127.0.0.1:36703
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping server on 36703
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 0 on 36703: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 1 on 36703: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping IPC Server listener on 36703
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/19 00:28:55 INFO mapred.TaskTracker: Shutting down StatusHttpServer
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 2 on 36703: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 3 on 36703: exiting
[junit] 11/07/19 00:28:55 INFO mapred.TaskTracker: Interrupted. Closing down.
[junit] 11/07/19 00:28:55 INFO mapred.JobTracker: Stopping infoServer
[junit] 11/07/19 00:28:55 INFO mapred.JobTracker: Stopping interTrackerServer
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping server on 54817
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 0 on 54817: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping IPC Server listener on 54817
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 3 on 54817: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 4 on 54817: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 2 on 54817: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 6 on 54817: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 7 on 54817: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 9 on 54817: exiting
[junit] 11/07/19 00:28:55 INFO mapred.JobTracker: Stopping expireTrackers
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 8 on 54817: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 1 on 54817: exiting
[junit] 11/07/19 00:28:55 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/19 00:28:55 INFO mapred.JobTracker: Stopping retirer
[junit] 11/07/19 00:28:55 INFO ipc.Server: IPC Server handler 5 on 54817: exiting
[junit] 11/07/19 00:28:55 INFO mapred.JobTracker: Stopped interTrackerServer
[junit] 11/07/19 00:28:55 INFO mapred.EagerTaskInitializationListener: Stopping Job Init Manager thread
[junit] 11/07/19 00:28:55 INFO mapred.EagerTaskInitializationListener: JobInitManagerThread interrupted.
[junit] 11/07/19 00:28:55 INFO mapred.EagerTaskInitializationListener: Shutting down thread pool
[junit] 11/07/19 00:28:55 INFO mapred.JobTracker: Stopping expireLaunchingTasks
[junit] 11/07/19 00:28:55 INFO mapred.JobTracker: stopped all jobtracker services
[junit] Tests run: 17, Failures: 0, Errors: 0, Time elapsed: 361.584 sec
[junit] Running org.apache.pig.test.TestStringUDFs
[junit] 11/07/19 00:28:56 WARN builtin.SUBSTRING: java.lang.NullPointerException
[junit] 11/07/19 00:28:56 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2
[junit] 11/07/19 00:28:56 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -1
[junit] 11/07/19 00:28:56 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -8
[junit] 11/07/19 00:28:56 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2
[junit] 11/07/19 00:28:56 WARN builtin.INDEXOF: Failed to process input; error - null
[junit] 11/07/19 00:28:56 WARN builtin.LAST_INDEX_OF: Failed to process input; error - null
[junit] Tests run: 11, Failures: 0, Errors: 0, Time elapsed: 0.116 sec
[delete] Deleting directory /tmp/pig_junit_tmp1637847269
BUILD FAILED
<https://builds.apache.org/job/Pig-trunk-commit/ws/trunk/build.xml>:652: The following error occurred while executing this line:
<https://builds.apache.org/job/Pig-trunk-commit/ws/trunk/build.xml>:707: Tests failed!
Total time: 21 minutes 12 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
Jenkins build is back to normal : Pig-trunk-commit #869
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Pig-trunk-commit/869/changes>
Build failed in Jenkins: Pig-trunk-commit #868
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Pig-trunk-commit/868/changes>
Changes:
[thejas] fix import in testcase added as part of - PIG-2146: POStore.getSchema() returns null because of which PigOutputCommitter
is not storing schema while cleanup
------------------------------------------
[...truncated 39692 lines...]
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] at org.apache.hadoop.ipc.Client.call(Client.java:740)
[junit] at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:3264)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.close(DFSClient.java:3188)
[junit] at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.close(DFSClient.java:1043)
[junit] at org.apache.hadoop.hdfs.DFSClient.close(DFSClient.java:237)
[junit] at org.apache.hadoop.hdfs.DistributedFileSystem.close(DistributedFileSystem.java:269)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsClusters(MiniGenericCluster.java:83)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsAndMrClusters(MiniGenericCluster.java:77)
[junit] at org.apache.pig.test.MiniGenericCluster.shutDown(MiniGenericCluster.java:68)
[junit] at org.apache.pig.test.TestStore.oneTimeTearDown(TestStore.java:127)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
[junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
[junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
[junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
[junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
[junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
[junit] 11/07/21 02:23:43 WARN hdfs.StateChange: DIR* NameSystem.completeFile: failed to complete /tmp/TestStore-output-1881025561287049326.txt_cleanupOnFailure_succeeded because dir.getFileBlocks() is null and pendingFile is null
[junit] 11/07/21 02:23:43 INFO ipc.Server: IPC Server handler 7 on 37270, call complete(/tmp/TestStore-output-1881025561287049326.txt_cleanupOnFailure_succeeded, DFSClient_492464520) from 127.0.0.1:34834: error: java.io.IOException: Could not complete write to file /tmp/TestStore-output-1881025561287049326.txt_cleanupOnFailure_succeeded by DFSClient_492464520
[junit] java.io.IOException: Could not complete write to file /tmp/TestStore-output-1881025561287049326.txt_cleanupOnFailure_succeeded by DFSClient_492464520
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit] 11/07/21 02:23:43 ERROR hdfs.DFSClient: Exception closing file /tmp/TestStore-output-1881025561287049326.txt_cleanupOnFailure_succeeded : org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output-1881025561287049326.txt_cleanupOnFailure_succeeded by DFSClient_492464520
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output-1881025561287049326.txt_cleanupOnFailure_succeeded by DFSClient_492464520
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] at org.apache.hadoop.ipc.Client.call(Client.java:740)
[junit] at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:3264)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.close(DFSClient.java:3188)
[junit] at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.close(DFSClient.java:1043)
[junit] at org.apache.hadoop.hdfs.DFSClient.close(DFSClient.java:237)
[junit] at org.apache.hadoop.hdfs.DistributedFileSystem.close(DistributedFileSystem.java:269)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsClusters(MiniGenericCluster.java:83)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsAndMrClusters(MiniGenericCluster.java:77)
[junit] at org.apache.pig.test.MiniGenericCluster.shutDown(MiniGenericCluster.java:68)
[junit] at org.apache.pig.test.TestStore.oneTimeTearDown(TestStore.java:127)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
[junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
[junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
[junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
[junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
[junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 3
[junit] 11/07/21 02:23:43 INFO ipc.Server: Stopping server on 40620
[junit] 11/07/21 02:23:43 INFO ipc.Server: Stopping IPC Server listener on 40620
[junit] 11/07/21 02:23:43 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/21 02:23:43 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/21 02:23:43 INFO ipc.Server: IPC Server handler 1 on 40620: exiting
[junit] 11/07/21 02:23:43 INFO ipc.Server: IPC Server handler 2 on 40620: exiting
[junit] 11/07/21 02:23:43 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:44546, storageID=DS-315745557-127.0.1.1-44546-1311214653834, infoPort=56124, ipcPort=40620):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/21 02:23:43 INFO ipc.Server: IPC Server handler 0 on 40620: exiting
[junit] 11/07/21 02:23:43 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:42768 to delete blk_-1729953649775561754_1127 blk_5366304699694942645_1123 blk_-1516394721850560862_1124 blk_-2581817329938677680_1122
[junit] 11/07/21 02:23:43 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:46974 to delete blk_-1729953649775561754_1127 blk_5366304699694942645_1123 blk_-3429364585100481170_1126 blk_-1516394721850560862_1124 blk_-3572013218284291470_1121 blk_-2581817329938677680_1122
[junit] 11/07/21 02:23:43 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/21 02:23:44 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/21 02:23:44 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:44546, storageID=DS-315745557-127.0.1.1-44546-1311214653834, infoPort=56124, ipcPort=40620):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/21 02:23:44 INFO ipc.Server: Stopping server on 40620
[junit] 11/07/21 02:23:44 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 2
[junit] 11/07/21 02:23:44 INFO ipc.Server: Stopping server on 40850
[junit] 11/07/21 02:23:44 INFO ipc.Server: Stopping IPC Server listener on 40850
[junit] 11/07/21 02:23:44 INFO ipc.Server: IPC Server handler 0 on 40850: exiting
[junit] 11/07/21 02:23:44 INFO ipc.Server: IPC Server handler 1 on 40850: exiting
[junit] 11/07/21 02:23:44 INFO ipc.Server: IPC Server handler 2 on 40850: exiting
[junit] 11/07/21 02:23:44 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/21 02:23:44 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/21 02:23:44 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:60345, storageID=DS-361767735-127.0.1.1-60345-1311214653504, infoPort=45852, ipcPort=40850):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/21 02:23:44 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/21 02:23:45 WARN datanode.DataNode: Unexpected error trying to delete block blk_-2581817329938677680_1122. BlockInfo not found in volumeMap.
[junit] 11/07/21 02:23:45 INFO datanode.DataNode: Deleting block blk_-1729953649775561754_1127 file build/test/data/dfs/data/data1/current/blk_-1729953649775561754
[junit] 11/07/21 02:23:45 INFO datanode.DataNode: Deleting block blk_-1516394721850560862_1124 file build/test/data/dfs/data/data2/current/blk_-1516394721850560862
[junit] 11/07/21 02:23:45 INFO datanode.DataNode: Deleting block blk_5366304699694942645_1123 file build/test/data/dfs/data/data1/current/blk_5366304699694942645
[junit] 11/07/21 02:23:45 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:662)
[junit] 11/07/21 02:23:45 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/21 02:23:45 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:60345, storageID=DS-361767735-127.0.1.1-60345-1311214653504, infoPort=45852, ipcPort=40850):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/21 02:23:45 INFO ipc.Server: Stopping server on 40850
[junit] 11/07/21 02:23:45 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 1
[junit] 11/07/21 02:23:45 INFO ipc.Server: Stopping server on 37532
[junit] 11/07/21 02:23:45 INFO ipc.Server: IPC Server handler 0 on 37532: exiting
[junit] 11/07/21 02:23:45 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/21 02:23:45 INFO ipc.Server: Stopping IPC Server listener on 37532
[junit] 11/07/21 02:23:45 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:46974, storageID=DS-1998064875-127.0.1.1-46974-1311214653186, infoPort=50848, ipcPort=37532):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/21 02:23:45 INFO ipc.Server: IPC Server handler 1 on 37532: exiting
[junit] 11/07/21 02:23:45 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/21 02:23:45 INFO ipc.Server: IPC Server handler 2 on 37532: exiting
[junit] 11/07/21 02:23:45 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/21 02:23:45 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:46974, storageID=DS-1998064875-127.0.1.1-46974-1311214653186, infoPort=50848, ipcPort=37532):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/21 02:23:45 INFO ipc.Server: Stopping server on 37532
[junit] 11/07/21 02:23:45 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 0
[junit] 11/07/21 02:23:46 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/21 02:23:46 INFO ipc.Server: Stopping server on 49205
[junit] 11/07/21 02:23:46 INFO ipc.Server: IPC Server handler 0 on 49205: exiting
[junit] 11/07/21 02:23:46 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/21 02:23:46 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/21 02:23:46 INFO ipc.Server: IPC Server handler 2 on 49205: exiting
[junit] 11/07/21 02:23:46 INFO ipc.Server: IPC Server handler 1 on 49205: exiting
[junit] 11/07/21 02:23:46 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:42768, storageID=DS-1912636143-127.0.1.1-42768-1311214652854, infoPort=55694, ipcPort=49205):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/21 02:23:46 INFO ipc.Server: Stopping IPC Server listener on 49205
[junit] 11/07/21 02:23:46 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:44546 to delete blk_5366304699694942645_1123 blk_-3429364585100481170_1126 blk_-3572013218284291470_1121 blk_-2581817329938677680_1122
[junit] 11/07/21 02:23:46 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:60345 to delete blk_-1729953649775561754_1127 blk_-3429364585100481170_1126 blk_-1516394721850560862_1124 blk_-3572013218284291470_1121
[junit] 11/07/21 02:23:46 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/21 02:23:47 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/21 02:23:47 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:42768, storageID=DS-1912636143-127.0.1.1-42768-1311214652854, infoPort=55694, ipcPort=49205):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/21 02:23:47 INFO ipc.Server: Stopping server on 49205
[junit] 11/07/21 02:23:47 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/21 02:23:47 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/21 02:23:47 INFO namenode.FSNamesystem: Number of transactions: 694 Total time for transactions(ms): 19Number of transactions batched in Syncs: 115 Number of syncs: 484 SyncTimes(ms): 6647 1055
[junit] 11/07/21 02:23:47 WARN namenode.FSNamesystem: ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] 11/07/21 02:23:47 INFO ipc.Server: Stopping server on 37270
[junit] 11/07/21 02:23:47 INFO ipc.Server: Stopping IPC Server listener on 37270
[junit] 11/07/21 02:23:47 INFO ipc.Server: IPC Server handler 2 on 37270: exiting
[junit] 11/07/21 02:23:47 INFO ipc.Server: IPC Server handler 7 on 37270: exiting
[junit] 11/07/21 02:23:47 INFO ipc.Server: IPC Server handler 8 on 37270: exiting
[junit] 11/07/21 02:23:47 INFO ipc.Server: IPC Server handler 4 on 37270: exiting
[junit] 11/07/21 02:23:47 INFO ipc.Server: IPC Server handler 0 on 37270: exiting
[junit] 11/07/21 02:23:47 INFO ipc.Server: IPC Server handler 6 on 37270: exiting
[junit] 11/07/21 02:23:47 INFO ipc.Server: IPC Server handler 9 on 37270: exiting
[junit] 11/07/21 02:23:47 INFO ipc.Server: IPC Server handler 3 on 37270: exiting
[junit] 11/07/21 02:23:47 INFO ipc.Server: IPC Server handler 1 on 37270: exiting
[junit] 11/07/21 02:23:47 INFO ipc.Server: IPC Server handler 5 on 37270: exiting
[junit] Tests run: 17, Failures: 0, Errors: 0, Time elapsed: 370.154 sec
[junit] 11/07/21 02:23:47 INFO ipc.Server: Stopping IPC Server Responder
[junit] Running org.apache.pig.test.TestStringUDFs
[junit] 11/07/21 02:23:48 WARN builtin.SUBSTRING: java.lang.NullPointerException
[junit] 11/07/21 02:23:48 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2
[junit] 11/07/21 02:23:48 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -1
[junit] 11/07/21 02:23:48 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -8
[junit] 11/07/21 02:23:48 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2
[junit] 11/07/21 02:23:48 WARN builtin.INDEXOF: Failed to process input; error - null
[junit] 11/07/21 02:23:48 WARN builtin.LAST_INDEX_OF: Failed to process input; error - null
[junit] Tests run: 11, Failures: 0, Errors: 0, Time elapsed: 0.106 sec
[delete] Deleting directory /tmp/pig_junit_tmp102120422
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: 21 minutes 27 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
Build failed in Jenkins: Pig-trunk-commit #867
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Pig-trunk-commit/867/changes>
Changes:
[daijy] PIG-2125: Make Pig work with hadoop .NEXT (PIG-2125-5.patch)
------------------------------------------
[...truncated 39623 lines...]
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output--809804008553611944.txt_cleanupOnFailure_succeeded2 by DFSClient_-700297148
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] at org.apache.hadoop.ipc.Client.call(Client.java:740)
[junit] at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:3264)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.close(DFSClient.java:3188)
[junit] at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.close(DFSClient.java:1043)
[junit] at org.apache.hadoop.hdfs.DFSClient.close(DFSClient.java:237)
[junit] at org.apache.hadoop.hdfs.DistributedFileSystem.close(DistributedFileSystem.java:269)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsClusters(MiniGenericCluster.java:83)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsAndMrClusters(MiniGenericCluster.java:77)
[junit] at org.apache.pig.test.MiniGenericCluster.shutDown(MiniGenericCluster.java:68)
[junit] at org.apache.pig.test.TestStore.oneTimeTearDown(TestStore.java:127)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
[junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
[junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
[junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
[junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
[junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
[junit] 11/07/21 01:29:12 WARN hdfs.StateChange: DIR* NameSystem.completeFile: failed to complete /tmp/TestStore-output-4697537299435714937.txt_cleanupOnFailure_succeeded because dir.getFileBlocks() is null and pendingFile is null
[junit] 11/07/21 01:29:12 INFO ipc.Server: IPC Server handler 8 on 57699, call complete(/tmp/TestStore-output-4697537299435714937.txt_cleanupOnFailure_succeeded, DFSClient_-700297148) from 127.0.0.1:35943: error: java.io.IOException: Could not complete write to file /tmp/TestStore-output-4697537299435714937.txt_cleanupOnFailure_succeeded by DFSClient_-700297148
[junit] java.io.IOException: Could not complete write to file /tmp/TestStore-output-4697537299435714937.txt_cleanupOnFailure_succeeded by DFSClient_-700297148
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit] 11/07/21 01:29:12 ERROR hdfs.DFSClient: Exception closing file /tmp/TestStore-output-4697537299435714937.txt_cleanupOnFailure_succeeded : org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output-4697537299435714937.txt_cleanupOnFailure_succeeded by DFSClient_-700297148
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output-4697537299435714937.txt_cleanupOnFailure_succeeded by DFSClient_-700297148
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] at org.apache.hadoop.ipc.Client.call(Client.java:740)
[junit] at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:3264)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.close(DFSClient.java:3188)
[junit] at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.close(DFSClient.java:1043)
[junit] at org.apache.hadoop.hdfs.DFSClient.close(DFSClient.java:237)
[junit] at org.apache.hadoop.hdfs.DistributedFileSystem.close(DistributedFileSystem.java:269)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsClusters(MiniGenericCluster.java:83)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsAndMrClusters(MiniGenericCluster.java:77)
[junit] at org.apache.pig.test.MiniGenericCluster.shutDown(MiniGenericCluster.java:68)
[junit] at org.apache.pig.test.TestStore.oneTimeTearDown(TestStore.java:127)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
[junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
[junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
[junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
[junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
[junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 3
[junit] 11/07/21 01:29:12 INFO ipc.Server: Stopping server on 44010
[junit] 11/07/21 01:29:12 INFO ipc.Server: IPC Server handler 0 on 44010: exiting
[junit] 11/07/21 01:29:12 INFO ipc.Server: Stopping IPC Server listener on 44010
[junit] 11/07/21 01:29:12 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/21 01:29:12 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/21 01:29:12 INFO ipc.Server: IPC Server handler 2 on 44010: exiting
[junit] 11/07/21 01:29:12 INFO ipc.Server: IPC Server handler 1 on 44010: exiting
[junit] 11/07/21 01:29:12 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:43159, storageID=DS-1656991554-127.0.1.1-43159-1311211385251, infoPort=43351, ipcPort=44010):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/21 01:29:13 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/21 01:29:13 INFO datanode.DataNode: Deleting block blk_1093319556596601540_1122 file build/test/data/dfs/data/data1/current/blk_1093319556596601540
[junit] 11/07/21 01:29:13 INFO datanode.DataNode: Deleting block blk_5260921591736181723_1123 file build/test/data/dfs/data/data2/current/blk_5260921591736181723
[junit] 11/07/21 01:29:13 INFO datanode.DataNode: Deleting block blk_5531389280537799325_1124 file build/test/data/dfs/data/data1/current/blk_5531389280537799325
[junit] 11/07/21 01:29:13 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/21 01:29:13 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:43159, storageID=DS-1656991554-127.0.1.1-43159-1311211385251, infoPort=43351, ipcPort=44010):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/21 01:29:13 INFO ipc.Server: Stopping server on 44010
[junit] 11/07/21 01:29:13 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 2
[junit] 11/07/21 01:29:13 INFO ipc.Server: Stopping server on 60715
[junit] 11/07/21 01:29:13 INFO ipc.Server: IPC Server handler 0 on 60715: exiting
[junit] 11/07/21 01:29:13 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/21 01:29:13 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/21 01:29:13 INFO ipc.Server: Stopping IPC Server listener on 60715
[junit] 11/07/21 01:29:13 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:40027, storageID=DS-1727606284-127.0.1.1-40027-1311211384948, infoPort=45050, ipcPort=60715):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/21 01:29:13 INFO ipc.Server: IPC Server handler 1 on 60715: exiting
[junit] 11/07/21 01:29:13 INFO ipc.Server: IPC Server handler 2 on 60715: exiting
[junit] 11/07/21 01:29:13 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/21 01:29:14 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:40027, storageID=DS-1727606284-127.0.1.1-40027-1311211384948, infoPort=45050, ipcPort=60715):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/21 01:29:14 INFO ipc.Server: Stopping server on 60715
[junit] 11/07/21 01:29:14 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 1
[junit] 11/07/21 01:29:14 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/21 01:29:14 INFO ipc.Server: Stopping server on 36825
[junit] 11/07/21 01:29:14 INFO ipc.Server: IPC Server handler 0 on 36825: exiting
[junit] 11/07/21 01:29:14 INFO ipc.Server: Stopping IPC Server listener on 36825
[junit] 11/07/21 01:29:14 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/21 01:29:14 INFO ipc.Server: IPC Server handler 2 on 36825: exiting
[junit] 11/07/21 01:29:14 INFO ipc.Server: IPC Server handler 1 on 36825: exiting
[junit] 11/07/21 01:29:14 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:44770, storageID=DS-2108816015-127.0.1.1-44770-1311211384646, infoPort=44463, ipcPort=36825):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/21 01:29:14 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/21 01:29:14 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/21 01:29:14 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:44770, storageID=DS-2108816015-127.0.1.1-44770-1311211384646, infoPort=44463, ipcPort=36825):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/21 01:29:14 INFO ipc.Server: Stopping server on 36825
[junit] 11/07/21 01:29:14 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 0
[junit] 11/07/21 01:29:14 INFO ipc.Server: Stopping server on 59830
[junit] 11/07/21 01:29:14 INFO ipc.Server: Stopping IPC Server listener on 59830
[junit] 11/07/21 01:29:14 INFO ipc.Server: IPC Server handler 1 on 59830: exiting
[junit] 11/07/21 01:29:14 INFO ipc.Server: IPC Server handler 2 on 59830: exiting
[junit] 11/07/21 01:29:14 INFO ipc.Server: IPC Server handler 0 on 59830: exiting
[junit] 11/07/21 01:29:14 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/21 01:29:14 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/21 01:29:14 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:37665, storageID=DS-1319285584-127.0.1.1-37665-1311211384319, infoPort=60397, ipcPort=59830):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/21 01:29:15 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:37665 to delete blk_-8017141708210012487_1121 blk_-7695567180087290520_1127 blk_-8026282395271837867_1126
[junit] 11/07/21 01:29:15 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:43159 to delete blk_-7695567180087290520_1127 blk_-8026282395271837867_1126
[junit] 11/07/21 01:29:15 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/21 01:29:15 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/21 01:29:15 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:37665, storageID=DS-1319285584-127.0.1.1-37665-1311211384319, infoPort=60397, ipcPort=59830):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/21 01:29:15 INFO ipc.Server: Stopping server on 59830
[junit] 11/07/21 01:29:15 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/21 01:29:15 WARN namenode.FSNamesystem: ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] 11/07/21 01:29:15 INFO namenode.FSNamesystem: Number of transactions: 694 Total time for transactions(ms): 13Number of transactions batched in Syncs: 114 Number of syncs: 484 SyncTimes(ms): 5359 479
[junit] 11/07/21 01:29:15 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/21 01:29:15 INFO ipc.Server: Stopping server on 57699
[junit] 11/07/21 01:29:15 INFO ipc.Server: Stopping IPC Server listener on 57699
[junit] 11/07/21 01:29:15 INFO ipc.Server: IPC Server handler 0 on 57699: exiting
[junit] 11/07/21 01:29:15 INFO ipc.Server: IPC Server handler 1 on 57699: exiting
[junit] 11/07/21 01:29:15 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/21 01:29:15 INFO ipc.Server: IPC Server handler 9 on 57699: exiting
[junit] 11/07/21 01:29:15 INFO ipc.Server: IPC Server handler 4 on 57699: exiting
[junit] 11/07/21 01:29:15 INFO ipc.Server: IPC Server handler 2 on 57699: exiting
[junit] 11/07/21 01:29:15 INFO ipc.Server: IPC Server handler 3 on 57699: exiting
[junit] 11/07/21 01:29:15 INFO ipc.Server: IPC Server handler 6 on 57699: exiting
[junit] 11/07/21 01:29:15 INFO ipc.Server: IPC Server handler 5 on 57699: exiting
[junit] 11/07/21 01:29:15 INFO ipc.Server: IPC Server handler 7 on 57699: exiting
[junit] 11/07/21 01:29:15 INFO ipc.Server: IPC Server handler 8 on 57699: exiting
[junit] Tests run: 17, Failures: 0, Errors: 0, Time elapsed: 368.392 sec
[junit] Running org.apache.pig.test.TestStringUDFs
[junit] 11/07/21 01:29:16 WARN builtin.SUBSTRING: java.lang.NullPointerException
[junit] 11/07/21 01:29:16 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2
[junit] 11/07/21 01:29:16 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -1
[junit] 11/07/21 01:29:16 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -8
[junit] 11/07/21 01:29:16 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2
[junit] 11/07/21 01:29:16 WARN builtin.INDEXOF: Failed to process input; error - null
[junit] 11/07/21 01:29:16 WARN builtin.LAST_INDEX_OF: Failed to process input; error - null
[junit] Tests run: 11, Failures: 0, Errors: 0, Time elapsed: 0.122 sec
[delete] Deleting directory /tmp/pig_junit_tmp1751572052
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: 21 minutes 14 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
Build failed in Jenkins: Pig-trunk-commit #866
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Pig-trunk-commit/866/changes>
Changes:
[thejas] PIG-2146: POStore.getSchema() returns null because of which PigOutputCommitter
is not storing schema while cleanup
------------------------------------------
[...truncated 39831 lines...]
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output--3939521172535858951.txt_cleanupOnFailure_succeeded2 by DFSClient_-634647566
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] at org.apache.hadoop.ipc.Client.call(Client.java:740)
[junit] at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:3264)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.close(DFSClient.java:3188)
[junit] at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.close(DFSClient.java:1043)
[junit] at org.apache.hadoop.hdfs.DFSClient.close(DFSClient.java:237)
[junit] at org.apache.hadoop.hdfs.DistributedFileSystem.close(DistributedFileSystem.java:269)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsClusters(MiniGenericCluster.java:83)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsAndMrClusters(MiniGenericCluster.java:77)
[junit] at org.apache.pig.test.MiniGenericCluster.shutDown(MiniGenericCluster.java:68)
[junit] at org.apache.pig.test.TestStore.oneTimeTearDown(TestStore.java:127)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
[junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
[junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
[junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
[junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
[junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
[junit] 11/07/20 23:28:36 WARN hdfs.StateChange: DIR* NameSystem.completeFile: failed to complete /tmp/TestStore-output-5551418102219430049.txt_cleanupOnFailure_succeeded1 because dir.getFileBlocks() is null and pendingFile is null
[junit] 11/07/20 23:28:36 INFO ipc.Server: IPC Server handler 4 on 40868, call complete(/tmp/TestStore-output-5551418102219430049.txt_cleanupOnFailure_succeeded1, DFSClient_-634647566) from 127.0.0.1:54942: error: java.io.IOException: Could not complete write to file /tmp/TestStore-output-5551418102219430049.txt_cleanupOnFailure_succeeded1 by DFSClient_-634647566
[junit] java.io.IOException: Could not complete write to file /tmp/TestStore-output-5551418102219430049.txt_cleanupOnFailure_succeeded1 by DFSClient_-634647566
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit] 11/07/20 23:28:36 ERROR hdfs.DFSClient: Exception closing file /tmp/TestStore-output-5551418102219430049.txt_cleanupOnFailure_succeeded1 : org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output-5551418102219430049.txt_cleanupOnFailure_succeeded1 by DFSClient_-634647566
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output-5551418102219430049.txt_cleanupOnFailure_succeeded1 by DFSClient_-634647566
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 3
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] at org.apache.hadoop.ipc.Client.call(Client.java:740)
[junit] at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:3264)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.close(DFSClient.java:3188)
[junit] at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.close(DFSClient.java:1043)
[junit] at org.apache.hadoop.hdfs.DFSClient.close(DFSClient.java:237)
[junit] at org.apache.hadoop.hdfs.DistributedFileSystem.close(DistributedFileSystem.java:269)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsClusters(MiniGenericCluster.java:83)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsAndMrClusters(MiniGenericCluster.java:77)
[junit] at org.apache.pig.test.MiniGenericCluster.shutDown(MiniGenericCluster.java:68)
[junit] at org.apache.pig.test.TestStore.oneTimeTearDown(TestStore.java:127)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
[junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
[junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
[junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
[junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
[junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
[junit] 11/07/20 23:28:36 INFO ipc.Server: Stopping server on 46781
[junit] 11/07/20 23:28:36 INFO ipc.Server: IPC Server handler 2 on 46781: exiting
[junit] 11/07/20 23:28:36 INFO ipc.Server: IPC Server handler 1 on 46781: exiting
[junit] 11/07/20 23:28:36 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/20 23:28:36 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/20 23:28:36 INFO ipc.Server: IPC Server handler 0 on 46781: exiting
[junit] 11/07/20 23:28:36 INFO ipc.Server: Stopping IPC Server listener on 46781
[junit] 11/07/20 23:28:36 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:36805, storageID=DS-195269808-127.0.1.1-36805-1311204154836, infoPort=45996, ipcPort=46781):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/20 23:28:36 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/20 23:28:37 INFO datanode.DataNode: Deleting block blk_-3204924733222348700_1122 file build/test/data/dfs/data/data2/current/blk_-3204924733222348700
[junit] 11/07/20 23:28:37 INFO datanode.DataNode: Deleting block blk_6333618558934951744_1124 file build/test/data/dfs/data/data1/current/blk_6333618558934951744
[junit] 11/07/20 23:28:37 INFO datanode.DataNode: Deleting block blk_-3204924733222348700_1122 file build/test/data/dfs/data/data3/current/blk_-3204924733222348700
[junit] 11/07/20 23:28:37 INFO datanode.DataNode: Deleting block blk_6333618558934951744_1124 file build/test/data/dfs/data/data3/current/blk_6333618558934951744
[junit] 11/07/20 23:28:37 INFO datanode.DataNode: Deleting block blk_8636658259747225878_1123 file build/test/data/dfs/data/data4/current/blk_8636658259747225878
[junit] 11/07/20 23:28:37 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/20 23:28:37 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:36805, storageID=DS-195269808-127.0.1.1-36805-1311204154836, infoPort=45996, ipcPort=46781):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/20 23:28:37 INFO ipc.Server: Stopping server on 46781
[junit] 11/07/20 23:28:37 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 2
[junit] 11/07/20 23:28:37 INFO ipc.Server: Stopping server on 43641
[junit] 11/07/20 23:28:37 INFO ipc.Server: IPC Server handler 2 on 43641: exiting
[junit] 11/07/20 23:28:37 INFO ipc.Server: IPC Server handler 0 on 43641: exiting
[junit] 11/07/20 23:28:37 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/20 23:28:37 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/20 23:28:37 INFO ipc.Server: Stopping IPC Server listener on 43641
[junit] 11/07/20 23:28:37 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:36410, storageID=DS-750487208-127.0.1.1-36410-1311204154540, infoPort=60500, ipcPort=43641):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/20 23:28:37 INFO ipc.Server: IPC Server handler 1 on 43641: exiting
[junit] 11/07/20 23:28:37 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/20 23:28:37 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:36410, storageID=DS-750487208-127.0.1.1-36410-1311204154540, infoPort=60500, ipcPort=43641):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/20 23:28:37 INFO ipc.Server: Stopping server on 43641
[junit] 11/07/20 23:28:37 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 1
[junit] 11/07/20 23:28:38 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/20 23:28:38 INFO ipc.Server: Stopping server on 47299
[junit] 11/07/20 23:28:38 INFO ipc.Server: IPC Server handler 0 on 47299: exiting
[junit] 11/07/20 23:28:38 INFO ipc.Server: IPC Server handler 2 on 47299: exiting
[junit] 11/07/20 23:28:38 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/20 23:28:38 INFO ipc.Server: Stopping IPC Server listener on 47299
[junit] 11/07/20 23:28:38 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/20 23:28:38 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:50569, storageID=DS-1228816136-127.0.1.1-50569-1311204154249, infoPort=59581, ipcPort=47299):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/20 23:28:38 INFO ipc.Server: IPC Server handler 1 on 47299: exiting
[junit] 11/07/20 23:28:38 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:50569 to delete blk_-6361483123941874151_1126 blk_-9092788064384877966_1127
[junit] 11/07/20 23:28:38 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:38335 to delete blk_-6361483123941874151_1126 blk_-9092788064384877966_1127 blk_2795447678487328647_1121
[junit] 11/07/20 23:28:39 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/20 23:28:39 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/20 23:28:39 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:50569, storageID=DS-1228816136-127.0.1.1-50569-1311204154249, infoPort=59581, ipcPort=47299):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/20 23:28:39 INFO ipc.Server: Stopping server on 47299
[junit] 11/07/20 23:28:39 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 0
[junit] 11/07/20 23:28:39 INFO ipc.Server: Stopping server on 41125
[junit] 11/07/20 23:28:39 INFO ipc.Server: IPC Server handler 0 on 41125: exiting
[junit] 11/07/20 23:28:39 INFO ipc.Server: IPC Server handler 1 on 41125: exiting
[junit] 11/07/20 23:28:39 INFO ipc.Server: IPC Server handler 2 on 41125: exiting
[junit] 11/07/20 23:28:39 INFO ipc.Server: Stopping IPC Server listener on 41125
[junit] 11/07/20 23:28:39 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/20 23:28:39 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/20 23:28:39 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:38335, storageID=DS-1763994815-127.0.1.1-38335-1311204153938, infoPort=39626, ipcPort=41125):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/20 23:28:39 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/20 23:28:40 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:38335, storageID=DS-1763994815-127.0.1.1-38335-1311204153938, infoPort=39626, ipcPort=41125):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/20 23:28:40 INFO ipc.Server: Stopping server on 41125
[junit] 11/07/20 23:28:40 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/20 23:28:40 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/20 23:28:40 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/20 23:28:40 INFO namenode.FSNamesystem: Number of transactions: 694 Total time for transactions(ms): 15Number of transactions batched in Syncs: 114 Number of syncs: 484 SyncTimes(ms): 4448 476
[junit] 11/07/20 23:28:40 WARN namenode.FSNamesystem: ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] 11/07/20 23:28:40 INFO ipc.Server: Stopping server on 40868
[junit] 11/07/20 23:28:40 INFO ipc.Server: Stopping IPC Server listener on 40868
[junit] 11/07/20 23:28:40 INFO ipc.Server: IPC Server handler 7 on 40868: exiting
[junit] 11/07/20 23:28:40 INFO ipc.Server: IPC Server handler 3 on 40868: exiting
[junit] 11/07/20 23:28:40 INFO ipc.Server: IPC Server handler 0 on 40868: exiting
[junit] 11/07/20 23:28:40 INFO ipc.Server: IPC Server handler 1 on 40868: exiting
[junit] 11/07/20 23:28:40 INFO ipc.Server: IPC Server handler 8 on 40868: exiting
[junit] 11/07/20 23:28:40 INFO ipc.Server: IPC Server handler 4 on 40868: exiting
[junit] 11/07/20 23:28:40 INFO ipc.Server: IPC Server handler 6 on 40868: exiting
[junit] 11/07/20 23:28:40 INFO ipc.Server: IPC Server handler 9 on 40868: exiting
[junit] 11/07/20 23:28:40 INFO ipc.Server: IPC Server handler 2 on 40868: exiting
[junit] 11/07/20 23:28:40 INFO ipc.Server: IPC Server handler 5 on 40868: exiting
[junit] 11/07/20 23:28:40 INFO ipc.Server: Stopping IPC Server Responder
[junit] Tests run: 17, Failures: 0, Errors: 0, Time elapsed: 363.663 sec
[junit] Running org.apache.pig.test.TestStringUDFs
[junit] 11/07/20 23:28:41 WARN builtin.SUBSTRING: java.lang.NullPointerException
[junit] 11/07/20 23:28:41 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2
[junit] 11/07/20 23:28:41 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -1
[junit] 11/07/20 23:28:41 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -8
[junit] 11/07/20 23:28:41 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2
[junit] 11/07/20 23:28:41 WARN builtin.INDEXOF: Failed to process input; error - null
[junit] 11/07/20 23:28:41 WARN builtin.LAST_INDEX_OF: Failed to process input; error - null
[junit] Tests run: 11, Failures: 0, Errors: 0, Time elapsed: 0.116 sec
[delete] Deleting directory /tmp/pig_junit_tmp665886679
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: 21 minutes 10 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
Build failed in Jenkins: Pig-trunk-commit #865
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Pig-trunk-commit/865/changes>
Changes:
[daijy] PIG-2175: Switch Pig wiki to use confluence
------------------------------------------
[...truncated 39819 lines...]
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output--6173355577045242468.txt_cleanupOnFailure_succeeded2 by DFSClient_-402372977
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] at org.apache.hadoop.ipc.Client.call(Client.java:740)
[junit] at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:3264)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.close(DFSClient.java:3188)
[junit] at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.close(DFSClient.java:1043)
[junit] at org.apache.hadoop.hdfs.DFSClient.close(DFSClient.java:237)
[junit] at org.apache.hadoop.hdfs.DistributedFileSystem.close(DistributedFileSystem.java:269)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsClusters(MiniGenericCluster.java:83)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsAndMrClusters(MiniGenericCluster.java:77)
[junit] at org.apache.pig.test.MiniGenericCluster.shutDown(MiniGenericCluster.java:68)
[junit] at org.apache.pig.test.TestStore.oneTimeTearDown(TestStore.java:127)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
[junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
[junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
[junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
[junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
[junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
[junit] 11/07/20 20:28:54 WARN hdfs.StateChange: DIR* NameSystem.completeFile: failed to complete /tmp/TestStore-output--8318435738590698187.txt_cleanupOnFailure_succeeded because dir.getFileBlocks() is null and pendingFile is null
[junit] 11/07/20 20:28:54 INFO ipc.Server: IPC Server handler 8 on 54827, call complete(/tmp/TestStore-output--8318435738590698187.txt_cleanupOnFailure_succeeded, DFSClient_-402372977) from 127.0.0.1:48677: error: java.io.IOException: Could not complete write to file /tmp/TestStore-output--8318435738590698187.txt_cleanupOnFailure_succeeded by DFSClient_-402372977
[junit] java.io.IOException: Could not complete write to file /tmp/TestStore-output--8318435738590698187.txt_cleanupOnFailure_succeeded by DFSClient_-402372977
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit] 11/07/20 20:28:54 ERROR hdfs.DFSClient: Exception closing file /tmp/TestStore-output--8318435738590698187.txt_cleanupOnFailure_succeeded : org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output--8318435738590698187.txt_cleanupOnFailure_succeeded by DFSClient_-402372977
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output--8318435738590698187.txt_cleanupOnFailure_succeeded by DFSClient_-402372977
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] at org.apache.hadoop.ipc.Client.call(Client.java:740)
[junit] at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:3264)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.close(DFSClient.java:3188)
[junit] at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.close(DFSClient.java:1043)
[junit] at org.apache.hadoop.hdfs.DFSClient.close(DFSClient.java:237)
[junit] at org.apache.hadoop.hdfs.DistributedFileSystem.close(DistributedFileSystem.java:269)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsClusters(MiniGenericCluster.java:83)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsAndMrClusters(MiniGenericCluster.java:77)
[junit] at org.apache.pig.test.MiniGenericCluster.shutDown(MiniGenericCluster.java:68)
[junit] at org.apache.pig.test.TestStore.oneTimeTearDown(TestStore.java:127)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
[junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
[junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
[junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
[junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
[junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 3
[junit] 11/07/20 20:28:54 INFO ipc.Server: Stopping server on 34604
[junit] 11/07/20 20:28:54 INFO ipc.Server: IPC Server handler 1 on 34604: exiting
[junit] 11/07/20 20:28:54 INFO ipc.Server: IPC Server handler 0 on 34604: exiting
[junit] 11/07/20 20:28:54 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/20 20:28:54 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/20 20:28:54 INFO ipc.Server: Stopping IPC Server listener on 34604
[junit] 11/07/20 20:28:54 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:43253, storageID=DS-1984411196-127.0.1.1-43253-1311193372417, infoPort=56585, ipcPort=34604):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/20 20:28:54 INFO ipc.Server: IPC Server handler 2 on 34604: exiting
[junit] 11/07/20 20:28:54 INFO datanode.DataNode: Deleting block blk_7997217196814725789_1123 file build/test/data/dfs/data/data4/current/blk_7997217196814725789
[junit] 11/07/20 20:28:54 INFO datanode.DataNode: Deleting block blk_8484644369041539496_1124 file build/test/data/dfs/data/data3/current/blk_8484644369041539496
[junit] 11/07/20 20:28:55 INFO datanode.DataNode: Deleting block blk_5883148209402507890_1122 file build/test/data/dfs/data/data6/current/blk_5883148209402507890
[junit] 11/07/20 20:28:55 INFO datanode.DataNode: Deleting block blk_7997217196814725789_1123 file build/test/data/dfs/data/data5/current/blk_7997217196814725789
[junit] 11/07/20 20:28:55 INFO datanode.DataNode: Deleting block blk_8484644369041539496_1124 file build/test/data/dfs/data/data6/current/blk_8484644369041539496
[junit] 11/07/20 20:28:55 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/20 20:28:55 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:43253, storageID=DS-1984411196-127.0.1.1-43253-1311193372417, infoPort=56585, ipcPort=34604):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/20 20:28:55 INFO ipc.Server: Stopping server on 34604
[junit] 11/07/20 20:28:55 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 2
[junit] 11/07/20 20:28:55 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/20 20:28:55 INFO ipc.Server: Stopping server on 57260
[junit] 11/07/20 20:28:55 INFO ipc.Server: IPC Server handler 0 on 57260: exiting
[junit] 11/07/20 20:28:55 INFO ipc.Server: IPC Server handler 2 on 57260: exiting
[junit] 11/07/20 20:28:55 INFO ipc.Server: Stopping IPC Server listener on 57260
[junit] 11/07/20 20:28:55 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/20 20:28:55 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/20 20:28:55 INFO ipc.Server: IPC Server handler 1 on 57260: exiting
[junit] 11/07/20 20:28:55 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:37203, storageID=DS-1190561332-127.0.1.1-37203-1311193372123, infoPort=56661, ipcPort=57260):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/20 20:28:56 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/20 20:28:56 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:37203 to delete blk_3079268705561693789_1121 blk_721618064306971440_1127 blk_6048780770867461787_1126
[junit] 11/07/20 20:28:56 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:54740 to delete blk_3079268705561693789_1121 blk_721618064306971440_1127 blk_6048780770867461787_1126
[junit] 11/07/20 20:28:56 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/20 20:28:56 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:37203, storageID=DS-1190561332-127.0.1.1-37203-1311193372123, infoPort=56661, ipcPort=57260):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/20 20:28:56 INFO ipc.Server: Stopping server on 57260
[junit] 11/07/20 20:28:56 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 1
[junit] 11/07/20 20:28:56 INFO ipc.Server: Stopping server on 36459
[junit] 11/07/20 20:28:56 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/20 20:28:56 INFO ipc.Server: IPC Server handler 1 on 36459: exiting
[junit] 11/07/20 20:28:56 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:54740, storageID=DS-1916942665-127.0.1.1-54740-1311193371833, infoPort=35013, ipcPort=36459):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/20 20:28:56 INFO ipc.Server: IPC Server handler 0 on 36459: exiting
[junit] 11/07/20 20:28:56 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/20 20:28:56 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/20 20:28:56 INFO ipc.Server: IPC Server handler 2 on 36459: exiting
[junit] 11/07/20 20:28:56 INFO ipc.Server: Stopping IPC Server listener on 36459
[junit] 11/07/20 20:28:56 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:54740, storageID=DS-1916942665-127.0.1.1-54740-1311193371833, infoPort=35013, ipcPort=36459):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/20 20:28:56 INFO ipc.Server: Stopping server on 36459
[junit] 11/07/20 20:28:56 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 0
[junit] 11/07/20 20:28:56 INFO ipc.Server: Stopping server on 40974
[junit] 11/07/20 20:28:56 INFO ipc.Server: IPC Server handler 0 on 40974: exiting
[junit] 11/07/20 20:28:56 INFO ipc.Server: Stopping IPC Server listener on 40974
[junit] 11/07/20 20:28:56 INFO ipc.Server: IPC Server handler 1 on 40974: exiting
[junit] 11/07/20 20:28:56 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/20 20:28:56 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/20 20:28:56 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:34942, storageID=DS-338607779-127.0.1.1-34942-1311193371504, infoPort=34299, ipcPort=40974):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/20 20:28:56 INFO ipc.Server: IPC Server handler 2 on 40974: exiting
[junit] 11/07/20 20:28:57 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/20 20:28:57 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:34942, storageID=DS-338607779-127.0.1.1-34942-1311193371504, infoPort=34299, ipcPort=40974):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/20 20:28:57 INFO ipc.Server: Stopping server on 40974
[junit] 11/07/20 20:28:57 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/20 20:28:57 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/20 20:28:57 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/20 20:28:57 INFO namenode.FSNamesystem: Number of transactions: 694 Total time for transactions(ms): 18Number of transactions batched in Syncs: 114 Number of syncs: 484 SyncTimes(ms): 3647 609
[junit] 11/07/20 20:28:57 WARN namenode.FSNamesystem: ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] 11/07/20 20:28:57 INFO ipc.Server: Stopping server on 54827
[junit] 11/07/20 20:28:57 INFO ipc.Server: IPC Server handler 1 on 54827: exiting
[junit] 11/07/20 20:28:57 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/20 20:28:57 INFO ipc.Server: Stopping IPC Server listener on 54827
[junit] 11/07/20 20:28:57 INFO ipc.Server: IPC Server handler 0 on 54827: exiting
[junit] 11/07/20 20:28:57 INFO ipc.Server: IPC Server handler 6 on 54827: exiting
[junit] 11/07/20 20:28:57 INFO ipc.Server: IPC Server handler 4 on 54827: exiting
[junit] 11/07/20 20:28:57 INFO ipc.Server: IPC Server handler 5 on 54827: exiting
[junit] 11/07/20 20:28:57 INFO ipc.Server: IPC Server handler 3 on 54827: exiting
[junit] 11/07/20 20:28:57 INFO ipc.Server: IPC Server handler 2 on 54827: exiting
[junit] 11/07/20 20:28:57 INFO ipc.Server: IPC Server handler 7 on 54827: exiting
[junit] 11/07/20 20:28:57 INFO ipc.Server: IPC Server handler 9 on 54827: exiting
[junit] 11/07/20 20:28:57 INFO ipc.Server: IPC Server handler 8 on 54827: exiting
[junit] Tests run: 17, Failures: 0, Errors: 0, Time elapsed: 363.051 sec
[junit] Running org.apache.pig.test.TestStringUDFs
[junit] 11/07/20 20:28:58 WARN builtin.SUBSTRING: java.lang.NullPointerException
[junit] 11/07/20 20:28:58 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2
[junit] 11/07/20 20:28:58 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -1
[junit] 11/07/20 20:28:58 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -8
[junit] 11/07/20 20:28:58 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2
[junit] 11/07/20 20:28:58 WARN builtin.INDEXOF: Failed to process input; error - null
[junit] 11/07/20 20:28:58 WARN builtin.LAST_INDEX_OF: Failed to process input; error - null
[junit] Tests run: 11, Failures: 0, Errors: 0, Time elapsed: 0.116 sec
[delete] Deleting directory /tmp/pig_junit_tmp1176941027
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: 21 minutes 10 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
Build failed in Jenkins: Pig-trunk-commit #864
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Pig-trunk-commit/864/changes>
Changes:
[daijy] PIG-2027: NPE if Pig don't have permission for log file
------------------------------------------
[...truncated 39819 lines...]
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output--4558572667977626699.txt_cleanupOnFailure_succeeded1 by DFSClient_-912609163
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] at org.apache.hadoop.ipc.Client.call(Client.java:740)
[junit] at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:3264)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.close(DFSClient.java:3188)
[junit] at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.close(DFSClient.java:1043)
[junit] at org.apache.hadoop.hdfs.DFSClient.close(DFSClient.java:237)
[junit] at org.apache.hadoop.hdfs.DistributedFileSystem.close(DistributedFileSystem.java:269)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsClusters(MiniGenericCluster.java:83)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsAndMrClusters(MiniGenericCluster.java:77)
[junit] at org.apache.pig.test.MiniGenericCluster.shutDown(MiniGenericCluster.java:68)
[junit] at org.apache.pig.test.TestStore.oneTimeTearDown(TestStore.java:127)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
[junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
[junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
[junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
[junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
[junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
[junit] 11/07/20 18:30:09 WARN hdfs.StateChange: DIR* NameSystem.completeFile: failed to complete /tmp/TestStore-output-2315760537085322334.txt_cleanupOnFailure_succeeded2 because dir.getFileBlocks() is null and pendingFile is null
[junit] 11/07/20 18:30:09 INFO ipc.Server: IPC Server handler 0 on 59045, call complete(/tmp/TestStore-output-2315760537085322334.txt_cleanupOnFailure_succeeded2, DFSClient_-912609163) from 127.0.0.1:52994: error: java.io.IOException: Could not complete write to file /tmp/TestStore-output-2315760537085322334.txt_cleanupOnFailure_succeeded2 by DFSClient_-912609163
[junit] java.io.IOException: Could not complete write to file /tmp/TestStore-output-2315760537085322334.txt_cleanupOnFailure_succeeded2 by DFSClient_-912609163
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit] 11/07/20 18:30:09 ERROR hdfs.DFSClient: Exception closing file /tmp/TestStore-output-2315760537085322334.txt_cleanupOnFailure_succeeded2 : org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output-2315760537085322334.txt_cleanupOnFailure_succeeded2 by DFSClient_-912609163
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output-2315760537085322334.txt_cleanupOnFailure_succeeded2 by DFSClient_-912609163
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] at org.apache.hadoop.ipc.Client.call(Client.java:740)
[junit] at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:3264)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.close(DFSClient.java:3188)
[junit] at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.close(DFSClient.java:1043)
[junit] at org.apache.hadoop.hdfs.DFSClient.close(DFSClient.java:237)
[junit] at org.apache.hadoop.hdfs.DistributedFileSystem.close(DistributedFileSystem.java:269)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsClusters(MiniGenericCluster.java:83)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsAndMrClusters(MiniGenericCluster.java:77)
[junit] at org.apache.pig.test.MiniGenericCluster.shutDown(MiniGenericCluster.java:68)
[junit] at org.apache.pig.test.TestStore.oneTimeTearDown(TestStore.java:127)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
[junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
[junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
[junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
[junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
[junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 3
[junit] 11/07/20 18:30:09 INFO ipc.Server: Stopping server on 57781
[junit] 11/07/20 18:30:09 INFO ipc.Server: Stopping IPC Server listener on 57781
[junit] 11/07/20 18:30:09 INFO ipc.Server: IPC Server handler 0 on 57781: exiting
[junit] 11/07/20 18:30:09 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/20 18:30:09 INFO ipc.Server: IPC Server handler 2 on 57781: exiting
[junit] 11/07/20 18:30:09 INFO ipc.Server: IPC Server handler 1 on 57781: exiting
[junit] 11/07/20 18:30:09 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/20 18:30:09 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:35781, storageID=DS-1404909414-127.0.1.1-35781-1311186237224, infoPort=59762, ipcPort=57781):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/20 18:30:09 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:60671 to delete blk_6129303074643234637_1124 blk_-3943494823013187226_1122 blk_768233242821262845_1121 blk_-1986181213677077307_1126
[junit] 11/07/20 18:30:09 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:37043 to delete blk_6129303074643234637_1124 blk_-5539916122989107898_1127 blk_-1986181213677077307_1126 blk_-4818205592067356364_1123
[junit] 11/07/20 18:30:10 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/20 18:30:10 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/20 18:30:10 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:35781, storageID=DS-1404909414-127.0.1.1-35781-1311186237224, infoPort=59762, ipcPort=57781):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/20 18:30:10 INFO ipc.Server: Stopping server on 57781
[junit] 11/07/20 18:30:10 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 2
[junit] 11/07/20 18:30:10 INFO ipc.Server: Stopping server on 57598
[junit] 11/07/20 18:30:10 INFO ipc.Server: IPC Server handler 0 on 57598: exiting
[junit] 11/07/20 18:30:10 INFO ipc.Server: IPC Server handler 2 on 57598: exiting
[junit] 11/07/20 18:30:10 INFO ipc.Server: IPC Server handler 1 on 57598: exiting
[junit] 11/07/20 18:30:10 INFO ipc.Server: Stopping IPC Server listener on 57598
[junit] 11/07/20 18:30:10 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/20 18:30:10 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/20 18:30:10 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:37043, storageID=DS-1204717515-127.0.1.1-37043-1311186236929, infoPort=40908, ipcPort=57598):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/20 18:30:10 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/20 18:30:11 INFO datanode.DataNode: Deleting block blk_-3943494823013187226_1122 file build/test/data/dfs/data/data2/current/blk_-3943494823013187226
[junit] 11/07/20 18:30:11 INFO datanode.DataNode: Deleting block blk_-1986181213677077307_1126 file build/test/data/dfs/data/data2/current/blk_-1986181213677077307
[junit] 11/07/20 18:30:11 INFO datanode.DataNode: Deleting block blk_768233242821262845_1121 file build/test/data/dfs/data/data1/current/blk_768233242821262845
[junit] 11/07/20 18:30:11 INFO datanode.DataNode: Deleting block blk_6129303074643234637_1124 file build/test/data/dfs/data/data1/current/blk_6129303074643234637
[junit] 11/07/20 18:30:11 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/20 18:30:11 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:37043, storageID=DS-1204717515-127.0.1.1-37043-1311186236929, infoPort=40908, ipcPort=57598):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/20 18:30:11 INFO ipc.Server: Stopping server on 57598
[junit] 11/07/20 18:30:11 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 1
[junit] 11/07/20 18:30:11 INFO ipc.Server: Stopping server on 42336
[junit] 11/07/20 18:30:11 INFO ipc.Server: IPC Server handler 0 on 42336: exiting
[junit] 11/07/20 18:30:11 INFO ipc.Server: IPC Server handler 1 on 42336: exiting
[junit] 11/07/20 18:30:11 INFO ipc.Server: Stopping IPC Server listener on 42336
[junit] 11/07/20 18:30:11 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/20 18:30:11 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/20 18:30:11 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:53806, storageID=DS-1772424937-127.0.1.1-53806-1311186236380, infoPort=39622, ipcPort=42336):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/20 18:30:11 INFO ipc.Server: IPC Server handler 2 on 42336: exiting
[junit] 11/07/20 18:30:12 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/20 18:30:12 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/20 18:30:12 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:53806, storageID=DS-1772424937-127.0.1.1-53806-1311186236380, infoPort=39622, ipcPort=42336):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/20 18:30:12 INFO ipc.Server: Stopping server on 42336
[junit] 11/07/20 18:30:12 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 0
[junit] 11/07/20 18:30:12 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:35781 to delete blk_-3943494823013187226_1122 blk_-5539916122989107898_1127 blk_768233242821262845_1121 blk_-1986181213677077307_1126 blk_-4818205592067356364_1123
[junit] 11/07/20 18:30:12 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:53806 to delete blk_6129303074643234637_1124 blk_-3943494823013187226_1122 blk_-5539916122989107898_1127 blk_768233242821262845_1121 blk_-4818205592067356364_1123
[junit] 11/07/20 18:30:12 INFO ipc.Server: Stopping server on 43045
[junit] 11/07/20 18:30:12 INFO ipc.Server: IPC Server handler 0 on 43045: exiting
[junit] 11/07/20 18:30:12 INFO ipc.Server: Stopping IPC Server listener on 43045
[junit] 11/07/20 18:30:12 INFO ipc.Server: IPC Server handler 2 on 43045: exiting
[junit] 11/07/20 18:30:12 INFO ipc.Server: IPC Server handler 1 on 43045: exiting
[junit] 11/07/20 18:30:12 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/20 18:30:12 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/20 18:30:12 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:60671, storageID=DS-1029713809-127.0.1.1-60671-1311186236075, infoPort=55542, ipcPort=43045):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/20 18:30:13 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/20 18:30:13 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/20 18:30:13 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:60671, storageID=DS-1029713809-127.0.1.1-60671-1311186236075, infoPort=55542, ipcPort=43045):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/20 18:30:13 INFO ipc.Server: Stopping server on 43045
[junit] 11/07/20 18:30:13 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/20 18:30:14 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/20 18:30:14 WARN namenode.FSNamesystem: ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] 11/07/20 18:30:14 INFO namenode.FSNamesystem: Number of transactions: 694 Total time for transactions(ms): 19Number of transactions batched in Syncs: 114 Number of syncs: 484 SyncTimes(ms): 7634 1658
[junit] 11/07/20 18:30:14 INFO ipc.Server: Stopping server on 59045
[junit] Tests run: 17, Failures: 0, Errors: 0, Time elapsed: 374.629 sec
[junit] 11/07/20 18:30:14 INFO ipc.Server: Stopping IPC Server listener on 59045
[junit] 11/07/20 18:30:14 INFO ipc.Server: IPC Server handler 0 on 59045: exiting
[junit] 11/07/20 18:30:14 INFO ipc.Server: IPC Server handler 2 on 59045: exiting
[junit] 11/07/20 18:30:14 INFO ipc.Server: IPC Server handler 3 on 59045: exiting
[junit] 11/07/20 18:30:14 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/20 18:30:14 INFO ipc.Server: IPC Server handler 8 on 59045: exiting
[junit] 11/07/20 18:30:14 INFO ipc.Server: IPC Server handler 1 on 59045: exiting
[junit] 11/07/20 18:30:14 INFO ipc.Server: IPC Server handler 4 on 59045: exiting
[junit] 11/07/20 18:30:14 INFO ipc.Server: IPC Server handler 9 on 59045: exiting
[junit] 11/07/20 18:30:14 INFO ipc.Server: IPC Server handler 5 on 59045: exiting
[junit] 11/07/20 18:30:14 INFO ipc.Server: IPC Server handler 6 on 59045: exiting
[junit] 11/07/20 18:30:14 INFO ipc.Server: IPC Server handler 7 on 59045: exiting
[junit] Running org.apache.pig.test.TestStringUDFs
[junit] 11/07/20 18:30:14 WARN builtin.SUBSTRING: java.lang.NullPointerException
[junit] 11/07/20 18:30:15 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2
[junit] 11/07/20 18:30:15 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -1
[junit] 11/07/20 18:30:15 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -8
[junit] 11/07/20 18:30:15 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2
[junit] 11/07/20 18:30:15 WARN builtin.INDEXOF: Failed to process input; error - null
[junit] 11/07/20 18:30:15 WARN builtin.LAST_INDEX_OF: Failed to process input; error - null
[junit] Tests run: 11, Failures: 0, Errors: 0, Time elapsed: 0.122 sec
[delete] Deleting directory /tmp/pig_junit_tmp574247011
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: 21 minutes 25 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
Build failed in Jenkins: Pig-trunk-commit #863
Posted by Apache Jenkins Server <je...@builds.apache.org>.
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
Build failed in Jenkins: Pig-trunk-commit #862
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Pig-trunk-commit/862/changes>
Changes:
[daijy] Make Pig work with hadoop .NEXT
------------------------------------------
[...truncated 39793 lines...]
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output--9208950352273007539.txt_cleanupOnFailure_succeeded1 by DFSClient_-814205210
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] at org.apache.hadoop.ipc.Client.call(Client.java:740)
[junit] at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:3264)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.close(DFSClient.java:3188)
[junit] at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.close(DFSClient.java:1043)
[junit] at org.apache.hadoop.hdfs.DFSClient.close(DFSClient.java:237)
[junit] at org.apache.hadoop.hdfs.DistributedFileSystem.close(DistributedFileSystem.java:269)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsClusters(MiniGenericCluster.java:83)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsAndMrClusters(MiniGenericCluster.java:77)
[junit] at org.apache.pig.test.MiniGenericCluster.shutDown(MiniGenericCluster.java:68)
[junit] at org.apache.pig.test.TestStore.oneTimeTearDown(TestStore.java:127)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
[junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
[junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
[junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
[junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
[junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
[junit] 11/07/19 02:28:01 WARN hdfs.StateChange: DIR* NameSystem.completeFile: failed to complete /tmp/TestStore-output-201847589470793672.txt_cleanupOnFailure_succeeded because dir.getFileBlocks() is null and pendingFile is null
[junit] 11/07/19 02:28:01 INFO ipc.Server: IPC Server handler 6 on 52543, call complete(/tmp/TestStore-output-201847589470793672.txt_cleanupOnFailure_succeeded, DFSClient_-814205210) from 127.0.0.1:51454: error: java.io.IOException: Could not complete write to file /tmp/TestStore-output-201847589470793672.txt_cleanupOnFailure_succeeded by DFSClient_-814205210
[junit] java.io.IOException: Could not complete write to file /tmp/TestStore-output-201847589470793672.txt_cleanupOnFailure_succeeded by DFSClient_-814205210
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit] 11/07/19 02:28:01 ERROR hdfs.DFSClient: Exception closing file /tmp/TestStore-output-201847589470793672.txt_cleanupOnFailure_succeeded : org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output-201847589470793672.txt_cleanupOnFailure_succeeded by DFSClient_-814205210
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /tmp/TestStore-output-201847589470793672.txt_cleanupOnFailure_succeeded by DFSClient_-814205210
[junit] at org.apache.hadoop.hdfs.server.namenode.NameNode.complete(NameNode.java:449)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:508)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:959)
[junit] at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:955)
[junit] at java.security.AccessController.doPrivileged(Native Method)
[junit] at javax.security.auth.Subject.doAs(Subject.java:396)
[junit] at org.apache.hadoop.ipc.Server$Handler.run(Server.java:953)
[junit]
[junit] at org.apache.hadoop.ipc.Client.call(Client.java:740)
[junit] at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:220)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at sun.reflect.GeneratedMethodAccessor18.invoke(Unknown Source)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
[junit] at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
[junit] at $Proxy0.complete(Unknown Source)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:3264)
[junit] at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.close(DFSClient.java:3188)
[junit] at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.close(DFSClient.java:1043)
[junit] at org.apache.hadoop.hdfs.DFSClient.close(DFSClient.java:237)
[junit] at org.apache.hadoop.hdfs.DistributedFileSystem.close(DistributedFileSystem.java:269)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsClusters(MiniGenericCluster.java:83)
[junit] at org.apache.pig.test.MiniGenericCluster.shutdownMiniDfsAndMrClusters(MiniGenericCluster.java:77)
[junit] at org.apache.pig.test.MiniGenericCluster.shutDown(MiniGenericCluster.java:68)
[junit] at org.apache.pig.test.TestStore.oneTimeTearDown(TestStore.java:127)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit] at java.lang.reflect.Method.invoke(Method.java:597)
[junit] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
[junit] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
[junit] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
[junit] at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
[junit] at org.junit.runners.ParentRunner.run(ParentRunner.java:220)
[junit] at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
[junit] at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
[junit] Shutting down the Mini HDFS Cluster
[junit] Shutting down DataNode 3
[junit] 11/07/19 02:28:01 INFO ipc.Server: Stopping server on 51161
[junit] 11/07/19 02:28:01 INFO ipc.Server: Stopping IPC Server listener on 51161
[junit] 11/07/19 02:28:01 INFO ipc.Server: IPC Server handler 0 on 51161: exiting
[junit] 11/07/19 02:28:01 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/19 02:28:01 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/19 02:28:01 INFO ipc.Server: IPC Server handler 2 on 51161: exiting
[junit] 11/07/19 02:28:01 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:57599, storageID=DS-693654083-127.0.1.1-57599-1311042113752, infoPort=37867, ipcPort=51161):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 02:28:01 INFO ipc.Server: IPC Server handler 1 on 51161: exiting
[junit] 11/07/19 02:28:01 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/19 02:28:01 INFO datanode.DataNode: Deleting block blk_5234227600792711340_1122 file build/test/data/dfs/data/data2/current/blk_5234227600792711340
[junit] 11/07/19 02:28:02 INFO datanode.DataNode: Deleting block blk_-8998815823102245938_1123 file build/test/data/dfs/data/data5/current/blk_-8998815823102245938
[junit] 11/07/19 02:28:02 INFO datanode.DataNode: Deleting block blk_5234227600792711340_1122 file build/test/data/dfs/data/data6/current/blk_5234227600792711340
[junit] 11/07/19 02:28:02 INFO datanode.DataNode: Deleting block blk_5331106965218945044_1124 file build/test/data/dfs/data/data6/current/blk_5331106965218945044
[junit] 11/07/19 02:28:02 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/19 02:28:02 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:57599, storageID=DS-693654083-127.0.1.1-57599-1311042113752, infoPort=37867, ipcPort=51161):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 02:28:02 INFO ipc.Server: Stopping server on 51161
[junit] 11/07/19 02:28:02 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 2
[junit] 11/07/19 02:28:02 INFO ipc.Server: Stopping server on 36330
[junit] 11/07/19 02:28:02 INFO ipc.Server: IPC Server handler 0 on 36330: exiting
[junit] 11/07/19 02:28:02 INFO ipc.Server: IPC Server handler 1 on 36330: exiting
[junit] 11/07/19 02:28:02 INFO ipc.Server: IPC Server handler 2 on 36330: exiting
[junit] 11/07/19 02:28:02 INFO ipc.Server: Stopping IPC Server listener on 36330
[junit] 11/07/19 02:28:02 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/19 02:28:02 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/19 02:28:02 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:38624, storageID=DS-1361277894-127.0.1.1-38624-1311042113450, infoPort=34275, ipcPort=36330):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 02:28:03 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/19 02:28:03 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:34641 to delete blk_1898666302133249207_1126 blk_1165538715395815209_1127
[junit] 11/07/19 02:28:03 INFO hdfs.StateChange: BLOCK* ask 127.0.0.1:38624 to delete blk_-6440474024445699655_1121 blk_1898666302133249207_1126 blk_1165538715395815209_1127
[junit] 11/07/19 02:28:03 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/19 02:28:03 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:38624, storageID=DS-1361277894-127.0.1.1-38624-1311042113450, infoPort=34275, ipcPort=36330):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 02:28:03 INFO ipc.Server: Stopping server on 36330
[junit] 11/07/19 02:28:03 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 1
[junit] 11/07/19 02:28:03 INFO ipc.Server: Stopping server on 48379
[junit] 11/07/19 02:28:03 INFO ipc.Server: IPC Server handler 0 on 48379: exiting
[junit] 11/07/19 02:28:03 INFO ipc.Server: IPC Server handler 2 on 48379: exiting
[junit] 11/07/19 02:28:03 INFO ipc.Server: Stopping IPC Server listener on 48379
[junit] 11/07/19 02:28:03 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/19 02:28:03 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/19 02:28:03 INFO ipc.Server: IPC Server handler 1 on 48379: exiting
[junit] 11/07/19 02:28:03 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:41397, storageID=DS-525555397-127.0.1.1-41397-1311042113142, infoPort=44301, ipcPort=48379):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 02:28:04 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/19 02:28:04 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/19 02:28:04 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:41397, storageID=DS-525555397-127.0.1.1-41397-1311042113142, infoPort=44301, ipcPort=48379):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 02:28:04 INFO ipc.Server: Stopping server on 48379
[junit] 11/07/19 02:28:04 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] Shutting down DataNode 0
[junit] 11/07/19 02:28:04 INFO ipc.Server: Stopping server on 60776
[junit] 11/07/19 02:28:04 INFO ipc.Server: IPC Server handler 0 on 60776: exiting
[junit] 11/07/19 02:28:04 INFO ipc.Server: IPC Server handler 1 on 60776: exiting
[junit] 11/07/19 02:28:04 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 1
[junit] 11/07/19 02:28:04 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/19 02:28:04 INFO ipc.Server: Stopping IPC Server listener on 60776
[junit] 11/07/19 02:28:04 INFO ipc.Server: IPC Server handler 2 on 60776: exiting
[junit] 11/07/19 02:28:04 WARN datanode.DataNode: DatanodeRegistration(127.0.0.1:34641, storageID=DS-1320328539-127.0.1.1-34641-1311042112822, infoPort=48996, ipcPort=60776):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 02:28:04 INFO datanode.DataBlockScanner: Exiting DataBlockScanner thread.
[junit] 11/07/19 02:28:04 INFO datanode.DataNode: DatanodeRegistration(127.0.0.1:34641, storageID=DS-1320328539-127.0.1.1-34641-1311042112822, infoPort=48996, ipcPort=60776):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 02:28:04 INFO ipc.Server: Stopping server on 60776
[junit] 11/07/19 02:28:04 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/19 02:28:05 INFO datanode.DataNode: Waiting for threadgroup to exit, active threads is 0
[junit] 11/07/19 02:28:05 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 02:28:05 INFO namenode.FSNamesystem: Number of transactions: 694 Total time for transactions(ms): 17Number of transactions batched in Syncs: 114 Number of syncs: 484 SyncTimes(ms): 7068 1286
[junit] 11/07/19 02:28:05 WARN namenode.FSNamesystem: ReplicationMonitor thread received InterruptedException.java.lang.InterruptedException: sleep interrupted
[junit] 11/07/19 02:28:05 INFO ipc.Server: Stopping server on 52543
[junit] 11/07/19 02:28:05 INFO ipc.Server: Stopping IPC Server listener on 52543
[junit] 11/07/19 02:28:05 INFO ipc.Server: IPC Server handler 0 on 52543: exiting
[junit] 11/07/19 02:28:05 INFO ipc.Server: IPC Server handler 3 on 52543: exiting
[junit] 11/07/19 02:28:05 INFO ipc.Server: IPC Server handler 1 on 52543: exiting
[junit] 11/07/19 02:28:05 INFO ipc.Server: Stopping IPC Server Responder
[junit] 11/07/19 02:28:05 INFO ipc.Server: IPC Server handler 5 on 52543: exiting
[junit] 11/07/19 02:28:05 INFO ipc.Server: IPC Server handler 9 on 52543: exiting
[junit] 11/07/19 02:28:05 INFO ipc.Server: IPC Server handler 6 on 52543: exiting
[junit] 11/07/19 02:28:05 INFO ipc.Server: IPC Server handler 8 on 52543: exiting
[junit] 11/07/19 02:28:05 INFO ipc.Server: IPC Server handler 7 on 52543: exiting
[junit] 11/07/19 02:28:05 INFO ipc.Server: IPC Server handler 2 on 52543: exiting
[junit] 11/07/19 02:28:05 INFO ipc.Server: IPC Server handler 4 on 52543: exiting
[junit] Tests run: 17, Failures: 0, Errors: 0, Time elapsed: 369.846 sec
[junit] Running org.apache.pig.test.TestStringUDFs
[junit] 11/07/19 02:28:06 WARN builtin.SUBSTRING: java.lang.NullPointerException
[junit] 11/07/19 02:28:06 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2
[junit] 11/07/19 02:28:06 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -1
[junit] 11/07/19 02:28:06 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -8
[junit] 11/07/19 02:28:06 WARN builtin.SUBSTRING: java.lang.StringIndexOutOfBoundsException: String index out of range: -2
[junit] 11/07/19 02:28:06 WARN builtin.INDEXOF: Failed to process input; error - null
[junit] 11/07/19 02:28:06 WARN builtin.LAST_INDEX_OF: Failed to process input; error - null
[junit] Tests run: 11, Failures: 0, Errors: 0, Time elapsed: 0.113 sec
[delete] Deleting directory /tmp/pig_junit_tmp2037482111
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: 21 minutes 19 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