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