Class cascading.cascade.ParallelCascadePlatformTest

2

tests

0

failures

0

ignored

2m27.58s

duration

100%

successful

Tests

Test Duration Result
testCascade 2m5.25s passed
testCascadeRaceCondition 22.330s passed

Standard output

2016-05-18 05:33:17,559 INFO  platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 05:33:17,575 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.cascade.ParallelCascadePlatformTest, with platform: hadoop
2016-05-18 05:33:17,597 INFO  hadoop.HadoopPlatform (HadoopPlatform.java:setUp(144)) - using cluster
2016-05-18 05:33:18,347 WARN  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-namenode.properties, hadoop-metrics2.properties
Starting DataNode 0 with dfs.data.dir: build/test/data/dfs/data/data1,build/test/data/dfs/data/data2
2016-05-18 05:33:19,185 WARN  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-05-18 05:33:19,186 WARN  util.MBeans (MBeans.java:register(59)) - Hadoop:service=DataNode,name=MetricsSystem,sub=Control
javax.management.InstanceAlreadyExistsException: MXBean already registered with name Hadoop:service=NameNode,name=MetricsSystem,sub=Control
	at com.sun.jmx.mbeanserver.MXBeanLookup.addReference(MXBeanLookup.java:151)
	at com.sun.jmx.mbeanserver.MXBeanSupport.register(MXBeanSupport.java:160)
	at com.sun.jmx.mbeanserver.MBeanSupport.preRegister2(MBeanSupport.java:173)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:930)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)
	at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522)
	at org.apache.hadoop.metrics2.util.MBeans.register(MBeans.java:56)
	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.initSystemMBean(MetricsSystemImpl.java:518)
	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.init(MetricsSystemImpl.java:140)
	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.init(DefaultMetricsSystem.java:40)
	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.initialize(DefaultMetricsSystem.java:50)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1650)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1626)
	at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes(MiniDFSCluster.java:421)
	at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:284)
	at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:124)
	at cascading.platform.hadoop.HadoopPlatform.setUp(HadoopPlatform.java:180)
	at cascading.PlatformTestCase.setUp(PlatformTestCase.java:161)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:303)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:69)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
	at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
	at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
	at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
2016-05-18 05:33:19,321 WARN  util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
Starting DataNode 1 with dfs.data.dir: build/test/data/dfs/data/data3,build/test/data/dfs/data/data4
2016-05-18 05:33:19,606 WARN  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-05-18 05:33:19,607 WARN  util.MBeans (MBeans.java:register(59)) - Hadoop:service=DataNode,name=MetricsSystem,sub=Control
javax.management.InstanceAlreadyExistsException: MXBean already registered with name Hadoop:service=NameNode,name=MetricsSystem,sub=Control
	at com.sun.jmx.mbeanserver.MXBeanLookup.addReference(MXBeanLookup.java:151)
	at com.sun.jmx.mbeanserver.MXBeanSupport.register(MXBeanSupport.java:160)
	at com.sun.jmx.mbeanserver.MBeanSupport.preRegister2(MBeanSupport.java:173)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:930)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)
	at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522)
	at org.apache.hadoop.metrics2.util.MBeans.register(MBeans.java:56)
	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.initSystemMBean(MetricsSystemImpl.java:518)
	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.init(MetricsSystemImpl.java:140)
	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.init(DefaultMetricsSystem.java:40)
	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.initialize(DefaultMetricsSystem.java:50)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1650)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1626)
	at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes(MiniDFSCluster.java:421)
	at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:284)
	at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:124)
	at cascading.platform.hadoop.HadoopPlatform.setUp(HadoopPlatform.java:180)
	at cascading.PlatformTestCase.setUp(PlatformTestCase.java:161)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:303)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:69)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
	at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
	at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
	at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
2016-05-18 05:33:19,695 WARN  util.MBeans (MBeans.java:register(59)) - Hadoop:service=DataNode,name=DataNodeInfo
javax.management.InstanceAlreadyExistsException: Hadoop:service=DataNode,name=DataNodeInfo
	at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithRepository(DefaultMBeanServerInterceptor.java:1898)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:966)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)
	at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522)
	at org.apache.hadoop.metrics2.util.MBeans.register(MBeans.java:56)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.registerMXBean(DataNode.java:581)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.startDataNode(DataNode.java:422)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.<init>(DataNode.java:321)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.makeInstance(DataNode.java:1712)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1651)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1626)
	at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes(MiniDFSCluster.java:421)
	at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:284)
	at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:124)
	at cascading.platform.hadoop.HadoopPlatform.setUp(HadoopPlatform.java:180)
	at cascading.PlatformTestCase.setUp(PlatformTestCase.java:161)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:303)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:69)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
	at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
	at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
	at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
