Class cascading.cascade.ParallelCascadePlatformTest

2

tests

0

failures

0

ignored

2m29.62s

duration

100%

successful

Tests

Test Duration Result
testCascade 2m7.93s passed
testCascadeRaceCondition 21.690s passed

Standard output

2016-01-14 22:09:03,646 INFO  platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 22:09:03,663 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.cascade.ParallelCascadePlatformTest, with platform: hadoop
2016-01-14 22:09:03,688 INFO  hadoop.HadoopPlatform (HadoopPlatform.java:setUp(144)) - using cluster
2016-01-14 22:09:04,544 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-01-14 22:09:05,465 WARN  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-01-14 22:09:05,515 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:500)
	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:1589)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1565)
	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:301)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:68)
	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 1 with dfs.data.dir: build/test/data/dfs/data/data3,build/test/data/dfs/data/data4
2016-01-14 22:09:05,913 WARN  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-01-14 22:09:05,914 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:500)
	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:1589)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1565)
	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:301)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:68)
	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-01-14 22:09:05,989 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:554)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.startDataNode(DataNode.java:407)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.<init>(DataNode.java:309)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.makeInstance(DataNode.java:1651)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1590)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1565)
	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:301)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:68)
	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-01-14 22:09:06,217 WARN  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-01-14 22:09:06,218 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:500)
	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:1589)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1565)
	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:301)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:68)
	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-01-14 22:09:06,293 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:554)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.startDataNode(DataNode.java:407)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.<init>(DataNode.java:309)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.makeInstance(DataNode.java:1651)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1590)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1565)
	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:301)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:68)
	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-01-14 22:09:06,500 WARN  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-01-14 22:09:06,502 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:500)
	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:1589)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1565)
	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:301)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:68)
	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-01-14 22:09:06,578 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:554)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.startDataNode(DataNode.java:407)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.<init>(DataNode.java:309)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.makeInstance(DataNode.java:1651)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1590)
	at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1565)
	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:301)
	at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:68)
	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-01-14 22:09:06,836 WARN  impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-jobtracker.properties, hadoop-metrics2.properties
2016-01-14 22:09:06,836 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:500)
	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:308)
	at org.apache.hadoop.mapred.JobTracker.startTracker(JobTracker.java:303)
	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:1149)
	at org.apache.hadoop.mapred.MiniMRCluster$JobTrackerRunner.run(MiniMRCluster.java:112)
	at java.lang.Thread.run(Thread.java:745)
