2016-01-14 21:11:45,245 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 21:11:45,278 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.cascade.CascadePlatformTest, with platform: hadoop2-mr1
2016-01-14 21:11:45,316 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-01-14 21:11:46,149 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
Formatting using clusterid: testClusterID
2016-01-14 21:11:46,793 WARN impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-01-14 21:11:47,338 WARN server.AuthenticationFilter (AuthenticationFilter.java:init(162)) - 'signature.secret' configuration not set, using a random value as secret
2016-01-14 21:11:50,583 WARN containermanager.AuxServices (AuxServices.java:serviceInit(114)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for class class org.apache.hadoop.mapred.ShuffleHandler which has a name of 'httpshuffle'. Because these are not the same tools trying to send ServiceData and read Service Meta Data may have issues unless the refer to the name in the config.
2016-01-14 21:11:50,731 WARN containermanager.AuxServices (AuxServices.java:serviceInit(114)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for class class org.apache.hadoop.mapred.ShuffleHandler which has a name of 'httpshuffle'. Because these are not the same tools trying to send ServiceData and read Service Meta Data may have issues unless the refer to the name in the config.
2016-01-14 21:11:50,848 WARN containermanager.AuxServices (AuxServices.java:serviceInit(114)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for class class org.apache.hadoop.mapred.ShuffleHandler which has a name of 'httpshuffle'. Because these are not the same tools trying to send ServiceData and read Service Meta Data may have issues unless the refer to the name in the config.
2016-01-14 21:11:50,965 WARN containermanager.AuxServices (AuxServices.java:serviceInit(114)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for class class org.apache.hadoop.mapred.ShuffleHandler which has a name of 'httpshuffle'. Because these are not the same tools trying to send ServiceData and read Service Meta Data may have issues unless the refer to the name in the config.
2016-01-14 21:12:08,041 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 21:12:08,151 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:12:08,152 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:12:08,224 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: F1C8558CC76A4A2DA28535F14672820C
2016-01-14 21:12:08,327 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.067
2016-01-14 21:12:08,329 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:12:08,330 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:12:08,450 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:12:08,450 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:12:08,498 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.040
2016-01-14 21:12:08,500 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:12:08,500 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:12:08,534 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:12:08,535 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:12:08,577 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.034
2016-01-14 21:12:08,579 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:12:08,579 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:12:08,644 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:12:08,645 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:12:08,687 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.034
2016-01-14 21:12:08,688 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:12:08,688 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:12:08,711 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 21:12:08,711 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] starting
2016-01-14 21:12:08,717 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] parallel execution of flows is enabled: true
2016-01-14 21:12:08,718 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] executing total flows: 4
2016-01-14 21:12:08,718 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] allocating management threads: 4
2016-01-14 21:12:08,719 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] starting flow: first
2016-01-14 21:12:08,721 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] skipping flow: first
2016-01-14 21:12:08,722 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] starting flow: second
2016-01-14 21:12:08,722 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] skipping flow: second
2016-01-14 21:12:08,723 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] starting flow: third
2016-01-14 21:12:08,724 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] skipping flow: third
2016-01-14 21:12:08,725 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] starting flow: fourth
2016-01-14 21:12:08,726 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] skipping flow: fourth
2016-01-14 21:12:08,732 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSkippedCascade/skipped/fourth
2016-01-14 21:12:08,733 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSkippedCascade/skipped/first
2016-01-14 21:12:08,735 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSkippedCascade/skipped/second
2016-01-14 21:12:08,736 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSkippedCascade/skipped/third
2016-01-14 21:12:08,758 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:12:08,758 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:12:08,807 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.041
2016-01-14 21:12:08,808 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:12:08,809 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:12:08,839 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:12:08,839 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:12:08,875 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.031
2016-01-14 21:12:08,876 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:12:08,877 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:12:08,900 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:12:08,900 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:12:08,936 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [multi-tap] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.031
2016-01-14 21:12:08,937 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [multi-tap] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:12:08,937 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [multi-tap] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:12:08,954 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] starting
2016-01-14 21:12:08,956 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] parallel execution of flows is enabled: true
2016-01-14 21:12:08,956 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] executing total flows: 3
2016-01-14 21:12:08,956 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] allocating management threads: 3
2016-01-14 21:12:08,956 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] starting flow: previous-multi-tap-second
2016-01-14 21:12:08,957 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-second] at least one sink is marked for delete
2016-01-14 21:12:08,957 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-second] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:12:08,957 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] starting flow: previous-multi-tap-first
2016-01-14 21:12:08,958 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-first] at least one sink is marked for delete
2016-01-14 21:12:08,958 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:12:08,976 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-first] starting
2016-01-14 21:12:08,976 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-second] starting
2016-01-14 21:12:08,977 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-second] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 21:12:08,977 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-first] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 21:12:08,978 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-second] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/second"]
2016-01-14 21:12:08,978 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-first] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/first"]
2016-01-14 21:12:08,978 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-first] parallel execution of steps is enabled: true
2016-01-14 21:12:08,978 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-first] executing total steps: 1
2016-01-14 21:12:08,978 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-first] allocating management threads: 1
2016-01-14 21:12:08,978 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-second] parallel execution of steps is enabled: true
2016-01-14 21:12:08,980 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-second] executing total steps: 1
2016-01-14 21:12:08,980 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-second] allocating management threads: 1
2016-01-14 21:12:08,983 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-first] starting step: (1/1) ...TapCascade/multitap/first
2016-01-14 21:12:08,984 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-second] starting step: (1/1) ...apCascade/multitap/second
2016-01-14 21:12:10,103 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-first] submitted hadoop job: job_1452805922540_0002
2016-01-14 21:12:10,103 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-first] tracking url: http://ip-10-167-78-165:58941/proxy/application_1452805922540_0002/
2016-01-14 21:12:10,104 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-second] submitted hadoop job: job_1452805922540_0001
2016-01-14 21:12:10,104 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-second] tracking url: http://ip-10-167-78-165:58941/proxy/application_1452805922540_0001/
2016-01-14 21:12:37,451 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0001_01_000002 is : 143
2016-01-14 21:12:37,745 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0001_01_000003 is : 143
2016-01-14 21:12:38,649 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0001_01_000004 is : 143
2016-01-14 21:12:39,109 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0001_01_000005 is : 143
2016-01-14 21:12:39,248 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0002_01_000005 is : 143
2016-01-14 21:12:39,574 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0002_01_000004 is : 143
2016-01-14 21:12:40,719 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0002_01_000003 is : 143
2016-01-14 21:12:40,787 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0002_01_000002 is : 143
2016-01-14 21:12:40,941 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/second/_temporary
2016-01-14 21:12:40,948 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-second] completed in: 00:31.957, using cpu time: 00:05.810
2016-01-14 21:12:40,948 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] completed flow: previous-multi-tap-second
2016-01-14 21:12:42,120 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/first/_temporary
2016-01-14 21:12:42,121 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [previous-multi-tap-first] completed in: 00:33.142, using cpu time: 00:05.510
2016-01-14 21:12:42,122 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] completed flow: previous-multi-tap-first
2016-01-14 21:12:42,122 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] starting flow: multi-tap
2016-01-14 21:12:42,122 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [multi-tap] at least one sink is marked for delete
2016-01-14 21:12:42,122 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [multi-tap] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:12:42,126 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [multi-tap] starting
2016-01-14 21:12:42,126 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [multi-tap] source: MultiSourceTap[2:[Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/first"], Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/second"]]]
2016-01-14 21:12:42,126 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [multi-tap] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/multitap"]
2016-01-14 21:12:42,127 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [multi-tap] parallel execution of steps is enabled: true
2016-01-14 21:12:42,127 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [multi-tap] executing total steps: 1
2016-01-14 21:12:42,127 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [multi-tap] allocating management threads: 1
2016-01-14 21:12:42,128 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [multi-tap] starting step: (1/1) ...Cascade/multitap/multitap
2016-01-14 21:12:42,295 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [multi-tap] submitted hadoop job: job_1452805922540_0003
2016-01-14 21:12:42,295 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [multi-tap] tracking url: http://ip-10-167-78-165:58941/proxy/application_1452805922540_0003/
2016-01-14 21:13:11,221 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0003_01_000002 is : 143
2016-01-14 21:13:11,373 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0003_01_000003 is : 143
2016-01-14 21:13:13,426 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0003_01_000007 is : 143
2016-01-14 21:13:13,503 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0003_01_000009 is : 143
2016-01-14 21:13:13,816 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0003_01_000006 is : 143
2016-01-14 21:13:13,885 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0003_01_000004 is : 143
2016-01-14 21:13:14,474 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0003_01_000005 is : 143
2016-01-14 21:13:14,478 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0003_01_000008 is : 143
2016-01-14 21:13:15,761 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/multitap/_temporary
2016-01-14 21:13:15,762 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [multi-tap] completed in: 00:33.632, using cpu time: 00:12.750
2016-01-14 21:13:15,763 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] completed flow: multi-tap
2016-01-14 21:13:15,852 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/multitap
2016-01-14 21:13:15,877 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/first
2016-01-14 21:13:15,903 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/second
2016-01-14 21:13:15,932 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:13:15,932 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:13:15,962 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-01-14 21:13:15,963 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:13:15,964 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:13:15,986 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:13:15,987 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:13:16,017 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.026
2016-01-14 21:13:16,018 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:13:16,019 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:13:16,042 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:13:16,043 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:13:16,053 INFO planner.FlowPlanner (FlowPlanner.java:makeTempTap(767)) - found checkpoint: checkpoint, using tap: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/third"]
2016-01-14 21:13:16,091 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.043
2016-01-14 21:13:16,092 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 2
2016-01-14 21:13:16,093 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:13:16,133 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:13:16,133 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:13:16,165 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.028
2016-01-14 21:13:16,166 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:13:16,166 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:13:16,177 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] starting
2016-01-14 21:13:16,177 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] parallel execution of flows is enabled: true
2016-01-14 21:13:16,177 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] executing total flows: 4
2016-01-14 21:13:16,178 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] allocating management threads: 4
2016-01-14 21:13:16,178 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] starting flow: first
2016-01-14 21:13:16,179 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] at least one sink is marked for delete
2016-01-14 21:13:16,179 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:13:16,183 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting
2016-01-14 21:13:16,183 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 21:13:16,183 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/first"]
2016-01-14 21:13:16,183 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] parallel execution of steps is enabled: true
2016-01-14 21:13:16,183 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executing total steps: 1
2016-01-14 21:13:16,183 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] allocating management threads: 1
2016-01-14 21:13:16,184 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting step: (1/1) ...pCascade/checkpoint/first
2016-01-14 21:13:16,332 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] submitted hadoop job: job_1452805922540_0004
2016-01-14 21:13:16,332 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] tracking url: http://ip-10-167-78-165:58941/proxy/application_1452805922540_0004/
2016-01-14 21:13:32,904 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0004_01_000005 is : 143
2016-01-14 21:13:33,020 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0004_01_000003 is : 143
2016-01-14 21:13:33,127 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0004_01_000004 is : 143
2016-01-14 21:13:34,170 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0004_01_000002 is : 143
2016-01-14 21:13:35,401 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/first/_temporary
2016-01-14 21:13:35,402 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] completed in: 00:19.217, using cpu time: 00:05.950
2016-01-14 21:13:35,402 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] completed flow: first
2016-01-14 21:13:35,403 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] starting flow: second
2016-01-14 21:13:35,403 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] at least one sink is marked for delete
2016-01-14 21:13:35,403 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:13:35,407 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting
2016-01-14 21:13:35,407 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/first"]
2016-01-14 21:13:35,408 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/second"]
2016-01-14 21:13:35,408 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] parallel execution of steps is enabled: true
2016-01-14 21:13:35,408 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executing total steps: 1
2016-01-14 21:13:35,408 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] allocating management threads: 1
2016-01-14 21:13:35,409 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting step: (1/1) ...Cascade/checkpoint/second
2016-01-14 21:13:35,562 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] submitted hadoop job: job_1452805922540_0005
2016-01-14 21:13:35,562 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] tracking url: http://ip-10-167-78-165:58941/proxy/application_1452805922540_0005/
2016-01-14 21:13:53,543 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0005_01_000003 is : 143
2016-01-14 21:13:54,293 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0005_01_000002 is : 143
2016-01-14 21:13:54,414 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0005_01_000006 is : 143
2016-01-14 21:13:54,599 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0005_01_000004 is : 143
2016-01-14 21:13:54,774 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0005_01_000005 is : 143
2016-01-14 21:13:56,030 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/second/_temporary
2016-01-14 21:13:56,031 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] completed in: 00:20.621, using cpu time: 00:06.800
2016-01-14 21:13:56,031 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] completed flow: second
2016-01-14 21:13:56,031 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] starting flow: null
2016-01-14 21:13:56,032 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] at least one sink is marked for delete
2016-01-14 21:13:56,032 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:13:56,037 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] starting
2016-01-14 21:13:56,038 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/second"]
2016-01-14 21:13:56,038 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/unusedpath"]
2016-01-14 21:13:56,038 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] parallel execution of steps is enabled: true
2016-01-14 21:13:56,038 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] executing total steps: 2
2016-01-14 21:13:56,038 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] allocating management threads: 2
2016-01-14 21:13:56,041 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] starting step: (1/2) ...pCascade/checkpoint/third
2016-01-14 21:13:56,216 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] submitted hadoop job: job_1452805922540_0006
2016-01-14 21:13:56,217 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] tracking url: http://ip-10-167-78-165:58941/proxy/application_1452805922540_0006/
2016-01-14 21:14:16,534 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0006_01_000002 is : 143
2016-01-14 21:14:16,745 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0006_01_000003 is : 143
2016-01-14 21:14:16,795 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0006_01_000007 is : 143
2016-01-14 21:14:17,196 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0006_01_000006 is : 143
2016-01-14 21:14:17,514 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0006_01_000005 is : 143
2016-01-14 21:14:17,577 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0006_01_000004 is : 143
2016-01-14 21:14:18,778 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] starting step: (2/2) ...ointTapCascade/unusedpath
2016-01-14 21:14:18,874 WARN blockmanagement.BlockPlacementPolicy (BlockPlacementPolicyDefault.java:chooseTarget(309)) - Failed to place enough replicas, still in need of 1 to reach 4. For more information, please enable DEBUG log level on org.apache.hadoop.hdfs.server.blockmanagement.BlockPlacementPolicy
2016-01-14 21:14:18,937 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] submitted hadoop job: job_1452805922540_0007
2016-01-14 21:14:18,937 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] tracking url: http://ip-10-167-78-165:58941/proxy/application_1452805922540_0007/
2016-01-14 21:14:41,997 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0007_01_000002 is : 143
2016-01-14 21:14:42,404 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0007_01_000007 is : 143
2016-01-14 21:14:42,784 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0007_01_000006 is : 143
2016-01-14 21:14:42,873 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0007_01_000008 is : 143
2016-01-14 21:14:42,939 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0007_01_000004 is : 143
2016-01-14 21:14:43,017 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0007_01_000005 is : 143
2016-01-14 21:14:44,274 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/third/_temporary
2016-01-14 21:14:44,275 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/unusedpath/_temporary
2016-01-14 21:14:44,276 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] completed in: 00:48.234, using cpu time: 00:16.640
2016-01-14 21:14:44,277 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] completed flow: null
2016-01-14 21:14:44,277 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] starting flow: fourth
2016-01-14 21:14:44,277 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] at least one sink is marked for delete
2016-01-14 21:14:44,277 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:14:44,280 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] starting
2016-01-14 21:14:44,280 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/third"]
2016-01-14 21:14:44,281 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/fourth"]
2016-01-14 21:14:44,281 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] parallel execution of steps is enabled: true
2016-01-14 21:14:44,281 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] executing total steps: 1
2016-01-14 21:14:44,281 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] allocating management threads: 1
2016-01-14 21:14:44,282 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] starting step: (1/1) ...Cascade/checkpoint/fourth
2016-01-14 21:14:44,409 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] submitted hadoop job: job_1452805922540_0008
2016-01-14 21:14:44,410 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] tracking url: http://ip-10-167-78-165:58941/proxy/application_1452805922540_0008/
2016-01-14 21:15:06,685 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0008_01_000003 is : 143
2016-01-14 21:15:07,110 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0008_01_000002 is : 143
2016-01-14 21:15:07,730 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0008_01_000006 is : 143
2016-01-14 21:15:08,113 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0008_01_000008 is : 143
2016-01-14 21:15:08,167 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0008_01_000007 is : 143
2016-01-14 21:15:08,352 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0008_01_000005 is : 143
2016-01-14 21:15:08,514 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0008_01_000004 is : 143
2016-01-14 21:15:09,770 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/fourth/_temporary
2016-01-14 21:15:09,771 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] completed in: 00:25.488, using cpu time: 00:08.540
2016-01-14 21:15:09,771 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] completed flow: fourth
2016-01-14 21:15:09,809 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/first
2016-01-14 21:15:09,821 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/third
2016-01-14 21:15:09,833 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/fourth
2016-01-14 21:15:09,847 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/second
2016-01-14 21:15:09,859 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/unusedpath
2016-01-14 21:15:09,888 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:15:09,889 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:15:09,919 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.026
2016-01-14 21:15:09,921 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:15:09,921 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:15:09,946 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:15:09,946 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:15:09,971 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.021
2016-01-14 21:15:09,972 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:15:09,973 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:15:09,993 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:15:09,993 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:15:10,022 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-01-14 21:15:10,023 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:15:10,023 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:15:10,042 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:15:10,042 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:15:10,069 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.023
2016-01-14 21:15:10,070 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:15:10,070 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:15:10,082 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] starting
2016-01-14 21:15:10,083 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] parallel execution of flows is enabled: true
2016-01-14 21:15:10,083 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] executing total flows: 4
2016-01-14 21:15:10,083 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] allocating management threads: 4
2016-01-14 21:15:10,085 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] starting flow: first
2016-01-14 21:15:10,085 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] at least one sink is marked for delete
2016-01-14 21:15:10,085 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:15:10,088 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting
2016-01-14 21:15:10,088 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 21:15:10,088 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascadeFail/simple/first"]
2016-01-14 21:15:10,088 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] parallel execution of steps is enabled: true
2016-01-14 21:15:10,089 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executing total steps: 1
2016-01-14 21:15:10,089 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] allocating management threads: 1
2016-01-14 21:15:10,090 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting step: (1/1) ...eCascadeFail/simple/first
2016-01-14 21:15:10,228 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] submitted hadoop job: job_1452805922540_0009
2016-01-14 21:15:10,229 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] tracking url: http://ip-10-167-78-165:58941/proxy/application_1452805922540_0009/
2016-01-14 21:15:25,726 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000002 is : 143
2016-01-14 21:15:25,786 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000003 is : 143
2016-01-14 21:15:25,903 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000005 is : 143
2016-01-14 21:15:26,049 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000004 is : 143
2016-01-14 21:15:35,646 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000007 is : 143
2016-01-14 21:15:35,795 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000006 is : 143
2016-01-14 21:15:36,141 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000008 is : 143
2016-01-14 21:15:36,178 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000009 is : 143
2016-01-14 21:15:39,758 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452805922540_0009_01_000014
2016-01-14 21:15:40,120 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452805922540_0009_01_000015
2016-01-14 21:15:40,165 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452805922540_0009_01_000016
2016-01-14 21:15:40,616 WARN containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(831)) - Event EventType: KILL_CONTAINER sent to absent container container_1452805922540_0009_01_000017
2016-01-14 21:15:45,274 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000012 is : 143
2016-01-14 21:15:45,408 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000010 is : 143
2016-01-14 21:15:45,602 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000011 is : 143
2016-01-14 21:15:45,933 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000013 is : 143
2016-01-14 21:15:55,620 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000021 is : 143
2016-01-14 21:15:55,627 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000018 is : 143
2016-01-14 21:15:55,634 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000020 is : 143
2016-01-14 21:15:55,662 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0009_01_000019 is : 143
2016-01-14 21:15:56,838 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [first] hadoop job job_1452805922540_0009 state at FAILED
2016-01-14 21:15:56,839 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [first] failure info: Task failed task_1452805922540_0009_m_000003
Job failed as tasks failed. failedMaps:1 failedReduces:0
2016-01-14 21:15:56,864 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [first] task completion events identify failed tasks
2016-01-14 21:15:56,864 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [first] task completion events count: 10
2016-01-14 21:15:56,865 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [first] event = Task Id : attempt_1452805922540_0009_m_000000_0, Status : FAILED
2016-01-14 21:15:56,865 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [first] event = Task Id : attempt_1452805922540_0009_m_000001_0, Status : FAILED
2016-01-14 21:15:56,865 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [first] event = Task Id : attempt_1452805922540_0009_m_000003_0, Status : FAILED
2016-01-14 21:15:56,865 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [first] event = Task Id : attempt_1452805922540_0009_m_000002_0, Status : FAILED
2016-01-14 21:15:56,866 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [first] event = Task Id : attempt_1452805922540_0009_m_000001_1, Status : FAILED
2016-01-14 21:15:56,866 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [first] event = Task Id : attempt_1452805922540_0009_m_000000_1, Status : FAILED
2016-01-14 21:15:56,866 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [first] event = Task Id : attempt_1452805922540_0009_m_000003_1, Status : FAILED
2016-01-14 21:15:56,866 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [first] event = Task Id : attempt_1452805922540_0009_m_000002_1, Status : FAILED
2016-01-14 21:15:56,867 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [first] event = Task Id : attempt_1452805922540_0009_m_000003_2, Status : FAILED
2016-01-14 21:15:56,867 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [first] event = Task Id : attempt_1452805922540_0009_m_000001_2, Status : FAILED
2016-01-14 21:15:56,893 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] stopping all jobs
2016-01-14 21:15:56,894 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] stopping: (1/1) ...eCascadeFail/simple/first
2016-01-14 21:15:56,896 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] stopped all jobs
2016-01-14 21:15:56,898 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascadeFail/simple/first/_temporary
2016-01-14 21:15:56,899 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] completed in: 00:46.808
2016-01-14 21:15:56,900 WARN cascade.Cascade (BaseCascade.java:logWarn(878)) - [fourth+second+third+first] flow failed: first
cascading.flow.FlowException: step failed: (1/1) ...eCascadeFail/simple/first, step id: BF15C8B47D6E40788264D5D49E136B6A, job id: job_1452805922540_0009, please see cluster logs for failure messages
at cascading.flow.planner.FlowStepJob.blockOnJob(FlowStepJob.java:295)
at cascading.flow.planner.FlowStepJob.start(FlowStepJob.java:184)
at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:146)
at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:48)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
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 21:15:56,903 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] stopping all flows
2016-01-14 21:15:56,906 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] stopping flow: fourth
2016-01-14 21:15:56,906 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] stopping all jobs
2016-01-14 21:15:56,906 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] stopping: (1/1) ...CascadeFail/simple/fourth
2016-01-14 21:15:56,907 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] stopped all jobs
2016-01-14 21:15:56,907 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] stopping flow: third
2016-01-14 21:15:56,907 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] stopping all jobs
2016-01-14 21:15:56,908 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] stopping: (1/1) ...eCascadeFail/simple/third
2016-01-14 21:15:56,908 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] stopped all jobs
2016-01-14 21:15:56,908 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] stopping flow: second
2016-01-14 21:15:56,909 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] stopping all jobs
2016-01-14 21:15:56,909 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] stopping: (1/1) ...CascadeFail/simple/second
2016-01-14 21:15:56,909 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] stopped all jobs
2016-01-14 21:15:56,909 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] stopping flow: first
2016-01-14 21:15:56,909 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] stopping all jobs
2016-01-14 21:15:56,909 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] stopping: (1/1) ...eCascadeFail/simple/first
2016-01-14 21:15:56,910 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] stopped all jobs
2016-01-14 21:15:56,910 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] stopped all flows
2016-01-14 21:15:56,911 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeFail/simple/first
2016-01-14 21:15:56,913 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeFail/simple/third
2016-01-14 21:15:56,914 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeFail/simple/fourth
2016-01-14 21:15:56,914 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeFail/simple/second
2016-01-14 21:15:56,928 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:15:56,928 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:15:56,958 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-01-14 21:15:56,958 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:15:56,958 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:15:56,977 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:15:56,978 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:15:57,003 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.021
2016-01-14 21:15:57,004 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:15:57,004 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:15:57,022 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:15:57,022 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:15:57,058 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.032
2016-01-14 21:15:57,059 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:15:57,060 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:15:57,077 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:15:57,077 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:15:57,102 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.021
2016-01-14 21:15:57,104 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:15:57,104 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
calling start
2016-01-14 21:15:57,114 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] starting
2016-01-14 21:15:57,114 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] parallel execution of flows is enabled: true
2016-01-14 21:15:57,114 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] executing total flows: 4
2016-01-14 21:15:57,114 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] allocating management threads: 4
2016-01-14 21:15:57,115 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] starting flow: first
2016-01-14 21:15:57,116 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] at least one sink is marked for delete
2016-01-14 21:15:57,116 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
testing if running
2016-01-14 21:15:57,119 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting
2016-01-14 21:15:57,119 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 21:15:57,120 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascadeStop/stopped/first-nondeterministic"]
2016-01-14 21:15:57,120 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] parallel execution of steps is enabled: true
2016-01-14 21:15:57,120 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executing total steps: 1
2016-01-14 21:15:57,120 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] allocating management threads: 1
2016-01-14 21:15:57,122 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting step: (1/1) ...ed/first-nondeterministic
2016-01-14 21:15:57,264 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] submitted hadoop job: job_1452805922540_0010
2016-01-14 21:15:57,264 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] tracking url: http://ip-10-167-78-165:58941/proxy/application_1452805922540_0010/
testing if running
testing if running
testing if running
testing if running
testing if running
testing if running
testing if running
testing if running
testing if running
testing if running
testing if running
testing if running
testing if running
testing if running
testing if running
2016-01-14 21:16:13,230 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0010_01_000002 is : 143
calling stop
2016-01-14 21:16:13,295 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] stopping all flows
2016-01-14 21:16:13,310 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] stopping flow: fourth
2016-01-14 21:16:13,311 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] stopping all jobs
2016-01-14 21:16:13,311 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] stopping: (1/1) ...d/fourth-nondeterministic
2016-01-14 21:16:13,311 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] stopped all jobs
2016-01-14 21:16:13,311 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] stopping flow: third
2016-01-14 21:16:13,312 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] stopping all jobs
2016-01-14 21:16:13,312 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] stopping: (1/1) ...ed/third-nondeterministic
2016-01-14 21:16:13,312 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] stopped all jobs
2016-01-14 21:16:13,312 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] stopping flow: second
2016-01-14 21:16:13,312 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] stopping all jobs
2016-01-14 21:16:13,313 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] stopping: (1/1) ...d/second-nondeterministic
2016-01-14 21:16:13,313 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] stopped all jobs
2016-01-14 21:16:13,313 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] stopping flow: first
2016-01-14 21:16:13,313 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] stopping all jobs
2016-01-14 21:16:13,338 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] stopping: (1/1) ...ed/first-nondeterministic
2016-01-14 21:16:13,451 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] did not capture all completed node details, will retry in 00:00.010, prior retries: 0
2016-01-14 21:16:13,551 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0010_01_000004 is : 143
2016-01-14 21:16:13,562 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0010_01_000003 is : 143
2016-01-14 21:16:13,666 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0010_01_000005 is : 143
2016-01-14 21:16:15,478 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] stopped all jobs
2016-01-14 21:16:15,478 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] shutting down job executor
2016-01-14 21:16:15,479 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] shutdown complete
2016-01-14 21:16:15,480 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] stopped all flows
2016-01-14 21:16:15,480 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] completed in: 00:16.194, using cpu time: 00:01.500
2016-01-14 21:16:15,481 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] shutting down flow executor
2016-01-14 21:16:15,481 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] completed flow: first
2016-01-14 21:16:15,482 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] shutdown complete
2016-01-14 21:16:15,484 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeStop/stopped/second-nondeterministic
2016-01-14 21:16:15,486 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeStop/stopped/first-nondeterministic
2016-01-14 21:16:15,489 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeStop/stopped/fourth-nondeterministic
2016-01-14 21:16:15,489 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeStop/stopped/third-nondeterministic
2016-01-14 21:16:15,503 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:16:15,503 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:16:15,528 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.021
2016-01-14 21:16:15,529 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:16:15,529 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:16:15,560 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:16:15,560 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:16:15,585 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.021
2016-01-14 21:16:15,587 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:16:15,588 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:16:15,606 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:16:15,606 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:16:15,631 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-01-14 21:16:15,633 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:16:15,633 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:16:15,651 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:16:15,651 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:16:15,676 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-01-14 21:16:15,677 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:16:15,677 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:16:15,686 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] starting
2016-01-14 21:16:15,686 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] parallel execution of flows is enabled: true
2016-01-14 21:16:15,686 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] executing total flows: 4
2016-01-14 21:16:15,686 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] allocating management threads: 4
2016-01-14 21:16:15,687 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] starting flow: first
2016-01-14 21:16:15,687 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] at least one sink is marked for delete
2016-01-14 21:16:15,687 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:16:15,691 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting
2016-01-14 21:16:15,691 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 21:16:15,691 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/first"]
2016-01-14 21:16:15,691 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] parallel execution of steps is enabled: true
2016-01-14 21:16:15,692 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executing total steps: 1
2016-01-14 21:16:15,692 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] allocating management threads: 1
2016-01-14 21:16:15,693 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] starting step: (1/1) ...impleCascade/simple/first
2016-01-14 21:16:15,819 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] submitted hadoop job: job_1452805922540_0011
2016-01-14 21:16:15,819 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] tracking url: http://ip-10-167-78-165:58941/proxy/application_1452805922540_0011/
2016-01-14 21:16:36,724 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0011_01_000003 is : 143
2016-01-14 21:16:36,807 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0011_01_000002 is : 143
2016-01-14 21:16:36,943 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0011_01_000004 is : 143
2016-01-14 21:16:37,182 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0011_01_000005 is : 143
2016-01-14 21:16:38,411 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/first/_temporary
2016-01-14 21:16:38,412 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] completed in: 00:22.718, using cpu time: 00:05.750
2016-01-14 21:16:38,412 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] completed flow: first
2016-01-14 21:16:38,413 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] starting flow: second
2016-01-14 21:16:38,413 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] at least one sink is marked for delete
2016-01-14 21:16:38,413 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:16:38,416 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting
2016-01-14 21:16:38,416 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/first"]
2016-01-14 21:16:38,416 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/second"]
2016-01-14 21:16:38,416 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] parallel execution of steps is enabled: true
2016-01-14 21:16:38,417 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executing total steps: 1
2016-01-14 21:16:38,417 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] allocating management threads: 1
2016-01-14 21:16:38,417 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] starting step: (1/1) ...mpleCascade/simple/second
2016-01-14 21:16:38,548 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] submitted hadoop job: job_1452805922540_0012
2016-01-14 21:16:38,548 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] tracking url: http://ip-10-167-78-165:58941/proxy/application_1452805922540_0012/
2016-01-14 21:17:00,741 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0012_01_000006 is : 143
2016-01-14 21:17:01,909 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0012_01_000004 is : 143
2016-01-14 21:17:01,984 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0012_01_000002 is : 143
2016-01-14 21:17:02,190 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0012_01_000003 is : 143
2016-01-14 21:17:02,427 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0012_01_000005 is : 143
2016-01-14 21:17:03,683 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/second/_temporary
2016-01-14 21:17:03,684 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] completed in: 00:25.265, using cpu time: 00:06.760
2016-01-14 21:17:03,684 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] completed flow: second
2016-01-14 21:17:03,685 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] starting flow: third
2016-01-14 21:17:03,685 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] at least one sink is marked for delete
2016-01-14 21:17:03,685 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:17:03,689 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] starting
2016-01-14 21:17:03,689 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/second"]
2016-01-14 21:17:03,689 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/third"]
2016-01-14 21:17:03,689 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] parallel execution of steps is enabled: true
2016-01-14 21:17:03,689 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] executing total steps: 1
2016-01-14 21:17:03,690 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] allocating management threads: 1
2016-01-14 21:17:03,690 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] starting step: (1/1) ...impleCascade/simple/third
2016-01-14 21:17:03,821 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] submitted hadoop job: job_1452805922540_0013
2016-01-14 21:17:03,822 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] tracking url: http://ip-10-167-78-165:58941/proxy/application_1452805922540_0013/
2016-01-14 21:17:30,457 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0013_01_000002 is : 143
2016-01-14 21:17:30,545 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0013_01_000003 is : 143
2016-01-14 21:17:31,108 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0013_01_000006 is : 143
2016-01-14 21:17:31,171 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0013_01_000004 is : 143
2016-01-14 21:17:31,206 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0013_01_000005 is : 143
2016-01-14 21:17:31,519 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0013_01_000007 is : 143
2016-01-14 21:17:32,756 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/third/_temporary
2016-01-14 21:17:32,757 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] completed in: 00:29.065, using cpu time: 00:07.390
2016-01-14 21:17:32,758 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] completed flow: third
2016-01-14 21:17:32,758 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] starting flow: fourth
2016-01-14 21:17:32,758 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] at least one sink is marked for delete
2016-01-14 21:17:32,759 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-01-14 21:17:32,764 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] starting
2016-01-14 21:17:32,765 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/third"]
2016-01-14 21:17:32,765 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/fourth"]
2016-01-14 21:17:32,765 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] parallel execution of steps is enabled: true
2016-01-14 21:17:32,766 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] executing total steps: 1
2016-01-14 21:17:32,767 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] allocating management threads: 1
2016-01-14 21:17:32,768 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] starting step: (1/1) ...mpleCascade/simple/fourth
2016-01-14 21:17:32,902 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] submitted hadoop job: job_1452805922540_0014
2016-01-14 21:17:32,902 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] tracking url: http://ip-10-167-78-165:58941/proxy/application_1452805922540_0014/
2016-01-14 21:18:00,277 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0014_01_000002 is : 143
2016-01-14 21:18:00,408 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0014_01_000003 is : 143
2016-01-14 21:18:01,876 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0014_01_000006 is : 143
2016-01-14 21:18:02,114 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0014_01_000004 is : 143
2016-01-14 21:18:02,117 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0014_01_000007 is : 143
2016-01-14 21:18:02,167 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0014_01_000005 is : 143
2016-01-14 21:18:02,242 WARN nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1452805922540_0014_01_000008 is : 143
2016-01-14 21:18:03,578 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/fourth/_temporary
2016-01-14 21:18:03,580 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] completed in: 00:30.813, using cpu time: 00:08.340
2016-01-14 21:18:03,580 INFO cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] completed flow: fourth
2016-01-14 21:18:03,604 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/second
2016-01-14 21:18:03,616 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/fourth
2016-01-14 21:18:03,631 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/third
2016-01-14 21:18:03,645 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/first
2016-01-14 21:18:03,676 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:18:03,677 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:18:03,700 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.019
2016-01-14 21:18:03,701 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:18:03,701 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:18:03,728 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:18:03,728 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:18:03,751 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.019
2016-01-14 21:18:03,752 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:18:03,752 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:18:03,771 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:18:03,771 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:18:03,792 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.018
2016-01-14 21:18:03,793 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:18:03,793 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [third] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:18:03,810 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:18:03,810 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:18:03,832 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.018
2016-01-14 21:18:03,833 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:18:03,833 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:18:03,841 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testCascadeID/idtest/fourth
2016-01-14 21:18:03,841 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testCascadeID/idtest/first
2016-01-14 21:18:03,842 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testCascadeID/idtest/second
2016-01-14 21:18:03,843 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/cascadeplatform/testCascadeID/idtest/third
2016-01-14 21:18:03,855 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:18:03,855 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:18:03,878 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.020
2016-01-14 21:18:03,879 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 21:18:03,879 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 21:18:03,911 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 21:18:03,912 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 21:18:03,942 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.027
2016-01-14 21:18:03,944 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 2
2016-01-14 21:18:03,944 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'