Starting DataNode 2 with dfs.data.dir: build/test/data/dfs/data/data5,build/test/data/dfs/data/data6
2016-05-18 05:33:19,981 WARN  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-05-18 05:33:19,982 WARN  util.MBeans (MBeans.java:register(59)) - Hadoop:service=DataNode,name=MetricsSystem,sub=Control
javax.management.InstanceAlreadyExistsException: MXBean already registered with name Hadoop:service=NameNode,name=MetricsSystem,sub=Control
	at com.sun.jmx.mbeanserver.MXBeanLookup.addReference(MXBeanLookup.java:151)
	at com.sun.jmx.mbeanserver.MXBeanSupport.register(MXBeanSupport.java:160)
	at com.sun.jmx.mbeanserver.MBeanSupport.preRegister2(MBeanSupport.java:173)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:930)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)
	at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522)
	at org.apache.hadoop.metrics2.util.MBeans.register(MBeans.java:56)
	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.initSystemMBean(MetricsSystemImpl.java:518)
	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.init(MetricsSystemImpl.java:140)
	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.init(DefaultMetricsSystem.java:40)
	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.initialize(DefaultMetricsSystem.java:50)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1650)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1626)
	at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes(MiniDFSCluster.java:421)
	at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:284)
	at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:124)
	at cascading.platform.hadoop.HadoopPlatform.setUp(HadoopPlatform.java:180)
	at cascading.PlatformTestCase.setUp(PlatformTestCase.java:161)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:303)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:69)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
	at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
	at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
	at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
2016-05-18 05:33:20,049 WARN  util.MBeans (MBeans.java:register(59)) - Hadoop:service=DataNode,name=DataNodeInfo
javax.management.InstanceAlreadyExistsException: Hadoop:service=DataNode,name=DataNodeInfo
	at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithRepository(DefaultMBeanServerInterceptor.java:1898)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:966)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)
	at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522)
	at org.apache.hadoop.metrics2.util.MBeans.register(MBeans.java:56)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.registerMXBean(DataNode.java:581)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.startDataNode(DataNode.java:422)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.<init>(DataNode.java:321)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.makeInstance(DataNode.java:1712)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1651)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1626)
	at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes(MiniDFSCluster.java:421)
	at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:284)
	at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:124)
	at cascading.platform.hadoop.HadoopPlatform.setUp(HadoopPlatform.java:180)
	at cascading.PlatformTestCase.setUp(PlatformTestCase.java:161)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:303)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:69)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
	at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
	at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
	at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
Starting DataNode 3 with dfs.data.dir: build/test/data/dfs/data/data7,build/test/data/dfs/data/data8
2016-05-18 05:33:20,270 WARN  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-05-18 05:33:20,271 WARN  util.MBeans (MBeans.java:register(59)) - Hadoop:service=DataNode,name=MetricsSystem,sub=Control
javax.management.InstanceAlreadyExistsException: MXBean already registered with name Hadoop:service=NameNode,name=MetricsSystem,sub=Control
	at com.sun.jmx.mbeanserver.MXBeanLookup.addReference(MXBeanLookup.java:151)
	at com.sun.jmx.mbeanserver.MXBeanSupport.register(MXBeanSupport.java:160)
	at com.sun.jmx.mbeanserver.MBeanSupport.preRegister2(MBeanSupport.java:173)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:930)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)
	at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522)
	at org.apache.hadoop.metrics2.util.MBeans.register(MBeans.java:56)
	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.initSystemMBean(MetricsSystemImpl.java:518)
	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.init(MetricsSystemImpl.java:140)
	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.init(DefaultMetricsSystem.java:40)
	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.initialize(DefaultMetricsSystem.java:50)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1650)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1626)
	at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes(MiniDFSCluster.java:421)
	at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:284)
	at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:124)
	at cascading.platform.hadoop.HadoopPlatform.setUp(HadoopPlatform.java:180)
	at cascading.PlatformTestCase.setUp(PlatformTestCase.java:161)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:303)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:69)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
	at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
	at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
	at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
2016-05-18 05:33:20,338 WARN  util.MBeans (MBeans.java:register(59)) - Hadoop:service=DataNode,name=DataNodeInfo
javax.management.InstanceAlreadyExistsException: Hadoop:service=DataNode,name=DataNodeInfo
	at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithRepository(DefaultMBeanServerInterceptor.java:1898)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:966)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)
	at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522)
	at org.apache.hadoop.metrics2.util.MBeans.register(MBeans.java:56)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.registerMXBean(DataNode.java:581)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.startDataNode(DataNode.java:422)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.<init>(DataNode.java:321)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.makeInstance(DataNode.java:1712)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1651)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1626)
	at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes(MiniDFSCluster.java:421)
	at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:284)
	at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:124)
	at cascading.platform.hadoop.HadoopPlatform.setUp(HadoopPlatform.java:180)
	at cascading.PlatformTestCase.setUp(PlatformTestCase.java:161)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:303)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:69)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
	at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
	at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
	at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
	at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