2016-01-14 22:09:07,799 WARN  util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-01-14 22:09:07,881 WARN  mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4391)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-01-14 22:09:08,138 WARN  mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4391)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-01-14 22:09:08,361 WARN  mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4391)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-01-14 22:09:08,568 WARN  mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4391)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-01-14 22:09:09,791 INFO  platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides: 
2016-01-14 22:09:09,887 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:09,888 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:09,964 INFO  property.AppProps (AppProps.java:getAppID(177)) - using app.id: DD19A76FD06D46B6B5C7A9DBD9B7232D
2016-01-14 22:09:10,085 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-0/first-nondeterm...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.084
2016-01-14 22:09:10,088 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-0/first-nondeterm...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 22:09:10,088 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-0/first-nondeterm...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:10,195 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] stopping all flows
2016-01-14 22:09:10,195 INFO  util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 22:09:10,195 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] stopped all flows
2016-01-14 22:09:10,196 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] starting
2016-01-14 22:09:10,215 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:10,216 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:10,268 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.046
2016-01-14 22:09:10,269 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 22:09:10,269 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:10,283 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] starting
2016-01-14 22:09:10,285 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...]  parallel execution of flows is enabled: false
2016-01-14 22:09:10,286 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...]  executing total flows: 1
2016-01-14 22:09:10,286 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...]  allocating management threads: 1
2016-01-14 22:09:10,286 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] starting flow: race-50/first-nondeterministic
2016-01-14 22:09:10,287 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] at least one sink is marked for delete
2016-01-14 22:09:10,287 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 22:09:10,303 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] starting
2016-01-14 22:09:10,304 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-01-14 22:09:10,305 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-50/first-nondeterministic"]
2016-01-14 22:09:10,305 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...]  parallel execution of steps is enabled: true
2016-01-14 22:09:10,305 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...]  executing total steps: 1
2016-01-14 22:09:10,306 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...]  allocating management threads: 1
2016-01-14 22:09:10,307 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] starting step: (1/1) ...50/first-nondeterministic
2016-01-14 22:09:10,333 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopping all flows
2016-01-14 22:09:10,334 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopping flow: race-50/first-nondeterministic
2016-01-14 22:09:10,335 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] stopping all jobs
2016-01-14 22:09:10,336 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] stopping: (1/1) ...50/first-nondeterministic
2016-01-14 22:09:10,337 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] stopped all jobs
2016-01-14 22:09:10,338 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] shutting down job executor
2016-01-14 22:09:10,385 WARN  snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2016-01-14 22:09:10,627 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] submitted hadoop job: job_20160114220906794_0001
2016-01-14 22:09:10,627 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] tracking url: http://localhost:50660/jobdetails.jsp?jobid=job_20160114220906794_0001
2016-01-14 22:09:10,632 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] shutdown complete
2016-01-14 22:09:10,633 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopped all flows
2016-01-14 22:09:10,633 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] shutting down flow executor
2016-01-14 22:09:10,637 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...]  completed in: 00:00.032
2016-01-14 22:09:10,637 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] completed flow: race-50/first-nondeterministic
2016-01-14 22:09:10,638 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] shutdown complete
2016-01-14 22:09:10,652 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:10,653 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:10,714 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.053
2016-01-14 22:09:10,715 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 22:09:10,716 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:10,740 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] starting
2016-01-14 22:09:10,741 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...]  parallel execution of flows is enabled: false
2016-01-14 22:09:10,741 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...]  executing total flows: 1
2016-01-14 22:09:10,742 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:10,742 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] starting flow: race-100/first-nondeterministic
2016-01-14 22:09:10,743 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] at least one sink is marked for delete
2016-01-14 22:09:10,743 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 22:09:10,750 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] starting
2016-01-14 22:09:10,751 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-01-14 22:09:10,752 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-100/first-nondeterministic"]
2016-01-14 22:09:10,752 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...]  parallel execution of steps is enabled: true
2016-01-14 22:09:10,752 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...]  executing total steps: 1
2016-01-14 22:09:10,753 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:10,754 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-01-14 22:09:10,840 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopping all flows
2016-01-14 22:09:10,842 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopping flow: race-100/first-nondeterministic
2016-01-14 22:09:10,843 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] stopping all jobs
2016-01-14 22:09:10,845 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-01-14 22:09:10,846 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] stopped all jobs
2016-01-14 22:09:10,846 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] shutting down job executor
2016-01-14 22:09:11,809 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] submitted hadoop job: job_20160114220906794_0002
2016-01-14 22:09:11,809 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] tracking url: http://localhost:50660/jobdetails.jsp?jobid=job_20160114220906794_0002
2016-01-14 22:09:11,812 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] shutdown complete
2016-01-14 22:09:11,812 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopped all flows
2016-01-14 22:09:11,813 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] shutting down flow executor
2016-01-14 22:09:11,824 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...]  completed in: 00:00.093
2016-01-14 22:09:11,824 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] completed flow: race-100/first-nondeterministic
2016-01-14 22:09:11,825 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] shutdown complete
2016-01-14 22:09:11,853 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:11,856 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:11,916 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.045
2016-01-14 22:09:11,917 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 22:09:11,918 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:11,937 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] starting
2016-01-14 22:09:11,941 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...]  parallel execution of flows is enabled: false
2016-01-14 22:09:11,944 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...]  executing total flows: 1
2016-01-14 22:09:11,944 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:11,945 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] starting flow: race-150/first-nondeterministic
2016-01-14 22:09:11,946 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] at least one sink is marked for delete
2016-01-14 22:09:11,946 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 22:09:11,954 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] starting
2016-01-14 22:09:11,958 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-01-14 22:09:11,958 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-150/first-nondeterministic"]
2016-01-14 22:09:11,958 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...]  parallel execution of steps is enabled: true
2016-01-14 22:09:11,958 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...]  executing total steps: 1
2016-01-14 22:09:11,958 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:11,959 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-01-14 22:09:12,087 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopping all flows
2016-01-14 22:09:12,097 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopping flow: race-150/first-nondeterministic
2016-01-14 22:09:12,097 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] stopping all jobs
2016-01-14 22:09:12,098 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-01-14 22:09:12,098 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] stopped all jobs
2016-01-14 22:09:12,099 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] shutting down job executor
2016-01-14 22:09:12,215 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] submitted hadoop job: job_20160114220906794_0003
2016-01-14 22:09:12,216 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] tracking url: http://localhost:50660/jobdetails.jsp?jobid=job_20160114220906794_0003
2016-01-14 22:09:12,220 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] shutdown complete
2016-01-14 22:09:12,220 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopped all flows
2016-01-14 22:09:12,224 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] shutting down flow executor
2016-01-14 22:09:12,224 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...]  completed in: 00:00.143
2016-01-14 22:09:12,225 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] completed flow: race-150/first-nondeterministic
2016-01-14 22:09:12,226 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] shutdown complete
2016-01-14 22:09:12,254 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:12,255 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:12,357 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.089
2016-01-14 22:09:12,364 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 22:09:12,365 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:12,387 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] starting
2016-01-14 22:09:12,390 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...]  parallel execution of flows is enabled: false
2016-01-14 22:09:12,390 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...]  executing total flows: 1
2016-01-14 22:09:12,391 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:12,402 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] starting flow: race-200/first-nondeterministic
2016-01-14 22:09:12,408 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] at least one sink is marked for delete
2016-01-14 22:09:12,409 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 22:09:12,444 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] starting
2016-01-14 22:09:12,445 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-01-14 22:09:12,446 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-200/first-nondeterministic"]
2016-01-14 22:09:12,447 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...]  parallel execution of steps is enabled: true
2016-01-14 22:09:12,448 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...]  executing total steps: 1
2016-01-14 22:09:12,449 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:12,466 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-01-14 22:09:12,592 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopping all flows
2016-01-14 22:09:12,596 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopping flow: race-200/first-nondeterministic
2016-01-14 22:09:12,597 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] stopping all jobs
2016-01-14 22:09:12,601 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-01-14 22:09:12,601 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] stopped all jobs
2016-01-14 22:09:12,602 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] shutting down job executor
2016-01-14 22:09:13,003 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] submitted hadoop job: job_20160114220906794_0004
2016-01-14 22:09:13,003 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] tracking url: http://localhost:50660/jobdetails.jsp?jobid=job_20160114220906794_0004
2016-01-14 22:09:13,009 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] shutdown complete
2016-01-14 22:09:13,009 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopped all flows
2016-01-14 22:09:13,010 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] shutting down flow executor
2016-01-14 22:09:13,011 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...]  completed in: 00:00.153
2016-01-14 22:09:13,012 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] completed flow: race-200/first-nondeterministic
2016-01-14 22:09:13,013 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] shutdown complete
2016-01-14 22:09:13,044 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:13,045 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:13,193 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.122
2016-01-14 22:09:13,195 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 22:09:13,196 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:13,234 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] starting
2016-01-14 22:09:13,241 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...]  parallel execution of flows is enabled: false
2016-01-14 22:09:13,241 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...]  executing total flows: 1
2016-01-14 22:09:13,242 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:13,256 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] starting flow: race-250/first-nondeterministic
2016-01-14 22:09:13,259 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] at least one sink is marked for delete
2016-01-14 22:09:13,260 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 22:09:13,300 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] starting
2016-01-14 22:09:13,301 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-01-14 22:09:13,301 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-250/first-nondeterministic"]
2016-01-14 22:09:13,301 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...]  parallel execution of steps is enabled: true
2016-01-14 22:09:13,302 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...]  executing total steps: 1
2016-01-14 22:09:13,302 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:13,335 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-01-14 22:09:13,483 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopping all flows
2016-01-14 22:09:13,488 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopping flow: race-250/first-nondeterministic
2016-01-14 22:09:13,488 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] stopping all jobs
2016-01-14 22:09:13,489 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-01-14 22:09:13,489 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] stopped all jobs
2016-01-14 22:09:13,490 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] shutting down job executor
2016-01-14 22:09:13,906 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] submitted hadoop job: job_20160114220906794_0005
2016-01-14 22:09:13,906 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] tracking url: http://localhost:50660/jobdetails.jsp?jobid=job_20160114220906794_0005
2016-01-14 22:09:13,954 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] shutdown complete
2016-01-14 22:09:13,955 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopped all flows
2016-01-14 22:09:13,955 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] shutting down flow executor
2016-01-14 22:09:13,960 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...]  completed in: 00:00.188
2016-01-14 22:09:13,961 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] completed flow: race-250/first-nondeterministic
2016-01-14 22:09:13,973 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] shutdown complete
2016-01-14 22:09:13,998 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:14,001 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:14,155 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.121
2016-01-14 22:09:14,170 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 22:09:14,170 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:14,254 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] starting
2016-01-14 22:09:14,285 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...]  parallel execution of flows is enabled: false
2016-01-14 22:09:14,285 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...]  executing total flows: 1
2016-01-14 22:09:14,285 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:14,312 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] starting flow: race-300/first-nondeterministic
2016-01-14 22:09:14,313 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] at least one sink is marked for delete
2016-01-14 22:09:14,314 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 22:09:14,385 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] starting
2016-01-14 22:09:14,385 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-01-14 22:09:14,386 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-300/first-nondeterministic"]
2016-01-14 22:09:14,386 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...]  parallel execution of steps is enabled: true
2016-01-14 22:09:14,386 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...]  executing total steps: 1
2016-01-14 22:09:14,386 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:14,409 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-01-14 22:09:14,570 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopping all flows
2016-01-14 22:09:14,584 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopping flow: race-300/first-nondeterministic
2016-01-14 22:09:14,585 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] stopping all jobs
2016-01-14 22:09:14,599 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-01-14 22:09:14,600 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] stopped all jobs
2016-01-14 22:09:14,601 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] shutting down job executor
2016-01-14 22:09:15,615 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] submitted hadoop job: job_20160114220906794_0006
2016-01-14 22:09:15,615 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] tracking url: http://localhost:50660/jobdetails.jsp?jobid=job_20160114220906794_0006
2016-01-14 22:09:15,619 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] shutdown complete
2016-01-14 22:09:15,620 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopped all flows
2016-01-14 22:09:15,620 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] shutting down flow executor
2016-01-14 22:09:15,665 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...]  completed in: 00:00.200
2016-01-14 22:09:15,666 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] completed flow: race-300/first-nondeterministic
2016-01-14 22:09:15,666 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] shutdown complete
2016-01-14 22:09:15,714 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:15,740 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:15,968 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.136
2016-01-14 22:09:15,969 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 22:09:15,970 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:16,012 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] starting
2016-01-14 22:09:16,041 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...]  parallel execution of flows is enabled: false
2016-01-14 22:09:16,042 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...]  executing total flows: 1
2016-01-14 22:09:16,042 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:16,059 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] starting flow: race-350/first-nondeterministic
2016-01-14 22:09:16,060 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] at least one sink is marked for delete
2016-01-14 22:09:16,060 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 22:09:16,080 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] starting
2016-01-14 22:09:16,081 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-01-14 22:09:16,082 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-350/first-nondeterministic"]
2016-01-14 22:09:16,082 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...]  parallel execution of steps is enabled: true
2016-01-14 22:09:16,083 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...]  executing total steps: 1
2016-01-14 22:09:16,083 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:16,098 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-01-14 22:09:16,362 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopping all flows
2016-01-14 22:09:16,398 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopping flow: race-350/first-nondeterministic
2016-01-14 22:09:16,399 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] stopping all jobs
2016-01-14 22:09:16,415 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-01-14 22:09:16,415 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] stopped all jobs
2016-01-14 22:09:16,415 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] shutting down job executor
2016-01-14 22:09:17,159 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] submitted hadoop job: job_20160114220906794_0007
2016-01-14 22:09:17,159 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] tracking url: http://localhost:50660/jobdetails.jsp?jobid=job_20160114220906794_0007
2016-01-14 22:09:17,173 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...]  completed in: 00:00.319
2016-01-14 22:09:17,176 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] shutdown complete
2016-01-14 22:09:17,176 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopped all flows
2016-01-14 22:09:17,176 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] shutting down flow executor
2016-01-14 22:09:17,177 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] completed flow: race-350/first-nondeterministic
2016-01-14 22:09:17,177 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] shutdown complete
2016-01-14 22:09:17,262 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:17,264 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:17,505 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.172
2016-01-14 22:09:17,506 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 22:09:17,506 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:17,653 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] starting
2016-01-14 22:09:17,665 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...]  parallel execution of flows is enabled: false
2016-01-14 22:09:17,665 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...]  executing total flows: 1
2016-01-14 22:09:17,665 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:17,723 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] starting flow: race-400/first-nondeterministic
2016-01-14 22:09:17,723 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] at least one sink is marked for delete
2016-01-14 22:09:17,724 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 22:09:17,816 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] starting
2016-01-14 22:09:17,816 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-01-14 22:09:17,817 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-400/first-nondeterministic"]
2016-01-14 22:09:17,817 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...]  parallel execution of steps is enabled: true
2016-01-14 22:09:17,817 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...]  executing total steps: 1
2016-01-14 22:09:17,817 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:17,919 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-01-14 22:09:18,041 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopping all flows
2016-01-14 22:09:18,064 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopping flow: race-400/first-nondeterministic
2016-01-14 22:09:18,065 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] stopping all jobs
2016-01-14 22:09:18,087 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-01-14 22:09:18,088 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] stopped all jobs
2016-01-14 22:09:18,088 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] shutting down job executor
2016-01-14 22:09:19,532 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] submitted hadoop job: job_20160114220906794_0008
2016-01-14 22:09:19,532 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] tracking url: http://localhost:50660/jobdetails.jsp?jobid=job_20160114220906794_0008
2016-01-14 22:09:19,575 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] shutdown complete
2016-01-14 22:09:19,575 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopped all flows
2016-01-14 22:09:19,575 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] shutting down flow executor
2016-01-14 22:09:19,608 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...]  completed in: 00:00.249
2016-01-14 22:09:19,609 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] completed flow: race-400/first-nondeterministic
2016-01-14 22:09:19,609 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] shutdown complete
2016-01-14 22:09:19,651 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:19,652 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:19,984 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.278
2016-01-14 22:09:19,985 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 22:09:19,986 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:20,060 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] starting
2016-01-14 22:09:20,100 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...]  parallel execution of flows is enabled: false
2016-01-14 22:09:20,100 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...]  executing total flows: 1
2016-01-14 22:09:20,100 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:20,169 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] starting flow: race-450/first-nondeterministic
2016-01-14 22:09:20,170 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] at least one sink is marked for delete
2016-01-14 22:09:20,171 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 22:09:20,207 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] starting
2016-01-14 22:09:20,208 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-01-14 22:09:20,208 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-450/first-nondeterministic"]
2016-01-14 22:09:20,209 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...]  parallel execution of steps is enabled: true
2016-01-14 22:09:20,210 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...]  executing total steps: 1
2016-01-14 22:09:20,210 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:20,235 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-01-14 22:09:20,386 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:20,502 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopping all flows
2016-01-14 22:09:20,545 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopping flow: race-450/first-nondeterministic
2016-01-14 22:09:20,546 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] stopping all jobs
2016-01-14 22:09:20,620 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-01-14 22:09:20,621 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] stopped all jobs
2016-01-14 22:09:20,621 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] shutting down job executor
2016-01-14 22:09:22,058 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] submitted hadoop job: job_20160114220906794_0009
2016-01-14 22:09:22,059 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] tracking url: http://localhost:50660/jobdetails.jsp?jobid=job_20160114220906794_0009
2016-01-14 22:09:22,115 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] shutdown complete
2016-01-14 22:09:22,116 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopped all flows
2016-01-14 22:09:22,116 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] shutting down flow executor
2016-01-14 22:09:22,142 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...]  completed in: 00:00.340
2016-01-14 22:09:22,142 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] completed flow: race-450/first-nondeterministic
2016-01-14 22:09:22,143 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] shutdown complete
2016-01-14 22:09:22,180 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:22,181 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:22,541 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.297
2016-01-14 22:09:22,548 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 22:09:22,549 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:22,623 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] starting
2016-01-14 22:09:22,668 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...]  parallel execution of flows is enabled: false
2016-01-14 22:09:22,668 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...]  executing total flows: 1
2016-01-14 22:09:22,669 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:22,683 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] starting flow: race-500/first-nondeterministic
2016-01-14 22:09:22,685 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] at least one sink is marked for delete
2016-01-14 22:09:22,687 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 22:09:22,803 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] starting
2016-01-14 22:09:22,804 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-01-14 22:09:22,805 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-500/first-nondeterministic"]
2016-01-14 22:09:22,808 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...]  parallel execution of steps is enabled: true
2016-01-14 22:09:22,808 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...]  executing total steps: 1
2016-01-14 22:09:22,809 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...]  allocating management threads: 1
2016-01-14 22:09:22,909 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-01-14 22:09:23,123 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopping all flows
2016-01-14 22:09:23,124 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopping flow: race-500/first-nondeterministic
2016-01-14 22:09:23,124 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] stopping all jobs
2016-01-14 22:09:23,153 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-01-14 22:09:23,153 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] stopped all jobs
2016-01-14 22:09:23,154 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] shutting down job executor
2016-01-14 22:09:23,616 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:24,925 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] submitted hadoop job: job_20160114220906794_0010
2016-01-14 22:09:24,926 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] tracking url: http://localhost:50660/jobdetails.jsp?jobid=job_20160114220906794_0010
2016-01-14 22:09:24,984 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] shutdown complete
2016-01-14 22:09:24,985 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopped all flows
2016-01-14 22:09:24,985 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] shutting down flow executor
2016-01-14 22:09:24,990 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...]  completed in: 00:00.321
2016-01-14 22:09:24,990 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] completed flow: race-500/first-nondeterministic
2016-01-14 22:09:24,991 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] shutdown complete
2016-01-14 22:09:24,991 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-50/first-nondeterministic
2016-01-14 22:09:25,052 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-0/first-nondeterministic
2016-01-14 22:09:25,053 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-150/first-nondeterministic
2016-01-14 22:09:25,056 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-450/first-nondeterministic
2016-01-14 22:09:25,059 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-250/first-nondeterministic
2016-01-14 22:09:25,067 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-350/first-nondeterministic
2016-01-14 22:09:25,072 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-200/first-nondeterministic
2016-01-14 22:09:25,079 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-400/first-nondeterministic
2016-01-14 22:09:25,085 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-300/first-nondeterministic
2016-01-14 22:09:25,217 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-500/first-nondeterministic
2016-01-14 22:09:25,230 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-100/first-nondeterministic
2016-01-14 22:09:25,464 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:25,464 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:25,693 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.188
2016-01-14 22:09:25,709 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 22:09:25,709 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:25,871 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:25,871 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:26,142 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.244
2016-01-14 22:09:26,176 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 22:09:26,177 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:26,450 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:26,451 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:26,763 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.259
2016-01-14 22:09:26,773 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 22:09:26,773 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:26,827 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:26,878 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:26,896 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:27,386 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.251
2016-01-14 22:09:27,388 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 22:09:27,388 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:27,576 INFO  util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 22:09:27,577 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 22:09:28,061 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.405
2016-01-14 22:09:28,062 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 22:09:28,063 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 22:09:28,302 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting
2016-01-14 22:09:28,366 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...]  parallel execution of flows is enabled: true
2016-01-14 22:09:28,367 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...]  executing total flows: 5
2016-01-14 22:09:28,367 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...]  allocating management threads: 5
2016-01-14 22:09:28,392 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: first2
2016-01-14 22:09:28,392 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] at least one sink is marked for delete
2016-01-14 22:09:28,392 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 22:09:28,402 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:28,418 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: first1
2016-01-14 22:09:28,419 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] at least one sink is marked for delete
2016-01-14 22:09:28,419 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 22:09:28,523 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] starting
2016-01-14 22:09:28,524 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first1]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-01-14 22:09:28,525 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first1]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first1"]
2016-01-14 22:09:28,525 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first1]  parallel execution of steps is enabled: true
2016-01-14 22:09:28,526 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first1]  executing total steps: 1
2016-01-14 22:09:28,526 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first1]  allocating management threads: 1
2016-01-14 22:09:28,557 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] starting
2016-01-14 22:09:28,557 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first2]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-01-14 22:09:28,557 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first2]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first2"]
2016-01-14 22:09:28,557 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first2]  parallel execution of steps is enabled: true
2016-01-14 22:09:28,558 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first2]  executing total steps: 1
2016-01-14 22:09:28,558 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first2]  allocating management threads: 1
2016-01-14 22:09:28,577 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] starting step: (1/1) ...atform/testCascade/first1
2016-01-14 22:09:28,612 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] starting step: (1/1) ...atform/testCascade/first2
2016-01-14 22:09:29,856 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:30,879 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:31,232 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:31,488 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:31,891 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] submitted hadoop job: job_20160114220906794_0011
2016-01-14 22:09:31,892 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] tracking url: http://localhost:50660/jobdetails.jsp?jobid=job_20160114220906794_0011
2016-01-14 22:09:32,695 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] submitted hadoop job: job_20160114220906794_0012
2016-01-14 22:09:32,696 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] tracking url: http://localhost:50660/jobdetails.jsp?jobid=job_20160114220906794_0012
2016-01-14 22:09:35,768 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:40,900 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:40,969 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:44,874 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:46,567 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:46,864 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:50,145 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:50,840 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:51,149 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:53,202 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:54,552 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160114220906794_0002 being deleted.
2016-01-14 22:09:54,561 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160114220906794_0002 being deleted.
2016-01-14 22:09:55,332 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:09:58,322 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:01,858 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:02,103 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160114220906794_0003 being deleted.
2016-01-14 22:10:02,550 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:03,231 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:05,451 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:05,909 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:06,560 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:07,100 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:08,563 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160114220906794_0004 being deleted.
2016-01-14 22:10:09,425 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:12,931 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:15,836 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:16,602 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:16,903 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:18,106 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160114220906794_0005 being deleted.
2016-01-14 22:10:20,157 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:20,595 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:20,884 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:21,124 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:21,266 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:24,598 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160114220906794_0006 being deleted.
2016-01-14 22:10:26,514 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:28,065 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:30,248 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:31,121 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:31,824 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:32,108 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160114220906794_0007 being deleted.
2016-01-14 22:10:35,243 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:35,297 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:35,645 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:35,884 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:39,568 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:42,138 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:46,110 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160114220906794_0009 being deleted.
2016-01-14 22:10:47,552 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:49,625 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first1/_temporary
2016-01-14 22:10:49,627 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first1]  completed in: 01:21.098
2016-01-14 22:10:49,627 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: first1
2016-01-14 22:10:49,627 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: second1
2016-01-14 22:10:49,627 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] at least one sink is marked for delete
2016-01-14 22:10:49,627 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 22:10:49,630 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] starting
2016-01-14 22:10:49,631 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second1]  source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first1"]
2016-01-14 22:10:49,631 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second1]  sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second1"]
2016-01-14 22:10:49,631 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second1]  parallel execution of steps is enabled: true
2016-01-14 22:10:49,631 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second1]  executing total steps: 1
2016-01-14 22:10:49,632 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second1]  allocating management threads: 1
2016-01-14 22:10:49,632 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] starting step: (1/1) ...tform/testCascade/second1
2016-01-14 22:10:50,325 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:50,572 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] submitted hadoop job: job_20160114220906794_0013
2016-01-14 22:10:50,572 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] tracking url: http://localhost:50660/jobdetails.jsp?jobid=job_20160114220906794_0013
2016-01-14 22:10:50,602 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160114220906794_0010 being deleted.
2016-01-14 22:10:50,814 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:50,925 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:51,211 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:51,687 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:51,740 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:53,347 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:53,375 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first2/_temporary
2016-01-14 22:10:53,377 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [first2]  completed in: 01:24.816
2016-01-14 22:10:53,377 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: first2
2016-01-14 22:10:53,377 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: second2
2016-01-14 22:10:53,378 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] at least one sink is marked for delete
2016-01-14 22:10:53,378 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 22:10:53,380 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] starting
2016-01-14 22:10:53,381 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second2]  source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first2"]
2016-01-14 22:10:53,381 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second2]  sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second2"]
2016-01-14 22:10:53,382 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second2]  parallel execution of steps is enabled: true
2016-01-14 22:10:53,382 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second2]  executing total steps: 1
2016-01-14 22:10:53,383 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second2]  allocating management threads: 1
2016-01-14 22:10:53,384 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] starting step: (1/1) ...tform/testCascade/second2
2016-01-14 22:10:53,516 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:53,569 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:53,687 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:54,216 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] submitted hadoop job: job_20160114220906794_0014
2016-01-14 22:10:54,216 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] tracking url: http://localhost:50660/jobdetails.jsp?jobid=job_20160114220906794_0014
2016-01-14 22:10:54,602 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160114220906794_0012 being deleted.
2016-01-14 22:10:55,613 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:10:55,740 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:11:00,856 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:11:01,072 WARN  mapred.TaskTracker (TaskTracker.java:statusUpdate(3506)) - Failed validating JVM
java.io.IOException: JvmValidate Failed. Ignoring request from task: attempt_20160114220906794_0013_m_000004_0, with JvmId: jvm_20160114220906794_0013_m_118787782
	at org.apache.hadoop.mapred.TaskTracker.validateJVM(TaskTracker.java:3434)
	at org.apache.hadoop.mapred.TaskTracker.statusUpdate(TaskTracker.java:3504)
	at sun.reflect.GeneratedMethodAccessor35.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:578)
	at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1393)
	at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1389)
	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:1149)
	at org.apache.hadoop.ipc.Server$Handler.run(Server.java:1387)
