2016-01-14 17:14:01,444 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 17:14:01,460 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.cascade.ParallelCascadePlatformTest, with platform: hadoop
2016-01-14 17:14:01,483 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(144)) - using cluster
2016-01-14 17:14:02,155 WARN impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-namenode.properties, hadoop-metrics2.properties
Starting DataNode 0 with dfs.data.dir: build/test/data/dfs/data/data1,build/test/data/dfs/data/data2
2016-01-14 17:14:02,918 WARN impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-01-14 17:14:02,919 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:1483)
at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1459)
at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes(MiniDFSCluster.java:417)
at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:280)
at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:124)
at cascading.platform.hadoop.HadoopPlatform.setUp(HadoopPlatform.java:180)
at cascading.PlatformTestCase.setUp(PlatformTestCase.java:161)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:301)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:68)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Starting DataNode 1 with dfs.data.dir: build/test/data/dfs/data/data3,build/test/data/dfs/data/data4
2016-01-14 17:14:03,360 WARN impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-01-14 17:14:03,361 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:1483)
at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1459)
at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes(MiniDFSCluster.java:417)
at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:280)
at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:124)
at cascading.platform.hadoop.HadoopPlatform.setUp(HadoopPlatform.java:180)
at cascading.PlatformTestCase.setUp(PlatformTestCase.java:161)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:301)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:68)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-01-14 17:14:03,449 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:500)
at org.apache.hadoop.hdfs.server.datanode.DataNode.startDataNode(DataNode.java:375)
at org.apache.hadoop.hdfs.server.datanode.DataNode.<init>(DataNode.java:281)
at org.apache.hadoop.hdfs.server.datanode.DataNode.makeInstance(DataNode.java:1545)
at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1484)
at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1459)
at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes(MiniDFSCluster.java:417)
at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:280)
at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:124)
at cascading.platform.hadoop.HadoopPlatform.setUp(HadoopPlatform.java:180)
at cascading.PlatformTestCase.setUp(PlatformTestCase.java:161)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:301)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:68)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Starting DataNode 2 with dfs.data.dir: build/test/data/dfs/data/data5,build/test/data/dfs/data/data6
2016-01-14 17:14:03,732 WARN impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-01-14 17:14:03,732 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:1483)
at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1459)
at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes(MiniDFSCluster.java:417)
at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:280)
at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:124)
at cascading.platform.hadoop.HadoopPlatform.setUp(HadoopPlatform.java:180)
at cascading.PlatformTestCase.setUp(PlatformTestCase.java:161)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:301)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:68)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-01-14 17:14:03,821 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:500)
at org.apache.hadoop.hdfs.server.datanode.DataNode.startDataNode(DataNode.java:375)
at org.apache.hadoop.hdfs.server.datanode.DataNode.<init>(DataNode.java:281)
at org.apache.hadoop.hdfs.server.datanode.DataNode.makeInstance(DataNode.java:1545)
at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1484)
at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1459)
at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes(MiniDFSCluster.java:417)
at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:280)
at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:124)
at cascading.platform.hadoop.HadoopPlatform.setUp(HadoopPlatform.java:180)
at cascading.PlatformTestCase.setUp(PlatformTestCase.java:161)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:301)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:68)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Starting DataNode 3 with dfs.data.dir: build/test/data/dfs/data/data7,build/test/data/dfs/data/data8
2016-01-14 17:14:04,036 WARN impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-datanode.properties, hadoop-metrics2.properties
2016-01-14 17:14:04,036 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:1483)
at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1459)
at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes(MiniDFSCluster.java:417)
at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:280)
at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:124)
at cascading.platform.hadoop.HadoopPlatform.setUp(HadoopPlatform.java:180)
at cascading.PlatformTestCase.setUp(PlatformTestCase.java:161)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:301)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:68)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-01-14 17:14:04,102 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:500)
at org.apache.hadoop.hdfs.server.datanode.DataNode.startDataNode(DataNode.java:375)
at org.apache.hadoop.hdfs.server.datanode.DataNode.<init>(DataNode.java:281)
at org.apache.hadoop.hdfs.server.datanode.DataNode.makeInstance(DataNode.java:1545)
at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1484)
at org.apache.hadoop.hdfs.server.datanode.DataNode.instantiateDataNode(DataNode.java:1459)
at org.apache.hadoop.hdfs.MiniDFSCluster.startDataNodes(MiniDFSCluster.java:417)
at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:280)
at org.apache.hadoop.hdfs.MiniDFSCluster.<init>(MiniDFSCluster.java:124)
at cascading.platform.hadoop.HadoopPlatform.setUp(HadoopPlatform.java:180)
at cascading.PlatformTestCase.setUp(PlatformTestCase.java:161)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24)
at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
at org.junit.rules.RunRules.evaluate(RunRules.java:20)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:301)
at cascading.platform.PlatformRunner.runChild(PlatformRunner.java:68)
at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:86)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:49)
at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:64)
at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:50)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
at org.gradle.messaging.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
at org.gradle.messaging.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
at org.gradle.messaging.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:360)
at org.gradle.internal.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Generating rack names for tasktrackers
Generating host names for tasktrackers
2016-01-14 17:14:04,359 WARN impl.MetricsSystemImpl (MetricsSystemImpl.java:init(137)) - Metrics system not started: Cannot locate configuration: tried hadoop-metrics2-jobtracker.properties, hadoop-metrics2.properties
2016-01-14 17:14:04,361 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:296)
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:1059)
at org.apache.hadoop.mapred.MiniMRCluster$JobTrackerRunner.run(MiniMRCluster.java:112)
at java.lang.Thread.run(Thread.java:745)
2016-01-14 17:14:05,360 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-01-14 17:14:05,406 WARN mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4162)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-01-14 17:14:05,673 WARN mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4162)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-01-14 17:14:05,969 WARN mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4162)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-01-14 17:14:06,161 WARN mapred.TaskTracker (TaskTracker.java:setTaskMemoryManagerEnabledFlag(4162)) - TaskTracker's totalMemoryAllottedForTasks is -1. TaskMemoryManager is disabled.
2016-01-14 17:14:06,378 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 17:14:06,485 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:06,487 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:06,593 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 2B358F12D0BB4EEF8D64F959A6CBC716
2016-01-14 17:14:06,719 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-0/first-nondeterm...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.081
2016-01-14 17:14:06,723 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-0/first-nondeterm...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:14:06,723 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-0/first-nondeterm...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:06,843 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] stopping all flows
2016-01-14 17:14:06,844 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 17:14:06,844 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] stopped all flows
2016-01-14 17:14:06,845 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] starting
2016-01-14 17:14:06,865 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:06,865 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:06,921 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.050
2016-01-14 17:14:06,922 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:14:06,922 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:06,937 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] starting
2016-01-14 17:14:06,940 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] parallel execution of flows is enabled: false
2016-01-14 17:14:06,940 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] executing total flows: 1
2016-01-14 17:14:06,940 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] allocating management threads: 1
2016-01-14 17:14:06,941 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] starting flow: race-50/first-nondeterministic
2016-01-14 17:14:06,941 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] at least one sink is marked for delete
2016-01-14 17:14:06,941 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:14:06,971 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] starting
2016-01-14 17:14:06,972 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/ips.20.txt"]
2016-01-14 17:14:06,972 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-50/first-nondeterministic"]
2016-01-14 17:14:06,973 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] parallel execution of steps is enabled: true
2016-01-14 17:14:06,973 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] executing total steps: 1
2016-01-14 17:14:06,973 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] allocating management threads: 1
2016-01-14 17:14:06,975 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] starting step: (1/1) ...50/first-nondeterministic
2016-01-14 17:14:06,987 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopping all flows
2016-01-14 17:14:06,988 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopping flow: race-50/first-nondeterministic
2016-01-14 17:14:06,989 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] stopping all jobs
2016-01-14 17:14:06,990 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] stopping: (1/1) ...50/first-nondeterministic
2016-01-14 17:14:06,990 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] stopped all jobs
2016-01-14 17:14:06,990 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] shutting down job executor
2016-01-14 17:14:08,054 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] submitted hadoop job: job_20160114171404315_0001
2016-01-14 17:14:08,054 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] tracking url: http://localhost:56220/jobdetails.jsp?jobid=job_20160114171404315_0001
2016-01-14 17:14:08,057 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] shutdown complete
2016-01-14 17:14:08,058 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopped all flows
2016-01-14 17:14:08,058 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] shutting down flow executor
2016-01-14 17:14:08,061 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-50/first-nondeter...] completed in: 00:00.018
2016-01-14 17:14:08,062 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] completed flow: race-50/first-nondeterministic
2016-01-14 17:14:08,062 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] shutdown complete
2016-01-14 17:14:08,086 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:08,087 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:08,156 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.053
2016-01-14 17:14:08,158 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:14:08,159 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:08,190 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] starting
2016-01-14 17:14:08,194 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 17:14:08,195 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] executing total flows: 1
2016-01-14 17:14:08,195 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] allocating management threads: 1
2016-01-14 17:14:08,196 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] starting flow: race-100/first-nondeterministic
2016-01-14 17:14:08,196 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] at least one sink is marked for delete
2016-01-14 17:14:08,196 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:14:08,212 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] starting
2016-01-14 17:14:08,212 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/ips.20.txt"]
2016-01-14 17:14:08,212 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-100/first-nondeterministic"]
2016-01-14 17:14:08,212 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 17:14:08,213 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] executing total steps: 1
2016-01-14 17:14:08,213 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] allocating management threads: 1
2016-01-14 17:14:08,217 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-01-14 17:14:08,288 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopping all flows
2016-01-14 17:14:08,289 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopping flow: race-100/first-nondeterministic
2016-01-14 17:14:08,290 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] stopping all jobs
2016-01-14 17:14:08,291 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-01-14 17:14:08,293 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] stopped all jobs
2016-01-14 17:14:08,293 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] shutting down job executor
2016-01-14 17:14:08,381 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] submitted hadoop job: job_20160114171404315_0002
2016-01-14 17:14:08,381 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] tracking url: http://localhost:56220/jobdetails.jsp?jobid=job_20160114171404315_0002
2016-01-14 17:14:08,385 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] shutdown complete
2016-01-14 17:14:08,385 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopped all flows
2016-01-14 17:14:08,386 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] shutting down flow executor
2016-01-14 17:14:08,387 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-100/first-nondete...] completed in: 00:00.079
2016-01-14 17:14:08,387 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] completed flow: race-100/first-nondeterministic
2016-01-14 17:14:08,388 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] shutdown complete
2016-01-14 17:14:08,402 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:08,403 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:08,481 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.072
2016-01-14 17:14:08,482 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:14:08,482 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:08,496 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] starting
2016-01-14 17:14:08,497 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 17:14:08,497 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] executing total flows: 1
2016-01-14 17:14:08,497 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] allocating management threads: 1
2016-01-14 17:14:08,498 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] starting flow: race-150/first-nondeterministic
2016-01-14 17:14:08,498 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] at least one sink is marked for delete
2016-01-14 17:14:08,498 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:14:08,502 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] starting
2016-01-14 17:14:08,502 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/ips.20.txt"]
2016-01-14 17:14:08,502 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-150/first-nondeterministic"]
2016-01-14 17:14:08,503 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 17:14:08,503 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] executing total steps: 1
2016-01-14 17:14:08,503 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] allocating management threads: 1
2016-01-14 17:14:08,504 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-01-14 17:14:08,646 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopping all flows
2016-01-14 17:14:08,647 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopping flow: race-150/first-nondeterministic
2016-01-14 17:14:08,648 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] stopping all jobs
2016-01-14 17:14:08,648 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-01-14 17:14:08,649 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] stopped all jobs
2016-01-14 17:14:08,649 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] shutting down job executor
2016-01-14 17:14:08,655 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] submitted hadoop job: job_20160114171404315_0003
2016-01-14 17:14:08,656 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] tracking url: http://localhost:56220/jobdetails.jsp?jobid=job_20160114171404315_0003
2016-01-14 17:14:08,661 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] shutdown complete
2016-01-14 17:14:08,662 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-150/first-nondete...] completed in: 00:00.146
2016-01-14 17:14:08,664 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] completed flow: race-150/first-nondeterministic
2016-01-14 17:14:08,663 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopped all flows
2016-01-14 17:14:08,685 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:08,685 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:08,753 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.058
2016-01-14 17:14:08,754 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:14:08,754 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:08,775 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] starting
2016-01-14 17:14:08,776 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 17:14:08,777 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] executing total flows: 1
2016-01-14 17:14:08,777 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] allocating management threads: 1
2016-01-14 17:14:08,777 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] starting flow: race-200/first-nondeterministic
2016-01-14 17:14:08,777 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] at least one sink is marked for delete
2016-01-14 17:14:08,778 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:14:08,785 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] starting
2016-01-14 17:14:08,786 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/ips.20.txt"]
2016-01-14 17:14:08,786 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-200/first-nondeterministic"]
2016-01-14 17:14:08,787 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 17:14:08,789 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] executing total steps: 1
2016-01-14 17:14:08,789 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] allocating management threads: 1
2016-01-14 17:14:08,791 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-01-14 17:14:08,975 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopping all flows
2016-01-14 17:14:08,982 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopping flow: race-200/first-nondeterministic
2016-01-14 17:14:08,982 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] stopping all jobs
2016-01-14 17:14:08,982 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-01-14 17:14:08,983 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] stopped all jobs
2016-01-14 17:14:08,983 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] shutting down job executor
2016-01-14 17:14:09,030 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] submitted hadoop job: job_20160114171404315_0004
2016-01-14 17:14:09,033 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] tracking url: http://localhost:56220/jobdetails.jsp?jobid=job_20160114171404315_0004
2016-01-14 17:14:09,041 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] completed in: 00:00.197
2016-01-14 17:14:09,047 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-200/first-nondete...] shutdown complete
2016-01-14 17:14:09,048 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopped all flows
2016-01-14 17:14:09,048 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] shutting down flow executor
2016-01-14 17:14:09,048 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] completed flow: race-200/first-nondeterministic
2016-01-14 17:14:09,050 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] shutdown complete
2016-01-14 17:14:09,068 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:09,069 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:09,145 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.068
2016-01-14 17:14:09,148 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:14:09,148 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:09,197 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] starting
2016-01-14 17:14:09,205 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 17:14:09,206 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] executing total flows: 1
2016-01-14 17:14:09,207 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] allocating management threads: 1
2016-01-14 17:14:09,220 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] starting flow: race-250/first-nondeterministic
2016-01-14 17:14:09,221 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] at least one sink is marked for delete
2016-01-14 17:14:09,221 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:14:09,252 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] starting
2016-01-14 17:14:09,253 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/ips.20.txt"]
2016-01-14 17:14:09,253 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-250/first-nondeterministic"]
2016-01-14 17:14:09,253 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 17:14:09,253 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] executing total steps: 1
2016-01-14 17:14:09,253 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] allocating management threads: 1
2016-01-14 17:14:09,262 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-01-14 17:14:09,447 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopping all flows
2016-01-14 17:14:09,447 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopping flow: race-250/first-nondeterministic
2016-01-14 17:14:09,448 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] stopping all jobs
2016-01-14 17:14:09,448 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-01-14 17:14:09,448 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] stopped all jobs
2016-01-14 17:14:09,449 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] shutting down job executor
2016-01-14 17:14:09,897 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] submitted hadoop job: job_20160114171404315_0005
2016-01-14 17:14:09,898 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] tracking url: http://localhost:56220/jobdetails.jsp?jobid=job_20160114171404315_0005
2016-01-14 17:14:09,901 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] shutdown complete
2016-01-14 17:14:09,901 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopped all flows
2016-01-14 17:14:09,901 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] shutting down flow executor
2016-01-14 17:14:09,905 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-250/first-nondete...] completed in: 00:00.196
2016-01-14 17:14:09,905 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] completed flow: race-250/first-nondeterministic
2016-01-14 17:14:09,907 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] shutdown complete
2016-01-14 17:14:09,942 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:09,943 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:10,059 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.100
2016-01-14 17:14:10,060 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:14:10,060 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:10,079 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] starting
2016-01-14 17:14:10,096 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 17:14:10,096 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] executing total flows: 1
2016-01-14 17:14:10,096 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] allocating management threads: 1
2016-01-14 17:14:10,106 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] starting flow: race-300/first-nondeterministic
2016-01-14 17:14:10,106 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] at least one sink is marked for delete
2016-01-14 17:14:10,110 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:14:10,136 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] starting
2016-01-14 17:14:10,142 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/ips.20.txt"]
2016-01-14 17:14:10,142 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-300/first-nondeterministic"]
2016-01-14 17:14:10,143 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 17:14:10,143 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] executing total steps: 1
2016-01-14 17:14:10,143 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] allocating management threads: 1
2016-01-14 17:14:10,150 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-01-14 17:14:10,379 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopping all flows
2016-01-14 17:14:10,380 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopping flow: race-300/first-nondeterministic
2016-01-14 17:14:10,381 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] stopping all jobs
2016-01-14 17:14:10,402 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-01-14 17:14:10,402 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] stopped all jobs
2016-01-14 17:14:10,403 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] shutting down job executor
2016-01-14 17:14:10,576 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] submitted hadoop job: job_20160114171404315_0006
2016-01-14 17:14:10,577 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] tracking url: http://localhost:56220/jobdetails.jsp?jobid=job_20160114171404315_0006
2016-01-14 17:14:10,580 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] shutdown complete
2016-01-14 17:14:10,580 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopped all flows
2016-01-14 17:14:10,580 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] shutting down flow executor
2016-01-14 17:14:10,582 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-300/first-nondete...] completed in: 00:00.245
2016-01-14 17:14:10,582 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] completed flow: race-300/first-nondeterministic
2016-01-14 17:14:10,583 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] shutdown complete
2016-01-14 17:14:10,608 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:10,609 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:10,700 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.063
2016-01-14 17:14:10,701 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:14:10,701 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:10,735 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] starting
2016-01-14 17:14:10,744 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 17:14:10,744 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] executing total flows: 1
2016-01-14 17:14:10,745 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] allocating management threads: 1
2016-01-14 17:14:10,752 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] starting flow: race-350/first-nondeterministic
2016-01-14 17:14:10,752 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] at least one sink is marked for delete
2016-01-14 17:14:10,752 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:14:10,781 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] starting
2016-01-14 17:14:10,781 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/ips.20.txt"]
2016-01-14 17:14:10,782 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-350/first-nondeterministic"]
2016-01-14 17:14:10,782 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 17:14:10,782 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] executing total steps: 1
2016-01-14 17:14:10,782 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] allocating management threads: 1
2016-01-14 17:14:10,801 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-01-14 17:14:11,085 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopping all flows
2016-01-14 17:14:11,100 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopping flow: race-350/first-nondeterministic
2016-01-14 17:14:11,100 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] stopping all jobs
2016-01-14 17:14:11,104 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-01-14 17:14:11,104 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] stopped all jobs
2016-01-14 17:14:11,104 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] shutting down job executor
2016-01-14 17:14:11,620 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] submitted hadoop job: job_20160114171404315_0007
2016-01-14 17:14:11,620 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] tracking url: http://localhost:56220/jobdetails.jsp?jobid=job_20160114171404315_0007
2016-01-14 17:14:11,623 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] shutdown complete
2016-01-14 17:14:11,623 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopped all flows
2016-01-14 17:14:11,623 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] shutting down flow executor
2016-01-14 17:14:11,625 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-350/first-nondete...] completed in: 00:00.319
2016-01-14 17:14:11,625 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] completed flow: race-350/first-nondeterministic
2016-01-14 17:14:11,630 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] shutdown complete
2016-01-14 17:14:11,690 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:11,691 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:11,799 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.086
2016-01-14 17:14:11,803 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:14:11,803 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:11,865 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] starting
2016-01-14 17:14:11,881 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 17:14:11,881 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] executing total flows: 1
2016-01-14 17:14:11,881 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] allocating management threads: 1
2016-01-14 17:14:11,891 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] starting flow: race-400/first-nondeterministic
2016-01-14 17:14:11,891 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] at least one sink is marked for delete
2016-01-14 17:14:11,892 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:14:11,924 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] starting
2016-01-14 17:14:11,925 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/ips.20.txt"]
2016-01-14 17:14:11,925 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-400/first-nondeterministic"]
2016-01-14 17:14:11,925 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 17:14:11,925 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] executing total steps: 1
2016-01-14 17:14:11,925 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] allocating management threads: 1
2016-01-14 17:14:11,935 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-01-14 17:14:12,265 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopping all flows
2016-01-14 17:14:12,282 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopping flow: race-400/first-nondeterministic
2016-01-14 17:14:12,282 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] stopping all jobs
2016-01-14 17:14:12,308 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-01-14 17:14:12,309 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] stopped all jobs
2016-01-14 17:14:12,309 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] shutting down job executor
2016-01-14 17:14:13,618 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] submitted hadoop job: job_20160114171404315_0008
2016-01-14 17:14:13,618 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] tracking url: http://localhost:56220/jobdetails.jsp?jobid=job_20160114171404315_0008
2016-01-14 17:14:13,635 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] shutdown complete
2016-01-14 17:14:13,635 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-400/first-nondete...] completed in: 00:00.358
2016-01-14 17:14:13,636 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] completed flow: race-400/first-nondeterministic
2016-01-14 17:14:13,636 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopped all flows
2016-01-14 17:14:13,659 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:13,660 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:13,772 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.098
2016-01-14 17:14:13,777 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:14:13,777 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:13,809 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] starting
2016-01-14 17:14:13,820 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 17:14:13,823 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] executing total flows: 1
2016-01-14 17:14:13,824 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] allocating management threads: 1
2016-01-14 17:14:13,832 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] starting flow: race-450/first-nondeterministic
2016-01-14 17:14:13,832 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] at least one sink is marked for delete
2016-01-14 17:14:13,833 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:14:13,851 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] starting
2016-01-14 17:14:13,851 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/ips.20.txt"]
2016-01-14 17:14:13,851 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-450/first-nondeterministic"]
2016-01-14 17:14:13,851 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 17:14:13,852 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] executing total steps: 1
2016-01-14 17:14:13,852 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] allocating management threads: 1
2016-01-14 17:14:13,861 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-01-14 17:14:14,258 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopping all flows
2016-01-14 17:14:14,260 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopping flow: race-450/first-nondeterministic
2016-01-14 17:14:14,260 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] stopping all jobs
2016-01-14 17:14:14,261 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-01-14 17:14:14,261 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] stopped all jobs
2016-01-14 17:14:14,262 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] shutting down job executor
2016-01-14 17:14:14,795 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] submitted hadoop job: job_20160114171404315_0009
2016-01-14 17:14:14,795 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] tracking url: http://localhost:56220/jobdetails.jsp?jobid=job_20160114171404315_0009
2016-01-14 17:14:14,810 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] shutdown complete
2016-01-14 17:14:14,811 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopped all flows
2016-01-14 17:14:14,811 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] shutting down flow executor
2016-01-14 17:14:14,843 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-450/first-nondete...] completed in: 00:00.409
2016-01-14 17:14:14,843 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] completed flow: race-450/first-nondeterministic
2016-01-14 17:14:14,862 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] shutdown complete
2016-01-14 17:14:14,897 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:14,898 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:15,127 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.185
2016-01-14 17:14:15,136 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:14:15,136 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:15,234 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] starting
2016-01-14 17:14:15,237 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] parallel execution of flows is enabled: false
2016-01-14 17:14:15,237 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] executing total flows: 1
2016-01-14 17:14:15,237 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] allocating management threads: 1
2016-01-14 17:14:15,257 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] starting flow: race-500/first-nondeterministic
2016-01-14 17:14:15,258 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] at least one sink is marked for delete
2016-01-14 17:14:15,258 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:14:15,366 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] starting
2016-01-14 17:14:15,366 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/ips.20.txt"]
2016-01-14 17:14:15,367 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-500/first-nondeterministic"]
2016-01-14 17:14:15,367 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] parallel execution of steps is enabled: true
2016-01-14 17:14:15,367 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] executing total steps: 1
2016-01-14 17:14:15,367 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] allocating management threads: 1
2016-01-14 17:14:15,405 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-01-14 17:14:15,696 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopping all flows
2016-01-14 17:14:15,716 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopping flow: race-500/first-nondeterministic
2016-01-14 17:14:15,716 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] stopping all jobs
2016-01-14 17:14:15,717 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-01-14 17:14:15,717 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] stopped all jobs
2016-01-14 17:14:15,717 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] shutting down job executor
2016-01-14 17:14:15,985 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:16,759 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] submitted hadoop job: job_20160114171404315_0010
2016-01-14 17:14:16,759 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] tracking url: http://localhost:56220/jobdetails.jsp?jobid=job_20160114171404315_0010
2016-01-14 17:14:16,766 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] shutdown complete
2016-01-14 17:14:16,766 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopped all flows
2016-01-14 17:14:16,767 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] shutting down flow executor
2016-01-14 17:14:16,767 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [race-500/first-nondete...] completed in: 00:00.350
2016-01-14 17:14:16,767 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] completed flow: race-500/first-nondeterministic
2016-01-14 17:14:16,769 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] shutdown complete
2016-01-14 17:14:16,769 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-500/first-nondeterministic
2016-01-14 17:14:16,778 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-450/first-nondeterministic
2016-01-14 17:14:16,792 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-350/first-nondeterministic
2016-01-14 17:14:16,800 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-150/first-nondeterministic
2016-01-14 17:14:16,804 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-200/first-nondeterministic
2016-01-14 17:14:16,809 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-50/first-nondeterministic
2016-01-14 17:14:16,816 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-100/first-nondeterministic
2016-01-14 17:14:16,821 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-0/first-nondeterministic
2016-01-14 17:14:16,822 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-300/first-nondeterministic
2016-01-14 17:14:16,830 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-400/first-nondeterministic
2016-01-14 17:14:16,834 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascadeRaceCondition/race-250/first-nondeterministic
2016-01-14 17:14:16,898 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:16,899 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:16,989 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.073
2016-01-14 17:14:16,995 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:14:16,995 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:17,021 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:17,022 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:17,082 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.056
2016-01-14 17:14:17,083 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:14:17,083 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:17,112 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:17,113 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:17,144 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.026
2016-01-14 17:14:17,145 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:14:17,145 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:17,169 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:17,170 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:17,231 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.057
2016-01-14 17:14:17,234 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 17:14:17,234 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:17,278 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 17:14:17,280 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 17:14:17,350 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.057
2016-01-14 17:14:17,351 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 17:14:17,351 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 17:14:17,392 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting
2016-01-14 17:14:17,393 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] parallel execution of flows is enabled: true
2016-01-14 17:14:17,393 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] executing total flows: 5
2016-01-14 17:14:17,395 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] allocating management threads: 5
2016-01-14 17:14:17,396 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: first1
2016-01-14 17:14:17,396 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] at least one sink is marked for delete
2016-01-14 17:14:17,396 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: first2
2016-01-14 17:14:17,398 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] at least one sink is marked for delete
2016-01-14 17:14:17,398 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:14:17,400 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:14:17,404 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] starting
2016-01-14 17:14:17,404 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/ips.20.txt"]
2016-01-14 17:14:17,405 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascade/first1"]
2016-01-14 17:14:17,406 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] parallel execution of steps is enabled: true
2016-01-14 17:14:17,406 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] executing total steps: 1
2016-01-14 17:14:17,407 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] allocating management threads: 1
2016-01-14 17:14:17,407 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] starting
2016-01-14 17:14:17,409 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/ips.20.txt"]
2016-01-14 17:14:17,409 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascade/first2"]
2016-01-14 17:14:17,409 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] parallel execution of steps is enabled: true
2016-01-14 17:14:17,409 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] executing total steps: 1
2016-01-14 17:14:17,409 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] allocating management threads: 1
2016-01-14 17:14:17,413 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] starting step: (1/1) ...atform/testCascade/first1
2016-01-14 17:14:17,414 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] starting step: (1/1) ...atform/testCascade/first2
2016-01-14 17:14:18,146 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] submitted hadoop job: job_20160114171404315_0011
2016-01-14 17:14:18,147 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] tracking url: http://localhost:56220/jobdetails.jsp?jobid=job_20160114171404315_0011
2016-01-14 17:14:18,218 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] submitted hadoop job: job_20160114171404315_0012
2016-01-14 17:14:18,219 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] tracking url: http://localhost:56220/jobdetails.jsp?jobid=job_20160114171404315_0012
2016-01-14 17:14:18,909 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:19,129 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:21,314 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:21,516 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:21,761 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:22,097 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:24,687 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:25,326 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:28,297 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:29,057 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:30,423 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:30,784 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:32,833 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:33,277 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:34,994 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:35,081 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:35,701 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:39,368 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:40,309 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:40,429 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:41,050 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:41,151 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:45,978 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:46,513 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:46,647 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:49,085 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:51,428 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:51,474 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:52,270 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:52,460 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:56,620 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:56,829 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:57,158 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:14:59,669 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:01,607 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:02,022 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:02,412 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:03,388 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:03,638 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:05,696 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:06,251 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:06,719 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:07,043 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(1993)) - Unknown job job_20160114171404315_0004 being deleted.
2016-01-14 17:15:09,598 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:09,966 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(1993)) - Unknown job job_20160114171404315_0005 being deleted.
2016-01-14 17:15:12,251 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:13,075 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:13,128 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:14,020 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:14,051 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:14,581 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:16,890 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:18,363 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:18,479 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(1993)) - Unknown job job_20160114171404315_0007 being deleted.
2016-01-14 17:15:20,473 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:23,684 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:25,196 WARN mapred.TaskTracker (TaskTracker.java:statusUpdate(3281)) - Failed validating JVM
java.io.IOException: JvmValidate Failed. Ignoring request from task: attempt_20160114171404315_0010_m_000002_0, with JvmId: jvm_20160114171404315_0010_m_-359876889
at org.apache.hadoop.mapred.TaskTracker.validateJVM(TaskTracker.java:3209)
at org.apache.hadoop.mapred.TaskTracker.statusUpdate(TaskTracker.java:3279)
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:563)
at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1388)
at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1384)
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:1059)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:1382)
2016-01-14 17:15:25,264 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:25,284 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:29,362 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:30,910 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(1993)) - Unknown job job_20160114171404315_0009 being deleted.
2016-01-14 17:15:32,410 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:34,996 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:38,530 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:40,325 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(1993)) - Unknown job job_20160114171404315_0011 being deleted.
2016-01-14 17:15:40,351 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascade/first1/_temporary
2016-01-14 17:15:40,352 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first1] completed in: 01:22.946
2016-01-14 17:15:40,353 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: first1
2016-01-14 17:15:40,353 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: second1
2016-01-14 17:15:40,353 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] at least one sink is marked for delete
2016-01-14 17:15:40,353 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:15:40,355 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] starting
2016-01-14 17:15:40,356 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascade/first1"]
2016-01-14 17:15:40,356 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascade/second1"]
2016-01-14 17:15:40,356 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] parallel execution of steps is enabled: true
2016-01-14 17:15:40,357 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] executing total steps: 1
2016-01-14 17:15:40,357 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] allocating management threads: 1
2016-01-14 17:15:40,358 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] starting step: (1/1) ...tform/testCascade/second1
2016-01-14 17:15:40,562 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:40,590 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascade/first2/_temporary
2016-01-14 17:15:40,591 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first2] completed in: 01:23.182
2016-01-14 17:15:40,592 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: first2
2016-01-14 17:15:40,592 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: second2
2016-01-14 17:15:40,592 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] at least one sink is marked for delete
2016-01-14 17:15:40,592 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:15:40,597 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] starting
2016-01-14 17:15:40,597 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascade/first2"]
2016-01-14 17:15:40,598 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascade/second2"]
2016-01-14 17:15:40,598 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] parallel execution of steps is enabled: true
2016-01-14 17:15:40,598 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] executing total steps: 1
2016-01-14 17:15:40,599 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] allocating management threads: 1
2016-01-14 17:15:40,600 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] starting step: (1/1) ...tform/testCascade/second2
2016-01-14 17:15:40,872 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] submitted hadoop job: job_20160114171404315_0013
2016-01-14 17:15:40,872 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] tracking url: http://localhost:56220/jobdetails.jsp?jobid=job_20160114171404315_0013
2016-01-14 17:15:41,023 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:41,311 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:41,382 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:41,499 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] submitted hadoop job: job_20160114171404315_0014
2016-01-14 17:15:41,499 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] tracking url: http://localhost:56220/jobdetails.jsp?jobid=job_20160114171404315_0014
2016-01-14 17:15:43,330 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(1993)) - Unknown job job_20160114171404315_0012 being deleted.
2016-01-14 17:15:43,803 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:44,664 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:49,556 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:15:54,092 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:16:00,945 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:16:10,420 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascade/second1/_temporary
2016-01-14 17:16:10,421 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second1] completed in: 00:30.063
2016-01-14 17:16:10,421 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: second1
2016-01-14 17:16:10,606 WARN mapred.TaskTracker (TaskTracker.java:purgeJob(1993)) - Unknown job job_20160114171404315_0013 being deleted.
2016-01-14 17:16:10,652 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:16:13,375 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascade/second2/_temporary
2016-01-14 17:16:13,376 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second2] completed in: 00:32.777
2016-01-14 17:16:13,376 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: second2
2016-01-14 17:16:13,376 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: lhs*rhs
2016-01-14 17:16:13,376 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] at least one sink is marked for delete
2016-01-14 17:16:13,376 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 17:16:13,380 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] starting
2016-01-14 17:16:13,380 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascade/second2"]
2016-01-14 17:16:13,380 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascade/second1"]
2016-01-14 17:16:13,381 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascade/third"]
2016-01-14 17:16:13,381 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] parallel execution of steps is enabled: true
2016-01-14 17:16:13,381 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] executing total steps: 1
2016-01-14 17:16:13,382 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] allocating management threads: 1
2016-01-14 17:16:13,383 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] starting step: (1/1) ...latform/testCascade/third
2016-01-14 17:16:13,629 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:16:13,890 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] submitted hadoop job: job_20160114171404315_0015
2016-01-14 17:16:13,890 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] tracking url: http://localhost:56220/jobdetails.jsp?jobid=job_20160114171404315_0015
2016-01-14 17:16:13,891 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:16:13,967 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:16:14,263 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:16:14,906 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:16:14,963 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:16:15,074 WARN mapred.DefaultTaskController (DefaultTaskController.java:launchTask(137)) - Exit code from task is : 143
2016-01-14 17:16:55,409 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/parallelcascadeplatform/testCascade/third/_temporary
2016-01-14 17:16:55,410 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] completed in: 00:42.028
2016-01-14 17:16:55,410 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: lhs*rhs
2016-01-14 17:16:55,428 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascade/first1
2016-01-14 17:16:55,441 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascade/first2
2016-01-14 17:16:55,451 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascade/second1
2016-01-14 17:16:55,462 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascade/second2
2016-01-14 17:16:55,475 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/parallelcascadeplatform/testCascade/third