Cluster is active
Generating rack names for tasktrackers
Generating host names for tasktrackers
2016-05-18 05:33:20,657 WARN  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-jobtracker.properties, hadoop-metrics2.properties
2016-05-18 05:33:20,658 WARN  util.MBeans (MBeans.java:register(59)) - Hadoop:service=JobTracker,name=MetricsSystem,sub=Control
javax.management.InstanceAlreadyExistsException: MXBean already registered with name Hadoop:service=NameNode,name=MetricsSystem,sub=Control
	at com.sun.jmx.mbeanserver.MXBeanLookup.addReference(MXBeanLookup.java:151)
	at com.sun.jmx.mbeanserver.MXBeanSupport.register(MXBeanSupport.java:160)
	at com.sun.jmx.mbeanserver.MBeanSupport.preRegister2(MBeanSupport.java:173)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:930)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)
	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)
	at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522)
	at org.apache.hadoop.metrics2.util.MBeans.register(MBeans.java:56)
	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.initSystemMBean(MetricsSystemImpl.java:518)
	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.init(MetricsSystemImpl.java:140)
	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.init(DefaultMetricsSystem.java:40)
	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.initialize(DefaultMetricsSystem.java:50)
	at org.apache.hadoop.mapred.JobTracker.startTracker(JobTracker.java:316)
	at org.apache.hadoop.mapred.JobTracker.startTracker(JobTracker.java:311)
	at org.apache.hadoop.mapred.MiniMRCluster$JobTrackerRunner$1.run(MiniMRCluster.java:114)
	at org.apache.hadoop.mapred.MiniMRCluster$JobTrackerRunner$1.run(MiniMRCluster.java:112)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:415)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1190)
	at org.apache.hadoop.mapred.MiniMRCluster$JobTrackerRunner.run(MiniMRCluster.java:112)
	at java.lang.Thread.run(Thread.java:745)