2016-01-14 22:11:01,189 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:11:02,855 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second1/_temporary
2016-01-14 22:11:02,856 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second1]  completed in: 00:13.224
2016-01-14 22:11:02,857 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: second1
2016-01-14 22:11:04,623 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160114220906794_0013 being deleted.
2016-01-14 22:11:05,707 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:11:09,569 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second2/_temporary
2016-01-14 22:11:09,570 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [second2]  completed in: 00:16.188
2016-01-14 22:11:09,570 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: second2
2016-01-14 22:11:09,570 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: lhs*rhs
2016-01-14 22:11:09,571 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] at least one sink is marked for delete
2016-01-14 22:11:09,571 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 22:11:09,573 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] starting
2016-01-14 22:11:09,573 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs]  source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second2"]
2016-01-14 22:11:09,574 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs]  source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second1"]
2016-01-14 22:11:09,574 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/third"]
2016-01-14 22:11:09,574 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs]  parallel execution of steps is enabled: true
2016-01-14 22:11:09,574 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs]  executing total steps: 1
2016-01-14 22:11:09,574 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs]  allocating management threads: 1
2016-01-14 22:11:09,575 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] starting step: (1/1) ...latform/testCascade/third
2016-01-14 22:11:10,355 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:11:10,494 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] submitted hadoop job: job_20160114220906794_0015
2016-01-14 22:11:10,495 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] tracking url: http://localhost:50660/jobdetails.jsp?jobid=job_20160114220906794_0015
2016-01-14 22:11:10,621 WARN  mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160114220906794_0014 being deleted.
2016-01-14 22:11:10,740 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:11:11,531 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:11:11,700 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:11:11,855 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:11:12,083 WARN  mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-01-14 22:11:33,242 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/third/_temporary
2016-01-14 22:11:33,243 INFO  flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs]  completed in: 00:23.668
2016-01-14 22:11:33,243 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: lhs*rhs
2016-01-14 22:11:33,261 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascade/second2
2016-01-14 22:11:33,273 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascade/third
2016-01-14 22:11:33,276 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascade/second1
2016-01-14 22:11:33,287 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascade/first2
2016-01-14 22:11:33,298 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascade/first1