2016-05-18 04:00:43,375 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 04:00:43,391 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.cascade.ParallelCascadePlatformTest, with platform: hadoop
2016-05-18 04:00:43,414 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(144)) - using cluster
2016-05-18 04:00:44,221 WARN impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-namenode.properties, hadoop-metrics2.properties
Starting DataNode 0 with dfs.data.dir: build/test/data/dfs/data/data1,build/test/data/dfs/data/data2
2016-05-18 04:00:45,052 WARN impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-05-18 04:00:45,054 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:303)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:69)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Starting DataNode 1 with dfs.data.dir: build/test/data/dfs/data/data3,build/test/data/dfs/data/data4
2016-05-18 04:00:45,504 WARN impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-05-18 04:00:45,505 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:303)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:69)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-18 04:00:45,602 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:303)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:69)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Starting DataNode 2 with dfs.data.dir: build/test/data/dfs/data/data5,build/test/data/dfs/data/data6
2016-05-18 04:00:45,900 WARN impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-05-18 04:00:45,901 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:303)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:69)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-18 04:00:45,970 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:303)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:69)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Starting DataNode 3 with dfs.data.dir: build/test/data/dfs/data/data7,build/test/data/dfs/data/data8
2016-05-18 04:00:46,200 WARN impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-05-18 04:00:46,201 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:303)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:69)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-18 04:00:46,266 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:303)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:69)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Cluster is active
Generating rack names for tasktrackers
Generating host names for tasktrackers
2016-05-18 04:00:46,562 WARN impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-jobtracker.properties, hadoop-metrics2.properties
2016-05-18 04:00:46,563 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-05-18 04:00:47,519 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-05-18 04:00:47,604 WARN mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4391)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-05-18 04:00:47,912 WARN mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4391)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-05-18 04:00:48,114 WARN mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4391)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-05-18 04:00:48,335 WARN mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4391)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-05-18 04:00:49,579 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 04:00:49,678 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:00:49,679 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:00:49,764 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 6089D4690B40467C95C97886EC75453B
2016-05-18 04:00:49,890 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-0/first-nondeterm...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.085
2016-05-18 04:00:49,893 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-0/first-nondeterm...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:00:49,893 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-0/first-nondeterm...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:00:50,014 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] stopping all flows
2016-05-18 04:00:50,015 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 04:00:50,015 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] stopped all flows
2016-05-18 04:00:50,015 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] starting
2016-05-18 04:00:50,034 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:00:50,035 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:00:50,094 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.050
2016-05-18 04:00:50,096 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:00:50,097 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:00:50,116 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] starting
2016-05-18 04:00:50,119 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] parallel execution of flows is enabled: false
2016-05-18 04:00:50,120 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] executing total flows: 1
2016-05-18 04:00:50,120 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] allocating management threads: 1
2016-05-18 04:00:50,121 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] starting flow: race-50/first-nondeterministic
2016-05-18 04:00:50,122 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] at least one sink is marked for delete
2016-05-18 04:00:50,122 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 04:00:50,140 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] starting
2016-05-18 04:00:50,141 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-05-18 04:00:50,142 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-50/first-nondeterministic"]
2016-05-18 04:00:50,142 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] parallel execution of steps is enabled: true
2016-05-18 04:00:50,143 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] executing total steps: 1
2016-05-18 04:00:50,143 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] allocating management threads: 1
2016-05-18 04:00:50,144 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] starting step: (1/1) ...50/first-nondeterministic
2016-05-18 04:00:50,166 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopping all flows
2016-05-18 04:00:50,168 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopping flow: race-50/first-nondeterministic
2016-05-18 04:00:50,169 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] stopping all jobs
2016-05-18 04:00:50,170 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] stopping: (1/1) ...50/first-nondeterministic
2016-05-18 04:00:50,171 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] stopped all jobs
2016-05-18 04:00:50,222 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2016-05-18 04:00:50,463 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] submitted hadoop job: job_20160518040046512_0001
2016-05-18 04:00:50,464 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] tracking url: http://localhost:60385/jobdetails.jsp?jobid=job_20160518040046512_0001
2016-05-18 04:00:50,468 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopped all flows
2016-05-18 04:00:50,468 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] shutting down flow executor
2016-05-18 04:00:50,473 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] completed in: 00:00.029
2016-05-18 04:00:50,474 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] completed flow: race-50/first-nondeterministic
2016-05-18 04:00:50,474 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] shutdown complete
2016-05-18 04:00:50,490 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:00:50,491 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:00:50,552 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.053
2016-05-18 04:00:50,554 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:00:50,554 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:00:50,568 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] starting
2016-05-18 04:00:50,569 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] parallel execution of flows is enabled: false
2016-05-18 04:00:50,569 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] executing total flows: 1
2016-05-18 04:00:50,569 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] allocating management threads: 1
2016-05-18 04:00:50,570 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] starting flow: race-100/first-nondeterministic
2016-05-18 04:00:50,570 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] at least one sink is marked for delete
2016-05-18 04:00:50,571 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 04:00:50,581 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] starting
2016-05-18 04:00:50,581 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-05-18 04:00:50,582 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-100/first-nondeterministic"]
2016-05-18 04:00:50,583 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] parallel execution of steps is enabled: true
2016-05-18 04:00:50,583 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] executing total steps: 1
2016-05-18 04:00:50,583 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] allocating management threads: 1
2016-05-18 04:00:50,585 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-05-18 04:00:50,668 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopping all flows
2016-05-18 04:00:50,669 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopping flow: race-100/first-nondeterministic
2016-05-18 04:00:50,669 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] stopping all jobs
2016-05-18 04:00:50,670 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-05-18 04:00:50,671 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] stopped all jobs
2016-05-18 04:00:51,653 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] submitted hadoop job: job_20160518040046512_0002
2016-05-18 04:00:51,653 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] tracking url: http://localhost:60385/jobdetails.jsp?jobid=job_20160518040046512_0002
2016-05-18 04:00:51,656 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopped all flows
2016-05-18 04:00:51,657 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] shutting down flow executor
2016-05-18 04:00:51,662 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] completed in: 00:00.092
2016-05-18 04:00:51,663 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] completed flow: race-100/first-nondeterministic
2016-05-18 04:00:51,663 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] shutdown complete
2016-05-18 04:00:51,693 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:00:51,694 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:00:51,782 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.066
2016-05-18 04:00:51,784 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:00:51,790 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:00:51,814 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] starting
2016-05-18 04:00:51,815 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] parallel execution of flows is enabled: false
2016-05-18 04:00:51,816 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] executing total flows: 1
2016-05-18 04:00:51,816 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] allocating management threads: 1
2016-05-18 04:00:51,817 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] starting flow: race-150/first-nondeterministic
2016-05-18 04:00:51,818 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] at least one sink is marked for delete
2016-05-18 04:00:51,818 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 04:00:51,826 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] starting
2016-05-18 04:00:51,827 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-05-18 04:00:51,828 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-150/first-nondeterministic"]
2016-05-18 04:00:51,828 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] parallel execution of steps is enabled: true
2016-05-18 04:00:51,829 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] executing total steps: 1
2016-05-18 04:00:51,829 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] allocating management threads: 1
2016-05-18 04:00:51,832 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-05-18 04:00:51,964 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopping all flows
2016-05-18 04:00:51,966 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopping flow: race-150/first-nondeterministic
2016-05-18 04:00:51,967 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] stopping all jobs
2016-05-18 04:00:51,969 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-05-18 04:00:51,970 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] stopped all jobs
2016-05-18 04:00:52,684 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] submitted hadoop job: job_20160518040046512_0003
2016-05-18 04:00:52,684 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] tracking url: http://localhost:60385/jobdetails.jsp?jobid=job_20160518040046512_0003
2016-05-18 04:00:52,688 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopped all flows
2016-05-18 04:00:52,689 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] shutting down flow executor
2016-05-18 04:00:52,688 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] completed in: 00:00.141
2016-05-18 04:00:52,690 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] completed flow: race-150/first-nondeterministic
2016-05-18 04:00:52,691 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] shutdown complete
2016-05-18 04:00:52,710 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:00:52,711 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:00:52,840 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.102
2016-05-18 04:00:52,842 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:00:52,843 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:00:52,874 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] starting
2016-05-18 04:00:52,884 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] parallel execution of flows is enabled: false
2016-05-18 04:00:52,884 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] executing total flows: 1
2016-05-18 04:00:52,885 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] allocating management threads: 1
2016-05-18 04:00:52,886 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] starting flow: race-200/first-nondeterministic
2016-05-18 04:00:52,887 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] at least one sink is marked for delete
2016-05-18 04:00:52,887 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 04:00:52,906 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] starting
2016-05-18 04:00:52,907 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-05-18 04:00:52,907 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-200/first-nondeterministic"]
2016-05-18 04:00:52,907 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] parallel execution of steps is enabled: true
2016-05-18 04:00:52,907 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] executing total steps: 1
2016-05-18 04:00:52,908 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] allocating management threads: 1
2016-05-18 04:00:52,938 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-05-18 04:00:53,074 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopping all flows
2016-05-18 04:00:53,076 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopping flow: race-200/first-nondeterministic
2016-05-18 04:00:53,076 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] stopping all jobs
2016-05-18 04:00:53,078 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-05-18 04:00:53,078 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] stopped all jobs
2016-05-18 04:00:53,700 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] submitted hadoop job: job_20160518040046512_0004
2016-05-18 04:00:53,701 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] tracking url: http://localhost:60385/jobdetails.jsp?jobid=job_20160518040046512_0004
2016-05-18 04:00:53,706 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] completed in: 00:00.170
2016-05-18 04:00:53,706 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopped all flows
2016-05-18 04:00:53,707 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] shutting down flow executor
2016-05-18 04:00:53,706 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] completed flow: race-200/first-nondeterministic
2016-05-18 04:00:53,709 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] shutdown complete
2016-05-18 04:00:53,728 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:00:53,730 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:00:53,808 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.062
2016-05-18 04:00:53,810 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:00:53,811 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:00:53,826 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] starting
2016-05-18 04:00:53,828 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] parallel execution of flows is enabled: false
2016-05-18 04:00:53,828 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] executing total flows: 1
2016-05-18 04:00:53,829 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] allocating management threads: 1
2016-05-18 04:00:53,829 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] starting flow: race-250/first-nondeterministic
2016-05-18 04:00:53,829 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] at least one sink is marked for delete
2016-05-18 04:00:53,830 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 04:00:53,834 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] starting
2016-05-18 04:00:53,835 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-05-18 04:00:53,835 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-250/first-nondeterministic"]
2016-05-18 04:00:53,835 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] parallel execution of steps is enabled: true
2016-05-18 04:00:53,837 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] executing total steps: 1
2016-05-18 04:00:53,837 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] allocating management threads: 1
2016-05-18 04:00:53,839 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-05-18 04:00:54,076 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopping all flows
2016-05-18 04:00:54,084 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopping flow: race-250/first-nondeterministic
2016-05-18 04:00:54,084 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] stopping all jobs
2016-05-18 04:00:54,091 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-05-18 04:00:54,091 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] stopped all jobs
2016-05-18 04:00:54,742 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] submitted hadoop job: job_20160518040046512_0005
2016-05-18 04:00:54,742 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] tracking url: http://localhost:60385/jobdetails.jsp?jobid=job_20160518040046512_0005
2016-05-18 04:00:54,745 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopped all flows
2016-05-18 04:00:54,745 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] shutting down flow executor
2016-05-18 04:00:54,754 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] completed in: 00:00.250
2016-05-18 04:00:54,754 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] completed flow: race-250/first-nondeterministic
2016-05-18 04:00:54,763 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] shutdown complete
2016-05-18 04:00:54,823 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:00:54,827 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:00:54,967 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.106
2016-05-18 04:00:54,976 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:00:54,976 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:00:55,009 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] starting
2016-05-18 04:00:55,010 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] parallel execution of flows is enabled: false
2016-05-18 04:00:55,011 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] executing total flows: 1
2016-05-18 04:00:55,011 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] allocating management threads: 1
2016-05-18 04:00:55,012 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] starting flow: race-300/first-nondeterministic
2016-05-18 04:00:55,013 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] at least one sink is marked for delete
2016-05-18 04:00:55,014 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 04:00:55,027 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] starting
2016-05-18 04:00:55,028 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-05-18 04:00:55,029 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-300/first-nondeterministic"]
2016-05-18 04:00:55,029 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] parallel execution of steps is enabled: true
2016-05-18 04:00:55,030 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] executing total steps: 1
2016-05-18 04:00:55,030 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] allocating management threads: 1
2016-05-18 04:00:55,031 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-05-18 04:00:55,349 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopping all flows
2016-05-18 04:00:55,358 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopping flow: race-300/first-nondeterministic
2016-05-18 04:00:55,358 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] stopping all jobs
2016-05-18 04:00:55,360 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-05-18 04:00:55,361 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] stopped all jobs
2016-05-18 04:00:56,580 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:00:57,231 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] submitted hadoop job: job_20160518040046512_0006
2016-05-18 04:00:57,232 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] tracking url: http://localhost:60385/jobdetails.jsp?jobid=job_20160518040046512_0006
2016-05-18 04:00:57,235 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopped all flows
2016-05-18 04:00:57,235 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] shutting down flow executor
2016-05-18 04:00:57,238 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] completed in: 00:00.331
2016-05-18 04:00:57,239 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] completed flow: race-300/first-nondeterministic
2016-05-18 04:00:57,240 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] shutdown complete
2016-05-18 04:00:57,338 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:00:57,367 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:00:57,642 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.238
2016-05-18 04:00:57,647 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:00:57,648 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:00:57,737 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] starting
2016-05-18 04:00:57,773 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] parallel execution of flows is enabled: false
2016-05-18 04:00:57,775 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] executing total flows: 1
2016-05-18 04:00:57,775 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] allocating management threads: 1
2016-05-18 04:00:57,816 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] starting flow: race-350/first-nondeterministic
2016-05-18 04:00:57,817 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] at least one sink is marked for delete
2016-05-18 04:00:57,818 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 04:00:57,927 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] starting
2016-05-18 04:00:57,928 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-05-18 04:00:57,928 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-350/first-nondeterministic"]
2016-05-18 04:00:57,928 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] parallel execution of steps is enabled: true
2016-05-18 04:00:57,928 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] executing total steps: 1
2016-05-18 04:00:57,928 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] allocating management threads: 1
2016-05-18 04:00:58,060 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-05-18 04:00:58,089 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopping all flows
2016-05-18 04:00:58,094 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopping flow: race-350/first-nondeterministic
2016-05-18 04:00:58,095 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] stopping all jobs
2016-05-18 04:00:58,096 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-05-18 04:00:58,096 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] stopped all jobs
2016-05-18 04:00:59,345 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:00:59,984 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:00,239 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] submitted hadoop job: job_20160518040046512_0007
2016-05-18 04:01:00,239 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] tracking url: http://localhost:60385/jobdetails.jsp?jobid=job_20160518040046512_0007
2016-05-18 04:01:00,260 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopped all flows
2016-05-18 04:01:00,261 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] shutting down flow executor
2016-05-18 04:01:00,279 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] completed in: 00:00.168
2016-05-18 04:01:00,280 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] completed flow: race-350/first-nondeterministic
2016-05-18 04:01:00,280 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] shutdown complete
2016-05-18 04:01:00,326 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:01:00,327 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:01:00,693 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.278
2016-05-18 04:01:00,695 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:01:00,695 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:01:00,802 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] starting
2016-05-18 04:01:00,825 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] parallel execution of flows is enabled: false
2016-05-18 04:01:00,826 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] executing total flows: 1
2016-05-18 04:01:00,826 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] allocating management threads: 1
2016-05-18 04:01:00,857 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] starting flow: race-400/first-nondeterministic
2016-05-18 04:01:00,857 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] at least one sink is marked for delete
2016-05-18 04:01:00,858 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 04:01:00,908 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] starting
2016-05-18 04:01:00,909 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-05-18 04:01:00,909 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-400/first-nondeterministic"]
2016-05-18 04:01:00,909 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] parallel execution of steps is enabled: true
2016-05-18 04:01:00,919 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] executing total steps: 1
2016-05-18 04:01:00,919 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] allocating management threads: 1
2016-05-18 04:01:00,949 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-05-18 04:01:01,195 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopping all flows
2016-05-18 04:01:01,296 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopping flow: race-400/first-nondeterministic
2016-05-18 04:01:01,297 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] stopping all jobs
2016-05-18 04:01:01,310 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-05-18 04:01:01,310 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] stopped all jobs
2016-05-18 04:01:03,129 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:03,302 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] submitted hadoop job: job_20160518040046512_0008
2016-05-18 04:01:03,302 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] tracking url: http://localhost:60385/jobdetails.jsp?jobid=job_20160518040046512_0008
2016-05-18 04:01:03,333 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopped all flows
2016-05-18 04:01:03,333 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] shutting down flow executor
2016-05-18 04:01:03,390 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] completed in: 00:00.389
2016-05-18 04:01:03,390 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] completed flow: race-400/first-nondeterministic
2016-05-18 04:01:03,391 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] shutdown complete
2016-05-18 04:01:03,436 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:01:03,437 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:01:03,849 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.281
2016-05-18 04:01:03,869 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:01:03,870 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:01:03,967 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] starting
2016-05-18 04:01:03,990 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] parallel execution of flows is enabled: false
2016-05-18 04:01:03,990 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] executing total flows: 1
2016-05-18 04:01:03,990 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] allocating management threads: 1
2016-05-18 04:01:04,004 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] starting flow: race-450/first-nondeterministic
2016-05-18 04:01:04,005 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] at least one sink is marked for delete
2016-05-18 04:01:04,005 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 04:01:04,097 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] starting
2016-05-18 04:01:04,098 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-05-18 04:01:04,098 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-450/first-nondeterministic"]
2016-05-18 04:01:04,098 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] parallel execution of steps is enabled: true
2016-05-18 04:01:04,098 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] executing total steps: 1
2016-05-18 04:01:04,098 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] allocating management threads: 1
2016-05-18 04:01:04,146 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-05-18 04:01:04,417 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopping all flows
2016-05-18 04:01:04,486 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopping flow: race-450/first-nondeterministic
2016-05-18 04:01:04,486 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] stopping all jobs
2016-05-18 04:01:04,529 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-05-18 04:01:04,530 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] stopped all jobs
2016-05-18 04:01:05,924 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] submitted hadoop job: job_20160518040046512_0009
2016-05-18 04:01:05,924 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] tracking url: http://localhost:60385/jobdetails.jsp?jobid=job_20160518040046512_0009
2016-05-18 04:01:05,927 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopped all flows
2016-05-18 04:01:05,927 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] shutting down flow executor
2016-05-18 04:01:05,929 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] completed in: 00:00.389
2016-05-18 04:01:05,930 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] completed flow: race-450/first-nondeterministic
2016-05-18 04:01:05,930 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] shutdown complete
2016-05-18 04:01:05,978 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:01:05,980 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:01:06,479 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.390
2016-05-18 04:01:06,519 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:01:06,519 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:01:06,588 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] starting
2016-05-18 04:01:06,617 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] parallel execution of flows is enabled: false
2016-05-18 04:01:06,618 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] executing total flows: 1
2016-05-18 04:01:06,619 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] allocating management threads: 1
2016-05-18 04:01:06,637 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] starting flow: race-500/first-nondeterministic
2016-05-18 04:01:06,637 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] at least one sink is marked for delete
2016-05-18 04:01:06,637 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 04:01:06,747 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] starting
2016-05-18 04:01:06,748 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-05-18 04:01:06,748 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-500/first-nondeterministic"]
2016-05-18 04:01:06,748 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] parallel execution of steps is enabled: true
2016-05-18 04:01:06,748 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] executing total steps: 1
2016-05-18 04:01:06,748 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] allocating management threads: 1
2016-05-18 04:01:06,793 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-05-18 04:01:07,088 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopping all flows
2016-05-18 04:01:07,143 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopping flow: race-500/first-nondeterministic
2016-05-18 04:01:07,143 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] stopping all jobs
2016-05-18 04:01:07,171 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-05-18 04:01:07,172 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] stopped all jobs
2016-05-18 04:01:09,248 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:09,344 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] submitted hadoop job: job_20160518040046512_0010
2016-05-18 04:01:09,345 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] tracking url: http://localhost:60385/jobdetails.jsp?jobid=job_20160518040046512_0010
2016-05-18 04:01:09,349 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopped all flows
2016-05-18 04:01:09,350 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] completed in: 00:00.396
2016-05-18 04:01:09,350 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] shutting down flow executor
2016-05-18 04:01:09,350 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] completed flow: race-500/first-nondeterministic
2016-05-18 04:01:09,394 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] shutdown complete
2016-05-18 04:01:09,395 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-450/first-nondeterministic
2016-05-18 04:01:09,399 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-0/first-nondeterministic
2016-05-18 04:01:09,400 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-50/first-nondeterministic
2016-05-18 04:01:09,457 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-400/first-nondeterministic
2016-05-18 04:01:09,462 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-300/first-nondeterministic
2016-05-18 04:01:09,465 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-250/first-nondeterministic
2016-05-18 04:01:09,469 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-350/first-nondeterministic
2016-05-18 04:01:09,473 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-500/first-nondeterministic
2016-05-18 04:01:09,480 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-150/first-nondeterministic
2016-05-18 04:01:09,484 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-200/first-nondeterministic
2016-05-18 04:01:09,488 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-100/first-nondeterministic
2016-05-18 04:01:09,573 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:01:09,575 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:01:10,070 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.277
2016-05-18 04:01:10,071 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:01:10,072 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:01:10,246 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:01:10,248 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:01:10,735 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.351
2016-05-18 04:01:10,736 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:01:10,736 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:01:10,935 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:01:10,935 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:01:11,362 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.359
2016-05-18 04:01:11,365 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:01:11,365 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:01:11,518 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:01:11,519 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:01:11,852 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.291
2016-05-18 04:01:11,854 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:01:11,854 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:01:12,053 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:01:12,086 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 04:01:12,655 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.478
2016-05-18 04:01:12,660 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 04:01:12,660 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:01:13,044 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting
2016-05-18 04:01:13,219 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] parallel execution of flows is enabled: true
2016-05-18 04:01:13,219 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] executing total flows: 5
2016-05-18 04:01:13,219 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] allocating management threads: 5
2016-05-18 04:01:13,280 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: first2
2016-05-18 04:01:13,280 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] at least one sink is marked for delete
2016-05-18 04:01:13,281 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 04:01:13,313 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: first1
2016-05-18 04:01:13,313 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] at least one sink is marked for delete
2016-05-18 04:01:13,313 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 04:01:13,507 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] starting
2016-05-18 04:01:13,507 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] starting
2016-05-18 04:01:13,508 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-05-18 04:01:13,508 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/ips.20.txt"]
2016-05-18 04:01:13,508 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first2"]
2016-05-18 04:01:13,509 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first1"]
2016-05-18 04:01:13,509 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] parallel execution of steps is enabled: true
2016-05-18 04:01:13,509 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] executing total steps: 1
2016-05-18 04:01:13,509 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] allocating management threads: 1
2016-05-18 04:01:13,509 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] parallel execution of steps is enabled: true
2016-05-18 04:01:13,509 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] executing total steps: 1
2016-05-18 04:01:13,509 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] allocating management threads: 1
2016-05-18 04:01:13,597 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:13,645 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] starting step: (1/1) ...atform/testCascade/first1
2016-05-18 04:01:13,703 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] starting step: (1/1) ...atform/testCascade/first2
2016-05-18 04:01:14,025 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:14,614 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:14,877 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:16,821 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] submitted hadoop job: job_20160518040046512_0011
2016-05-18 04:01:16,821 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] tracking url: http://localhost:60385/jobdetails.jsp?jobid=job_20160518040046512_0011
2016-05-18 04:01:17,350 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] submitted hadoop job: job_20160518040046512_0012
2016-05-18 04:01:17,351 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] tracking url: http://localhost:60385/jobdetails.jsp?jobid=job_20160518040046512_0012
2016-05-18 04:01:19,982 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:20,131 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:20,339 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:21,466 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:27,449 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:28,320 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160518040046512_0001 being deleted.
2016-05-18 04:01:28,366 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:29,069 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:32,866 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:32,990 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:33,668 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:34,403 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:34,671 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:37,842 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:38,051 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:38,396 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:38,530 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:43,466 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:43,644 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:46,247 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:48,380 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:49,010 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:50,058 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160518040046512_0004 being deleted.
2016-05-18 04:01:50,997 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:52,832 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:52,971 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:53,391 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:57,096 WARN mapred.TaskTracker (TaskTracker.java:statusUpdate(3506)) - Failed validating JVM
java.io.IOException: JvmValidate Failed. Ignoring request from task: attempt_20160518040046512_0007_m_000001_0, with JvmId: jvm_20160518040046512_0007_m_919152739
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-05-18 04:01:57,216 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:58,495 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:58,857 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:01:59,044 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:00,166 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160518040046512_0005 being deleted.
2016-05-18 04:02:00,495 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:03,418 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:03,837 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:04,168 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160518040046512_0006 being deleted.
2016-05-18 04:02:04,992 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:08,148 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:08,433 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:08,762 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:11,447 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:12,971 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:14,168 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160518040046512_0007 being deleted.
2016-05-18 04:02:14,906 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:15,273 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:15,378 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:18,409 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:18,904 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:20,169 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160518040046512_0008 being deleted.
2016-05-18 04:02:20,897 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:22,378 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:22,696 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:23,482 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:28,174 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160518040046512_0009 being deleted.
2016-05-18 04:02:29,181 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:32,174 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160518040046512_0010 being deleted.
2016-05-18 04:02:32,455 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:32,607 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first2/_temporary
2016-05-18 04:02:32,611 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] completed in: 01:19.084
2016-05-18 04:02:32,611 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: first2
2016-05-18 04:02:32,611 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: second2
2016-05-18 04:02:32,612 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] at least one sink is marked for delete
2016-05-18 04:02:32,612 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 04:02:32,621 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] starting
2016-05-18 04:02:32,621 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first2"]
2016-05-18 04:02:32,623 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second2"]
2016-05-18 04:02:32,623 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] parallel execution of steps is enabled: true
2016-05-18 04:02:32,624 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] executing total steps: 1
2016-05-18 04:02:32,625 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] allocating management threads: 1
2016-05-18 04:02:32,648 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] starting step: (1/1) ...tform/testCascade/second2
2016-05-18 04:02:33,505 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] submitted hadoop job: job_20160518040046512_0013
2016-05-18 04:02:33,505 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] tracking url: http://localhost:60385/jobdetails.jsp?jobid=job_20160518040046512_0013
2016-05-18 04:02:34,180 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:34,842 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first1/_temporary
2016-05-18 04:02:34,843 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] completed in: 01:21.334
2016-05-18 04:02:34,843 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: first1
2016-05-18 04:02:34,844 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: second1
2016-05-18 04:02:34,844 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] at least one sink is marked for delete
2016-05-18 04:02:34,844 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 04:02:34,848 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] starting
2016-05-18 04:02:34,849 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/first1"]
2016-05-18 04:02:34,849 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second1"]
2016-05-18 04:02:34,850 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] parallel execution of steps is enabled: true
2016-05-18 04:02:34,851 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] executing total steps: 1
2016-05-18 04:02:34,851 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] allocating management threads: 1
2016-05-18 04:02:34,853 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] starting step: (1/1) ...tform/testCascade/second1
2016-05-18 04:02:35,198 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:35,243 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:35,442 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] submitted hadoop job: job_20160518040046512_0014
2016-05-18 04:02:35,442 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] tracking url: http://localhost:60385/jobdetails.jsp?jobid=job_20160518040046512_0014
2016-05-18 04:02:35,451 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:35,867 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:36,180 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160518040046512_0012 being deleted.
2016-05-18 04:02:36,213 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:36,935 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:40,833 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:47,588 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second2/_temporary
2016-05-18 04:02:47,589 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] completed in: 00:14.966
2016-05-18 04:02:47,589 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: second2
2016-05-18 04:02:48,535 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160518040046512_0013 being deleted.
2016-05-18 04:02:48,728 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:48,862 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:48,936 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:50,723 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second1/_temporary
2016-05-18 04:02:50,724 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] completed in: 00:15.874
2016-05-18 04:02:50,724 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: second1
2016-05-18 04:02:50,725 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: lhs*rhs
2016-05-18 04:02:50,725 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] at least one sink is marked for delete
2016-05-18 04:02:50,725 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 04:02:50,727 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] starting
2016-05-18 04:02:50,728 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second2"]
2016-05-18 04:02:50,728 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/second1"]
2016-05-18 04:02:50,728 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/third"]
2016-05-18 04:02:50,728 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] parallel execution of steps is enabled: true
2016-05-18 04:02:50,728 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] executing total steps: 1
2016-05-18 04:02:50,728 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] allocating management threads: 1
2016-05-18 04:02:50,729 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] starting step: (1/1) ...latform/testCascade/third
2016-05-18 04:02:52,032 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] submitted hadoop job: job_20160518040046512_0015
2016-05-18 04:02:52,032 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] tracking url: http://localhost:60385/jobdetails.jsp?jobid=job_20160518040046512_0015
2016-05-18 04:02:52,181 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160518040046512_0014 being deleted.
2016-05-18 04:02:52,589 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(2213)) - Unknown job job_20160518040046512_0014 being deleted.
2016-05-18 04:02:52,613 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:52,686 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:52,896 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:02:53,605 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(146)) - Exit code from task is : 143
2016-05-18 04:03:14,912 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/parallelcascadeplatform/testCascade/third/_temporary
2016-05-18 04:03:14,913 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] completed in: 00:24.183
2016-05-18 04:03:14,913 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: lhs*rhs
2016-05-18 04:03:14,939 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascade/first2
2016-05-18 04:03:14,951 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascade/second2
2016-05-18 04:03:14,963 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascade/second1
2016-05-18 04:03:14,975 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascade/first1
2016-05-18 04:03:14,986 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/parallelcascadeplatform/testCascade/third