2016-05-18 05:33:21,685 WARN  mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4422)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-05-18 05:33:21,967 WARN  mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4422)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-05-18 05:33:22,263 WARN  mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4422)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-05-18 05:33:22,486 WARN  mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4422)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-05-18 05:33:23,758 INFO  platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides: 
2016-05-18 05:33:23,850 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:23,852 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:23,928 INFO  property.AppProps (AppProps.java:getAppID(177)) - using app.id: 300B912652FA49CB93CAB03D16C4E276
2016-05-18 05:33:24,052 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-0/first-nondeterm...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.084
2016-05-18 05:33:24,056 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-0/first-nondeterm...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:33:24,057 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-0/first-nondeterm...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:24,186 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] stopping all flows
2016-05-18 05:33:24,186 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] stopped all flows
2016-05-18 05:33:24,186 INFO  util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 05:33:24,187 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] starting
2016-05-18 05:33:24,204 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:24,204 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:24,266 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.057
2016-05-18 05:33:24,267 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:33:24,268 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:24,282 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] starting
2016-05-18 05:33:24,284 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...]  parallel execution of flows is enabled: false
2016-05-18 05:33:24,284 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...]  executing total flows: 1
2016-05-18 05:33:24,285 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...]  allocating management threads: 1
2016-05-18 05:33:24,285 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] starting flow: race-50/first-nondeterministic
2016-05-18 05:33:24,285 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] at least one sink is marked for delete
2016-05-18 05:33:24,286 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:33:24,303 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] starting
2016-05-18 05:33:24,303 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/ips.20.txt"]
2016-05-18 05:33:24,304 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-50/first-nondeterministic"]
2016-05-18 05:33:24,304 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...]  parallel execution of steps is enabled: true
2016-05-18 05:33:24,304 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...]  executing total steps: 1
2016-05-18 05:33:24,304 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...]  allocating management threads: 1
2016-05-18 05:33:24,305 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] starting step: (1/1) ...50/first-nondeterministic
2016-05-18 05:33:24,332 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopping all flows
2016-05-18 05:33:24,333 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopping flow: race-50/first-nondeterministic
2016-05-18 05:33:24,333 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] stopping all jobs
2016-05-18 05:33:24,333 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] stopping: (1/1) ...50/first-nondeterministic
2016-05-18 05:33:24,334 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] stopped all jobs
2016-05-18 05:33:24,393 WARN  snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2016-05-18 05:33:24,658 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] submitted hadoop job: job_20160518053320597_0001
2016-05-18 05:33:24,659 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] tracking url: http://localhost:46565/jobdetails.jsp?jobid=job_20160518053320597_0001
2016-05-18 05:33:24,661 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopped all flows
2016-05-18 05:33:24,662 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] shutting down flow executor
2016-05-18 05:33:24,666 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...]  completed in: 00:00.030
2016-05-18 05:33:24,666 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] completed flow: race-50/first-nondeterministic
2016-05-18 05:33:24,666 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] shutdown complete
2016-05-18 05:33:24,687 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:24,687 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:24,753 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.058
2016-05-18 05:33:24,755 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:33:24,755 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:24,775 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] starting
2016-05-18 05:33:24,776 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 05:33:24,776 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...]  executing total flows: 1
2016-05-18 05:33:24,777 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:24,777 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] starting flow: race-100/first-nondeterministic
2016-05-18 05:33:24,778 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] at least one sink is marked for delete
2016-05-18 05:33:24,778 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:33:24,788 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] starting
2016-05-18 05:33:24,789 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/ips.20.txt"]
2016-05-18 05:33:24,789 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-100/first-nondeterministic"]
2016-05-18 05:33:24,789 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 05:33:24,789 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...]  executing total steps: 1
2016-05-18 05:33:24,789 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:24,794 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-05-18 05:33:24,878 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopping all flows
2016-05-18 05:33:24,878 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopping flow: race-100/first-nondeterministic
2016-05-18 05:33:24,879 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] stopping all jobs
2016-05-18 05:33:24,879 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-05-18 05:33:24,879 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] stopped all jobs
2016-05-18 05:33:25,442 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] submitted hadoop job: job_20160518053320597_0002
2016-05-18 05:33:25,442 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] tracking url: http://localhost:46565/jobdetails.jsp?jobid=job_20160518053320597_0002
2016-05-18 05:33:25,444 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopped all flows
2016-05-18 05:33:25,445 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] shutting down flow executor
2016-05-18 05:33:25,446 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...]  completed in: 00:00.091
2016-05-18 05:33:25,446 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] completed flow: race-100/first-nondeterministic
2016-05-18 05:33:25,447 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] shutdown complete
2016-05-18 05:33:25,469 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:25,470 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:25,531 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.053
2016-05-18 05:33:25,533 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:33:25,534 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:25,553 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] starting
2016-05-18 05:33:25,554 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 05:33:25,555 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...]  executing total flows: 1
2016-05-18 05:33:25,555 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:25,557 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] starting flow: race-150/first-nondeterministic
2016-05-18 05:33:25,558 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] at least one sink is marked for delete
2016-05-18 05:33:25,558 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:33:25,573 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] starting
2016-05-18 05:33:25,574 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/ips.20.txt"]
2016-05-18 05:33:25,575 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-150/first-nondeterministic"]
2016-05-18 05:33:25,575 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 05:33:25,577 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...]  executing total steps: 1
2016-05-18 05:33:25,578 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:25,583 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-05-18 05:33:25,703 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopping all flows
2016-05-18 05:33:25,731 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopping flow: race-150/first-nondeterministic
2016-05-18 05:33:25,732 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] stopping all jobs
2016-05-18 05:33:25,747 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-05-18 05:33:25,748 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] stopped all jobs
2016-05-18 05:33:26,098 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] submitted hadoop job: job_20160518053320597_0003
2016-05-18 05:33:26,098 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] tracking url: http://localhost:46565/jobdetails.jsp?jobid=job_20160518053320597_0003
2016-05-18 05:33:26,105 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopped all flows
2016-05-18 05:33:26,105 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] shutting down flow executor
2016-05-18 05:33:26,112 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...]  completed in: 00:00.159
2016-05-18 05:33:26,113 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] completed flow: race-150/first-nondeterministic
2016-05-18 05:33:26,113 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] shutdown complete
2016-05-18 05:33:26,130 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:26,131 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:26,201 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.065
2016-05-18 05:33:26,203 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:33:26,203 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:26,231 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] starting
2016-05-18 05:33:26,234 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 05:33:26,235 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...]  executing total flows: 1
2016-05-18 05:33:26,235 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:26,243 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] starting flow: race-200/first-nondeterministic
2016-05-18 05:33:26,246 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] at least one sink is marked for delete
2016-05-18 05:33:26,250 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:33:26,269 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] starting
2016-05-18 05:33:26,269 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/ips.20.txt"]
2016-05-18 05:33:26,270 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-200/first-nondeterministic"]
2016-05-18 05:33:26,270 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 05:33:26,270 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...]  executing total steps: 1
2016-05-18 05:33:26,271 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:26,274 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-05-18 05:33:26,431 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopping all flows
2016-05-18 05:33:26,435 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopping flow: race-200/first-nondeterministic
2016-05-18 05:33:26,435 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] stopping all jobs
2016-05-18 05:33:26,436 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-05-18 05:33:26,437 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] stopped all jobs
2016-05-18 05:33:26,816 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] submitted hadoop job: job_20160518053320597_0004
2016-05-18 05:33:26,816 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] tracking url: http://localhost:46565/jobdetails.jsp?jobid=job_20160518053320597_0004
2016-05-18 05:33:26,830 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopped all flows
2016-05-18 05:33:26,830 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] shutting down flow executor
2016-05-18 05:33:26,833 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...]  completed in: 00:00.166
2016-05-18 05:33:26,834 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] completed flow: race-200/first-nondeterministic
2016-05-18 05:33:26,834 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] shutdown complete
2016-05-18 05:33:26,858 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:26,861 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:27,001 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.109
2016-05-18 05:33:27,002 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:33:27,003 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:27,045 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] starting
2016-05-18 05:33:27,048 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 05:33:27,048 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...]  executing total flows: 1
2016-05-18 05:33:27,048 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:27,057 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] starting flow: race-250/first-nondeterministic
2016-05-18 05:33:27,057 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] at least one sink is marked for delete
2016-05-18 05:33:27,057 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:33:27,078 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] starting
2016-05-18 05:33:27,078 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/ips.20.txt"]
2016-05-18 05:33:27,079 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-250/first-nondeterministic"]
2016-05-18 05:33:27,079 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 05:33:27,079 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...]  executing total steps: 1
2016-05-18 05:33:27,079 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:27,089 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-05-18 05:33:27,279 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopping all flows
2016-05-18 05:33:27,283 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopping flow: race-250/first-nondeterministic
2016-05-18 05:33:27,284 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] stopping all jobs
2016-05-18 05:33:27,293 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-05-18 05:33:27,293 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] stopped all jobs
2016-05-18 05:33:28,154 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] submitted hadoop job: job_20160518053320597_0005
2016-05-18 05:33:28,154 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] tracking url: http://localhost:46565/jobdetails.jsp?jobid=job_20160518053320597_0005
2016-05-18 05:33:28,158 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopped all flows
2016-05-18 05:33:28,158 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] shutting down flow executor
2016-05-18 05:33:28,163 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...]  completed in: 00:00.206
2016-05-18 05:33:28,163 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] completed flow: race-250/first-nondeterministic
2016-05-18 05:33:28,163 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] shutdown complete
2016-05-18 05:33:28,202 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:28,203 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:28,358 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.124
2016-05-18 05:33:28,359 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:33:28,360 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:28,409 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] starting
2016-05-18 05:33:28,422 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 05:33:28,423 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...]  executing total flows: 1
2016-05-18 05:33:28,445 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:28,452 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] starting flow: race-300/first-nondeterministic
2016-05-18 05:33:28,452 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] at least one sink is marked for delete
2016-05-18 05:33:28,452 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:33:28,483 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] starting
2016-05-18 05:33:28,483 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/ips.20.txt"]
2016-05-18 05:33:28,484 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-300/first-nondeterministic"]
2016-05-18 05:33:28,485 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 05:33:28,485 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...]  executing total steps: 1
2016-05-18 05:33:28,485 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:28,492 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-05-18 05:33:28,712 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopping all flows
2016-05-18 05:33:28,755 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopping flow: race-300/first-nondeterministic
2016-05-18 05:33:28,755 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] stopping all jobs
2016-05-18 05:33:28,756 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-05-18 05:33:28,757 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] stopped all jobs
2016-05-18 05:33:29,480 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:33:29,840 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] submitted hadoop job: job_20160518053320597_0006
2016-05-18 05:33:29,841 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] tracking url: http://localhost:46565/jobdetails.jsp?jobid=job_20160518053320597_0006
2016-05-18 05:33:29,853 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopped all flows
2016-05-18 05:33:29,854 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] shutting down flow executor
2016-05-18 05:33:29,885 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...]  completed in: 00:00.272
2016-05-18 05:33:29,886 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] completed flow: race-300/first-nondeterministic
2016-05-18 05:33:29,886 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] shutdown complete
2016-05-18 05:33:29,918 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:29,918 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:30,133 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.125
2016-05-18 05:33:30,138 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:33:30,138 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:30,197 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] starting
2016-05-18 05:33:30,201 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 05:33:30,201 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...]  executing total flows: 1
2016-05-18 05:33:30,202 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:30,220 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] starting flow: race-350/first-nondeterministic
2016-05-18 05:33:30,241 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] at least one sink is marked for delete
2016-05-18 05:33:30,241 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:33:30,330 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] starting
2016-05-18 05:33:30,331 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/ips.20.txt"]
2016-05-18 05:33:30,331 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-350/first-nondeterministic"]
2016-05-18 05:33:30,331 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 05:33:30,331 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...]  executing total steps: 1
2016-05-18 05:33:30,331 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:30,356 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-05-18 05:33:30,542 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopping all flows
2016-05-18 05:33:30,557 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopping flow: race-350/first-nondeterministic
2016-05-18 05:33:30,557 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] stopping all jobs
2016-05-18 05:33:30,562 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-05-18 05:33:30,562 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] stopped all jobs
2016-05-18 05:33:31,171 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:33:31,920 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] submitted hadoop job: job_20160518053320597_0007
2016-05-18 05:33:31,920 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] tracking url: http://localhost:46565/jobdetails.jsp?jobid=job_20160518053320597_0007
2016-05-18 05:33:31,949 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopped all flows
2016-05-18 05:33:31,949 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] shutting down flow executor
2016-05-18 05:33:31,970 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...]  completed in: 00:00.227
2016-05-18 05:33:31,970 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] completed flow: race-350/first-nondeterministic
2016-05-18 05:33:31,971 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] shutdown complete
2016-05-18 05:33:32,013 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:32,014 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:32,278 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:33:32,303 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.250
2016-05-18 05:33:32,309 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:33:32,309 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:32,423 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] starting
2016-05-18 05:33:32,489 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 05:33:32,489 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...]  executing total flows: 1
2016-05-18 05:33:32,489 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:32,498 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] starting flow: race-400/first-nondeterministic
2016-05-18 05:33:32,499 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] at least one sink is marked for delete
2016-05-18 05:33:32,499 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:33:32,543 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] starting
2016-05-18 05:33:32,544 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/ips.20.txt"]
2016-05-18 05:33:32,544 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-400/first-nondeterministic"]
2016-05-18 05:33:32,546 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 05:33:32,547 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...]  executing total steps: 1
2016-05-18 05:33:32,547 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:32,599 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-05-18 05:33:32,823 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopping all flows
2016-05-18 05:33:32,836 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopping flow: race-400/first-nondeterministic
2016-05-18 05:33:32,843 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] stopping all jobs
2016-05-18 05:33:32,848 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-05-18 05:33:32,848 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] stopped all jobs
2016-05-18 05:33:34,051 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] submitted hadoop job: job_20160518053320597_0008
2016-05-18 05:33:34,052 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] tracking url: http://localhost:46565/jobdetails.jsp?jobid=job_20160518053320597_0008
2016-05-18 05:33:34,055 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopped all flows
2016-05-18 05:33:34,056 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] shutting down flow executor
2016-05-18 05:33:34,066 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...]  completed in: 00:00.300
2016-05-18 05:33:34,066 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] completed flow: race-400/first-nondeterministic
2016-05-18 05:33:34,067 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] shutdown complete
2016-05-18 05:33:34,164 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:34,165 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:34,437 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.243
2016-05-18 05:33:34,439 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:33:34,440 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:34,518 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] starting
2016-05-18 05:33:34,541 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 05:33:34,542 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...]  executing total flows: 1
2016-05-18 05:33:34,542 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:34,566 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] starting flow: race-450/first-nondeterministic
2016-05-18 05:33:34,566 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] at least one sink is marked for delete
2016-05-18 05:33:34,567 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:33:34,612 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] starting
2016-05-18 05:33:34,613 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/ips.20.txt"]
2016-05-18 05:33:34,613 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-450/first-nondeterministic"]
2016-05-18 05:33:34,614 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 05:33:34,614 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...]  executing total steps: 1
2016-05-18 05:33:34,614 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:34,656 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-05-18 05:33:35,020 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopping all flows
2016-05-18 05:33:35,037 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopping flow: race-450/first-nondeterministic
2016-05-18 05:33:35,038 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] stopping all jobs
2016-05-18 05:33:35,042 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-05-18 05:33:35,042 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] stopped all jobs
2016-05-18 05:33:35,270 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:33:36,819 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] submitted hadoop job: job_20160518053320597_0009
2016-05-18 05:33:36,819 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] tracking url: http://localhost:46565/jobdetails.jsp?jobid=job_20160518053320597_0009
2016-05-18 05:33:36,829 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopped all flows
2016-05-18 05:33:36,829 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] shutting down flow executor
2016-05-18 05:33:36,830 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...]  completed in: 00:00.426
2016-05-18 05:33:36,830 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] completed flow: race-450/first-nondeterministic
2016-05-18 05:33:36,831 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] shutdown complete
2016-05-18 05:33:36,870 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:36,872 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:37,240 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.271
2016-05-18 05:33:37,247 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:33:37,248 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:37,322 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] starting
2016-05-18 05:33:37,326 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 05:33:37,326 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...]  executing total flows: 1
2016-05-18 05:33:37,327 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:37,340 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] starting flow: race-500/first-nondeterministic
2016-05-18 05:33:37,341 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] at least one sink is marked for delete
2016-05-18 05:33:37,341 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:33:37,392 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] starting
2016-05-18 05:33:37,392 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/ips.20.txt"]
2016-05-18 05:33:37,392 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-500/first-nondeterministic"]
2016-05-18 05:33:37,393 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 05:33:37,393 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...]  executing total steps: 1
2016-05-18 05:33:37,393 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...]  allocating management threads: 1
2016-05-18 05:33:37,448 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-05-18 05:33:37,841 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopping all flows
2016-05-18 05:33:37,889 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopping flow: race-500/first-nondeterministic
2016-05-18 05:33:37,890 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] stopping all jobs
2016-05-18 05:33:37,891 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-05-18 05:33:37,891 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] stopped all jobs
2016-05-18 05:33:38,975 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:33:39,829 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] submitted hadoop job: job_20160518053320597_0010
2016-05-18 05:33:39,830 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] tracking url: http://localhost:46565/jobdetails.jsp?jobid=job_20160518053320597_0010
2016-05-18 05:33:39,843 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopped all flows
2016-05-18 05:33:39,844 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] shutting down flow executor
2016-05-18 05:33:39,845 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...]  completed in: 00:00.498
2016-05-18 05:33:39,845 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] completed flow: race-500/first-nondeterministic
2016-05-18 05:33:39,846 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] shutdown complete
2016-05-18 05:33:39,846 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-150/first-nondeterministic
2016-05-18 05:33:39,851 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-350/first-nondeterministic
2016-05-18 05:33:39,855 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-200/first-nondeterministic
2016-05-18 05:33:39,859 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-450/first-nondeterministic
2016-05-18 05:33:39,863 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-500/first-nondeterministic
2016-05-18 05:33:39,867 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-400/first-nondeterministic
2016-05-18 05:33:39,870 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-300/first-nondeterministic
2016-05-18 05:33:39,884 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-250/first-nondeterministic
2016-05-18 05:33:39,893 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-50/first-nondeterministic
2016-05-18 05:33:39,897 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-100/first-nondeterministic
2016-05-18 05:33:39,923 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-0/first-nondeterministic
2016-05-18 05:33:40,054 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:40,055 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:40,336 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.198
2016-05-18 05:33:40,337 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:33:40,337 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:40,491 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:40,492 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:40,828 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.301
2016-05-18 05:33:40,829 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:33:40,829 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:40,947 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:40,948 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:41,253 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.239
2016-05-18 05:33:41,254 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:33:41,254 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:41,351 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:41,363 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:41,600 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.155
2016-05-18 05:33:41,601 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 05:33:41,602 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:41,780 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:33:41,782 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 05:33:41,800 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:33:42,209 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.352
2016-05-18 05:33:42,243 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 05:33:42,243 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 05:33:42,544 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting
2016-05-18 05:33:42,580 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...]  parallel execution of flows is enabled: true
2016-05-18 05:33:42,581 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...]  executing total flows: 5
2016-05-18 05:33:42,581 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...]  allocating management threads: 5
2016-05-18 05:33:42,601 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: first2
2016-05-18 05:33:42,601 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] at least one sink is marked for delete
2016-05-18 05:33:42,601 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:33:42,622 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: first1
2016-05-18 05:33:42,622 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] at least one sink is marked for delete
2016-05-18 05:33:42,623 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:33:42,812 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] starting
2016-05-18 05:33:42,812 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] starting
2016-05-18 05:33:42,813 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/ips.20.txt"]
2016-05-18 05:33:42,814 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first1"]
2016-05-18 05:33:42,814 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/ips.20.txt"]
2016-05-18 05:33:42,836 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first2"]
2016-05-18 05:33:42,836 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2]  parallel execution of steps is enabled: true
2016-05-18 05:33:42,836 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2]  executing total steps: 1
2016-05-18 05:33:42,837 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2]  allocating management threads: 1
2016-05-18 05:33:42,836 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1]  parallel execution of steps is enabled: true
2016-05-18 05:33:42,837 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1]  executing total steps: 1
2016-05-18 05:33:42,837 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1]  allocating management threads: 1
2016-05-18 05:33:43,065 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] starting step: (1/1) ...atform/testCascade/first1
2016-05-18 05:33:43,184 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] starting step: (1/1) ...atform/testCascade/first2
2016-05-18 05:33:44,480 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:33:45,321 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:33:45,737 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:33:46,156 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:33:46,607 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] submitted hadoop job: job_20160518053320597_0012
2016-05-18 05:33:46,607 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] tracking url: http://localhost:46565/jobdetails.jsp?jobid=job_20160518053320597_0012
2016-05-18 05:33:46,876 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:33:47,147 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] submitted hadoop job: job_20160518053320597_0011
2016-05-18 05:33:47,147 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] tracking url: http://localhost:46565/jobdetails.jsp?jobid=job_20160518053320597_0011
2016-05-18 05:33:48,958 WARN  mapred.TaskTracker (TaskTracker.java:statusUpdate(3537)) - Failed validating JVM
java.io.IOException: JvmValidate Failed. Ignoring request from task: attempt_20160518053320597_0002_m_000000_0, with JvmId: jvm_20160518053320597_0002_m_1478014190
	at org.apache.hadoop.mapred.TaskTracker.validateJVM(TaskTracker.java:3465)
	at org.apache.hadoop.mapred.TaskTracker.statusUpdate(TaskTracker.java:3535)
	at sun.reflect.GeneratedMethodAccessor40.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:587)
	at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1432)
	at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1428)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:415)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1190)
	at org.apache.hadoop.ipc.Server$Handler.run(Server.java:1426)
2016-05-18 05:33:49,282 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:33:52,034 WARN  mapred.TaskTracker (TaskTracker.java:statusUpdate(3537)) - Failed validating JVM
java.io.IOException: JvmValidate Failed. Ignoring request from task: attempt_20160518053320597_0002_m_000001_0, with JvmId: jvm_20160518053320597_0002_m_-1345508866
	at org.apache.hadoop.mapred.TaskTracker.validateJVM(TaskTracker.java:3465)
	at org.apache.hadoop.mapred.TaskTracker.statusUpdate(TaskTracker.java:3535)
	at sun.reflect.GeneratedMethodAccessor40.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:587)
	at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1432)
	at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1428)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:415)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1190)
	at org.apache.hadoop.ipc.Server$Handler.run(Server.java:1426)
2016-05-18 05:33:52,382 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 66
2016-05-18 05:33:57,658 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:00,321 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:01,347 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:02,000 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0001 being deleted.
2016-05-18 05:34:03,270 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:04,108 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:04,407 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:04,626 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:06,450 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:08,562 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:12,500 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0002 being deleted.
2016-05-18 05:34:12,858 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0002 being deleted.
2016-05-18 05:34:13,780 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:14,653 WARN  mapred.TaskTracker (TaskTracker.java:statusUpdate(3537)) - Failed validating JVM
java.io.IOException: JvmValidate Failed. Ignoring request from task: attempt_20160518053320597_0004_m_000003_0, with JvmId: jvm_20160518053320597_0004_m_1516612450
	at org.apache.hadoop.mapred.TaskTracker.validateJVM(TaskTracker.java:3465)
	at org.apache.hadoop.mapred.TaskTracker.statusUpdate(TaskTracker.java:3535)
	at sun.reflect.GeneratedMethodAccessor40.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:587)
	at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1432)
	at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1428)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:415)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1190)
	at org.apache.hadoop.ipc.Server$Handler.run(Server.java:1426)
2016-05-18 05:34:14,809 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:15,133 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:16,299 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0003 being deleted.
2016-05-18 05:34:18,689 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:18,965 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:19,852 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:19,904 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:20,556 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:21,890 WARN  mapred.TaskTracker (TaskTracker.java:statusUpdate(3537)) - Failed validating JVM
java.io.IOException: JvmValidate Failed. Ignoring request from task: attempt_20160518053320597_0006_m_000001_0, with JvmId: jvm_20160518053320597_0006_m_-1447391368
	at org.apache.hadoop.mapred.TaskTracker.validateJVM(TaskTracker.java:3465)
	at org.apache.hadoop.mapred.TaskTracker.statusUpdate(TaskTracker.java:3535)
	at sun.reflect.GeneratedMethodAccessor40.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:587)
	at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1432)
	at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1428)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:415)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1190)
	at org.apache.hadoop.ipc.Server$Handler.run(Server.java:1426)
2016-05-18 05:34:22,003 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:26,504 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0004 being deleted.
2016-05-18 05:34:26,860 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0004 being deleted.
2016-05-18 05:34:28,778 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:29,056 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:31,236 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:32,016 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0005 being deleted.
2016-05-18 05:34:33,384 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:33,600 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:33,806 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:34,174 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:34,297 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:36,982 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:38,861 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0006 being deleted.
2016-05-18 05:34:40,520 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0006 being deleted.
2016-05-18 05:34:40,991 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:43,177 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:43,674 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:45,295 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:46,017 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0007 being deleted.
2016-05-18 05:34:46,306 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0007 being deleted.
2016-05-18 05:34:48,078 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:48,200 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:48,661 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:48,904 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:49,417 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:50,741 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:52,307 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0009 being deleted.
2016-05-18 05:34:52,897 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0008 being deleted.
2016-05-18 05:34:54,550 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0008 being deleted.
2016-05-18 05:34:56,728 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:34:56,870 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:03,298 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first2/_temporary
2016-05-18 05:35:03,299 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2]  completed in: 01:20.483
2016-05-18 05:35:03,299 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: first2
2016-05-18 05:35:03,300 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: second2
2016-05-18 05:35:03,300 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] at least one sink is marked for delete
2016-05-18 05:35:03,300 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:35:03,319 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] starting
2016-05-18 05:35:03,319 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2]  source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first2"]
2016-05-18 05:35:03,320 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2]  sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second2"]
2016-05-18 05:35:03,320 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2]  parallel execution of steps is enabled: true
2016-05-18 05:35:03,320 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2]  executing total steps: 1
2016-05-18 05:35:03,320 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2]  allocating management threads: 1
2016-05-18 05:35:03,336 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] starting step: (1/1) ...tform/testCascade/second2
2016-05-18 05:35:03,894 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] submitted hadoop job: job_20160518053320597_0013
2016-05-18 05:35:03,895 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] tracking url: http://localhost:46565/jobdetails.jsp?jobid=job_20160518053320597_0013
2016-05-18 05:35:04,025 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0012 being deleted.
2016-05-18 05:35:04,551 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0010 being deleted.
2016-05-18 05:35:04,740 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:04,819 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:04,998 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:05,441 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:05,495 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:05,860 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:05,949 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:07,131 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:07,136 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first1/_temporary
2016-05-18 05:35:07,138 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1]  completed in: 01:24.322
2016-05-18 05:35:07,139 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: first1
2016-05-18 05:35:07,139 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: second1
2016-05-18 05:35:07,139 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] at least one sink is marked for delete
2016-05-18 05:35:07,139 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:35:07,145 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] starting
2016-05-18 05:35:07,145 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1]  source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first1"]
2016-05-18 05:35:07,146 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1]  sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second1"]
2016-05-18 05:35:07,146 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1]  parallel execution of steps is enabled: true
2016-05-18 05:35:07,146 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1]  executing total steps: 1
2016-05-18 05:35:07,146 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1]  allocating management threads: 1
2016-05-18 05:35:07,147 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] starting step: (1/1) ...tform/testCascade/second1
2016-05-18 05:35:08,112 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] submitted hadoop job: job_20160518053320597_0014
2016-05-18 05:35:08,113 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] tracking url: http://localhost:46565/jobdetails.jsp?jobid=job_20160518053320597_0014
2016-05-18 05:35:08,682 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:08,916 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0011 being deleted.
2016-05-18 05:35:09,776 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:09,819 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:14,880 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:15,175 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:16,304 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second2/_temporary
2016-05-18 05:35:16,306 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2]  completed in: 00:12.985
2016-05-18 05:35:16,306 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: second2
2016-05-18 05:35:16,311 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0013 being deleted.
2016-05-18 05:35:17,323 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:18,430 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:22,641 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second1/_temporary
2016-05-18 05:35:22,643 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1]  completed in: 00:15.496
2016-05-18 05:35:22,644 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: second1
2016-05-18 05:35:22,644 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: lhs*rhs
2016-05-18 05:35:22,644 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] at least one sink is marked for delete
2016-05-18 05:35:22,644 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 05:35:22,647 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] starting
2016-05-18 05:35:22,647 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second2"]
2016-05-18 05:35:22,647 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second1"]
2016-05-18 05:35:22,647 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/third"]
2016-05-18 05:35:22,648 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  parallel execution of steps is enabled: true
2016-05-18 05:35:22,648 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  executing total steps: 1
2016-05-18 05:35:22,648 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  allocating management threads: 1
2016-05-18 05:35:22,649 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] starting step: (1/1) ...latform/testCascade/third
2016-05-18 05:35:23,161 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] submitted hadoop job: job_20160518053320597_0015
2016-05-18 05:35:23,162 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] tracking url: http://localhost:46565/jobdetails.jsp?jobid=job_20160518053320597_0015
2016-05-18 05:35:23,389 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:23,474 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:24,028 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2235)) - Unknown job job_20160518053320597_0014 being deleted.
2016-05-18 05:35:25,095 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:25,341 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:25,412 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 05:35:45,148 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/third/_temporary
2016-05-18 05:35:45,149 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  completed in: 00:22.500
2016-05-18 05:35:45,149 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: lhs*rhs
2016-05-18 05:35:45,170 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascade/second2
2016-05-18 05:35:45,180 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascade/second1
2016-05-18 05:35:45,191 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascade/third
2016-05-18 05:35:45,195 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascade/first2
2016-05-18 05:35:45,204 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/parallelcascadeplatform/testCascade/first1