Class cascading.cascade.CascadePlatformTest

8

tests

0

failures

0

ignored

7m9.41s

duration

100%

successful

Tests

Test Duration Result
testCascadeID 0.209s passed
testCheckpointTapCascade 2m20.07s passed
testMultiTapCascade 1m20.35s passed
testPlannerFailureDuplicateSinks 0.109s passed
testSimpleCascade 1m48.83s passed
testSimpleCascadeFail 51.082s passed
testSimpleCascadeStop 24.343s passed
testSkippedCascade 24.417s passed

Standard output

2016-05-18 08:14:36,094 INFO  platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 08:14:36,126 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.cascade.CascadePlatformTest, with platform: hadoop2-mr1
2016-05-18 08:14:36,162 INFO  hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-05-18 08:14:37,178 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-05-18 08:14:37,865 WARN  impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-05-18 08:14:42,057 WARN  containermanager.AuxServices (AuxServices.java:serviceInit(130)) - 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-05-18 08:14:42,282 WARN  containermanager.AuxServices (AuxServices.java:serviceInit(130)) - 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-05-18 08:14:42,458 WARN  containermanager.AuxServices (AuxServices.java:serviceInit(130)) - 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-05-18 08:14:42,632 WARN  containermanager.AuxServices (AuxServices.java:serviceInit(130)) - 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-05-18 08:14:59,742 INFO  platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides: 
2016-05-18 08:14:59,841 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:14:59,842 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:14:59,907 INFO  property.AppProps (AppProps.java:getAppID(177)) - using app.id: DC47D87BF44646D4980FBE9B4034C863
2016-05-18 08:15:00,043 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.071
2016-05-18 08:15:00,047 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:15:00,047 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:15:00,239 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:15:00,240 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:15:00,310 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.056
2016-05-18 08:15:00,311 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:15:00,312 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:15:00,366 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:15:00,367 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:15:00,436 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.057
2016-05-18 08:15:00,439 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:15:00,439 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:15:00,470 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:15:00,471 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:15:00,508 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.030
2016-05-18 08:15:00,510 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:15:00,512 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:15:00,544 INFO  util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 08:15:00,544 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] starting
2016-05-18 08:15:00,551 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth]  parallel execution of flows is enabled: true
2016-05-18 08:15:00,551 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth]  executing total flows: 4
2016-05-18 08:15:00,552 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth]  allocating management threads: 4
2016-05-18 08:15:00,553 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] starting flow: first
2016-05-18 08:15:00,555 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] skipping flow: first
2016-05-18 08:15:00,556 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] starting flow: second
2016-05-18 08:15:00,557 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] skipping flow: second
2016-05-18 08:15:00,558 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] starting flow: third
2016-05-18 08:15:00,559 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] skipping flow: third
2016-05-18 08:15:00,560 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] starting flow: fourth
2016-05-18 08:15:00,560 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] skipping flow: fourth
2016-05-18 08:15:00,569 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSkippedCascade/skipped/first
2016-05-18 08:15:00,570 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSkippedCascade/skipped/third
2016-05-18 08:15:00,572 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSkippedCascade/skipped/second
2016-05-18 08:15:00,573 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSkippedCascade/skipped/fourth
2016-05-18 08:15:00,606 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:15:00,607 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:15:00,642 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.029
2016-05-18 08:15:00,643 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:15:00,643 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:15:00,669 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:15:00,670 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:15:00,706 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.032
2016-05-18 08:15:00,707 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:15:00,707 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:15:00,735 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:15:00,735 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:15:00,770 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [multi-tap] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.031
2016-05-18 08:15:00,771 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [multi-tap] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:15:00,771 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [multi-tap] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:15:00,788 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] starting
2016-05-18 08:15:00,790 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...]  parallel execution of flows is enabled: true
2016-05-18 08:15:00,790 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...]  executing total flows: 3
2016-05-18 08:15:00,790 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...]  allocating management threads: 3
2016-05-18 08:15:00,790 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] starting flow: previous-multi-tap-second
2016-05-18 08:15:00,791 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-second] at least one sink is marked for delete
2016-05-18 08:15:00,791 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-second] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 08:15:00,791 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] starting flow: previous-multi-tap-first
2016-05-18 08:15:00,791 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-first] at least one sink is marked for delete
2016-05-18 08:15:00,792 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 08:15:00,817 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-first] starting
2016-05-18 08:15:00,817 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-second] starting
2016-05-18 08:15:00,818 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-second]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/ips.20.txt"]
2016-05-18 08:15:00,818 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-first]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/ips.20.txt"]
2016-05-18 08:15:00,818 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-second]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/second"]
2016-05-18 08:15:00,818 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-second]  parallel execution of steps is enabled: true
2016-05-18 08:15:00,818 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-second]  executing total steps: 1
2016-05-18 08:15:00,818 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-first]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/first"]
2016-05-18 08:15:00,820 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-second]  allocating management threads: 1
2016-05-18 08:15:00,820 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-first]  parallel execution of steps is enabled: true
2016-05-18 08:15:00,820 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-first]  executing total steps: 1
2016-05-18 08:15:00,820 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-first]  allocating management threads: 1
2016-05-18 08:15:00,822 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-second] starting step: (1/1) ...apCascade/multitap/second
2016-05-18 08:15:00,822 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-first] starting step: (1/1) ...TapCascade/multitap/first
2016-05-18 08:15:01,790 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-first] submitted hadoop job: job_1463559294241_0001
2016-05-18 08:15:01,790 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-second] submitted hadoop job: job_1463559294241_0002
2016-05-18 08:15:01,790 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-second] tracking url: http://ip-10-158-37-203:39645/proxy/application_1463559294241_0002/
2016-05-18 08:15:01,790 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-first] tracking url: http://ip-10-158-37-203:39645/proxy/application_1463559294241_0001/
2016-05-18 08:15:19,704 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0001_01_000003 is : 143
2016-05-18 08:15:20,164 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0001_01_000005 is : 143
2016-05-18 08:15:20,380 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0001_01_000004 is : 143
2016-05-18 08:15:20,847 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0001_01_000002 is : 143
2016-05-18 08:15:22,105 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/first/_temporary
2016-05-18 08:15:22,107 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-first]  completed in: 00:21.284, using cpu time: 00:04.580
2016-05-18 08:15:22,107 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] completed flow: previous-multi-tap-first
2016-05-18 08:15:44,352 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0002_01_000003 is : 143
2016-05-18 08:15:44,532 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0002_01_000002 is : 143
2016-05-18 08:15:44,765 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0002_01_000005 is : 143
2016-05-18 08:15:44,952 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0002_01_000004 is : 143
2016-05-18 08:15:46,138 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/second/_temporary
2016-05-18 08:15:46,141 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [previous-multi-tap-second]  completed in: 00:45.319, using cpu time: 00:04.580
2016-05-18 08:15:46,141 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] completed flow: previous-multi-tap-second
2016-05-18 08:15:46,141 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] starting flow: multi-tap
2016-05-18 08:15:46,141 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [multi-tap] at least one sink is marked for delete
2016-05-18 08:15:46,142 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [multi-tap] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 08:15:46,146 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [multi-tap] starting
2016-05-18 08:15:46,146 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [multi-tap]  source: MultiSourceTap[2:[Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/first"], Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/second"]]]
2016-05-18 08:15:46,146 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [multi-tap]  sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/multitap"]
2016-05-18 08:15:46,147 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [multi-tap]  parallel execution of steps is enabled: true
2016-05-18 08:15:46,147 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [multi-tap]  executing total steps: 1
2016-05-18 08:15:46,147 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [multi-tap]  allocating management threads: 1
2016-05-18 08:15:46,148 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [multi-tap] starting step: (1/1) ...Cascade/multitap/multitap
2016-05-18 08:15:46,292 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [multi-tap] submitted hadoop job: job_1463559294241_0003
2016-05-18 08:15:46,292 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [multi-tap] tracking url: http://ip-10-158-37-203:39645/proxy/application_1463559294241_0003/
2016-05-18 08:16:18,346 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0003_01_000002 is : 143
2016-05-18 08:16:18,762 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0003_01_000004 is : 143
2016-05-18 08:16:18,847 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0003_01_000003 is : 143
2016-05-18 08:16:18,896 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0003_01_000006 is : 143
2016-05-18 08:16:19,561 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0003_01_000009 is : 143
2016-05-18 08:16:19,616 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0003_01_000007 is : 143
2016-05-18 08:16:20,833 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/multitap/_temporary
2016-05-18 08:16:20,834 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [multi-tap]  completed in: 00:34.685, using cpu time: 00:09.570
2016-05-18 08:16:20,835 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [multi-tap+previous-mul...] completed flow: multi-tap
2016-05-18 08:16:20,880 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/multitap
2016-05-18 08:16:20,903 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/first
2016-05-18 08:16:20,915 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testMultiTapCascade/multitap/second
2016-05-18 08:16:20,944 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:16:20,945 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:16:20,984 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.035
2016-05-18 08:16:20,987 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:16:20,987 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:16:21,009 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:16:21,010 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:16:21,037 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.023
2016-05-18 08:16:21,037 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:16:21,038 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:16:21,061 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:16:21,061 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:16:21,072 INFO  planner.FlowPlanner (FlowPlanner.java:makeTempTap(768)) - found checkpoint: checkpoint, using tap: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/third"]
2016-05-18 08:16:21,105 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.040
2016-05-18 08:16:21,106 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 2
2016-05-18 08:16:21,106 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:16:21,136 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:16:21,136 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:16:21,167 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.027
2016-05-18 08:16:21,168 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:16:21,168 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:16:21,178 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] starting
2016-05-18 08:16:21,178 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first]  parallel execution of flows is enabled: true
2016-05-18 08:16:21,178 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first]  executing total flows: 4
2016-05-18 08:16:21,179 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first]  allocating management threads: 4
2016-05-18 08:16:21,179 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] starting flow: first
2016-05-18 08:16:21,179 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] at least one sink is marked for delete
2016-05-18 08:16:21,179 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 08:16:21,182 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting
2016-05-18 08:16:21,183 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/ips.20.txt"]
2016-05-18 08:16:21,183 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/first"]
2016-05-18 08:16:21,183 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  parallel execution of steps is enabled: true
2016-05-18 08:16:21,183 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  executing total steps: 1
2016-05-18 08:16:21,183 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  allocating management threads: 1
2016-05-18 08:16:21,184 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting step: (1/1) ...pCascade/checkpoint/first
2016-05-18 08:16:21,315 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] submitted hadoop job: job_1463559294241_0004
2016-05-18 08:16:21,315 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] tracking url: http://ip-10-158-37-203:39645/proxy/application_1463559294241_0004/
2016-05-18 08:16:42,600 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0004_01_000002 is : 143
2016-05-18 08:16:42,662 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0004_01_000003 is : 143
2016-05-18 08:16:43,194 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0004_01_000004 is : 143
2016-05-18 08:16:43,285 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0004_01_000005 is : 143
2016-05-18 08:16:44,472 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/first/_temporary
2016-05-18 08:16:44,474 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  completed in: 00:23.288, using cpu time: 00:04.460
2016-05-18 08:16:44,474 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] completed flow: first
2016-05-18 08:16:44,474 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] starting flow: second
2016-05-18 08:16:44,474 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] at least one sink is marked for delete
2016-05-18 08:16:44,475 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 08:16:44,477 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting
2016-05-18 08:16:44,477 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/first"]
2016-05-18 08:16:44,478 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/second"]
2016-05-18 08:16:44,478 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  parallel execution of steps is enabled: true
2016-05-18 08:16:44,478 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  executing total steps: 1
2016-05-18 08:16:44,478 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  allocating management threads: 1
2016-05-18 08:16:44,479 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting step: (1/1) ...Cascade/checkpoint/second
2016-05-18 08:16:44,602 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] submitted hadoop job: job_1463559294241_0005
2016-05-18 08:16:44,602 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] tracking url: http://ip-10-158-37-203:39645/proxy/application_1463559294241_0005/
2016-05-18 08:17:08,020 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0005_01_000002 is : 143
2016-05-18 08:17:08,217 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0005_01_000005 is : 143
2016-05-18 08:17:08,391 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0005_01_000006 is : 143
2016-05-18 08:17:08,680 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0005_01_000004 is : 143
2016-05-18 08:17:09,861 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/second/_temporary
2016-05-18 08:17:09,863 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  completed in: 00:25.382, using cpu time: 00:05.580
2016-05-18 08:17:09,863 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] completed flow: second
2016-05-18 08:17:09,863 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] starting flow: null
2016-05-18 08:17:09,866 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] at least one sink is marked for delete
2016-05-18 08:17:09,866 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 08:17:09,871 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] starting
2016-05-18 08:17:09,871 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - []  source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/second"]
2016-05-18 08:17:09,872 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - []  sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/unusedpath"]
2016-05-18 08:17:09,872 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - []  parallel execution of steps is enabled: true
2016-05-18 08:17:09,872 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - []  executing total steps: 2
2016-05-18 08:17:09,872 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - []  allocating management threads: 2
2016-05-18 08:17:09,873 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] starting step: (1/2) ...pCascade/checkpoint/third
2016-05-18 08:17:10,064 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] submitted hadoop job: job_1463559294241_0006
2016-05-18 08:17:10,065 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] tracking url: http://ip-10-158-37-203:39645/proxy/application_1463559294241_0006/
2016-05-18 08:17:35,602 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0006_01_000006 is : 143
2016-05-18 08:17:35,806 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0006_01_000007 is : 143
2016-05-18 08:17:36,342 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0006_01_000002 is : 143
2016-05-18 08:17:36,530 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0006_01_000004 is : 143
2016-05-18 08:17:36,867 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0006_01_000005 is : 143
2016-05-18 08:17:37,043 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0006_01_000003 is : 143
2016-05-18 08:17:38,202 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] starting step: (2/2) ...ointTapCascade/unusedpath
2016-05-18 08:17:38,277 WARN  blockmanagement.BlockPlacementPolicy (BlockPlacementPolicyDefault.java:chooseTarget(381)) - Failed to place enough replicas, still in need of 1 to reach 4 (unavailableStorages=[], storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]}, newBlock=true) For more information, please enable DEBUG log level on org.apache.hadoop.hdfs.server.blockmanagement.BlockPlacementPolicy
2016-05-18 08:17:38,277 WARN  protocol.BlockStoragePolicy (BlockStoragePolicy.java:chooseStorageTypes(160)) - Failed to place enough replicas: expected size is 1 but only 0 storage types can be selected (replication=4, selected=[], unavailable=[DISK], removed=[DISK], policy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]})
2016-05-18 08:17:38,278 WARN  blockmanagement.BlockPlacementPolicy (BlockPlacementPolicyDefault.java:chooseTarget(381)) - Failed to place enough replicas, still in need of 1 to reach 4 (unavailableStorages=[DISK], storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]}, newBlock=true) All required storage types are unavailable:  unavailableStorages=[DISK], storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]}
2016-05-18 08:17:38,328 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] submitted hadoop job: job_1463559294241_0007
2016-05-18 08:17:38,328 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] tracking url: http://ip-10-158-37-203:39645/proxy/application_1463559294241_0007/
2016-05-18 08:17:38,818 WARN  blockmanagement.BlockPlacementPolicy (BlockPlacementPolicyDefault.java:chooseTarget(381)) - Failed to place enough replicas, still in need of 1 to reach 4 (unavailableStorages=[], storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]}, newBlock=false) For more information, please enable DEBUG log level on org.apache.hadoop.hdfs.server.blockmanagement.BlockPlacementPolicy
2016-05-18 08:17:38,819 WARN  blockmanagement.BlockPlacementPolicy (BlockPlacementPolicyDefault.java:chooseTarget(381)) - Failed to place enough replicas, still in need of 1 to reach 4 (unavailableStorages=[DISK], storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]}, newBlock=false) For more information, please enable DEBUG log level on org.apache.hadoop.hdfs.server.blockmanagement.BlockPlacementPolicy
2016-05-18 08:17:38,820 WARN  protocol.BlockStoragePolicy (BlockStoragePolicy.java:chooseStorageTypes(160)) - Failed to place enough replicas: expected size is 1 but only 0 storage types can be selected (replication=4, selected=[], unavailable=[DISK, ARCHIVE], removed=[DISK], policy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]})
2016-05-18 08:17:38,820 WARN  blockmanagement.BlockPlacementPolicy (BlockPlacementPolicyDefault.java:chooseTarget(381)) - Failed to place enough replicas, still in need of 1 to reach 4 (unavailableStorages=[DISK, ARCHIVE], storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]}, newBlock=false) All required storage types are unavailable:  unavailableStorages=[DISK, ARCHIVE], storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]}
2016-05-18 08:18:05,725 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0007_01_000006 is : 143
2016-05-18 08:18:06,662 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0007_01_000007 is : 143
2016-05-18 08:18:08,041 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0007_01_000002 is : 143
2016-05-18 08:18:08,063 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0007_01_000008 is : 143
2016-05-18 08:18:08,234 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0007_01_000005 is : 143
2016-05-18 08:18:08,339 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0007_01_000004 is : 143
2016-05-18 08:18:09,548 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/third/_temporary
2016-05-18 08:18:09,550 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/unusedpath/_temporary
2016-05-18 08:18:09,552 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - []  completed in: 00:59.675, using cpu time: 00:14.240
2016-05-18 08:18:09,552 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] completed flow: null
2016-05-18 08:18:09,553 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] starting flow: fourth
2016-05-18 08:18:09,553 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] at least one sink is marked for delete
2016-05-18 08:18:09,553 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 08:18:09,555 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] starting
2016-05-18 08:18:09,556 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/third"]
2016-05-18 08:18:09,556 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/fourth"]
2016-05-18 08:18:09,556 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  parallel execution of steps is enabled: true
2016-05-18 08:18:09,557 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  executing total steps: 1
2016-05-18 08:18:09,557 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  allocating management threads: 1
2016-05-18 08:18:09,558 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] starting step: (1/1) ...Cascade/checkpoint/fourth
2016-05-18 08:18:09,669 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] submitted hadoop job: job_1463559294241_0008
2016-05-18 08:18:09,669 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] tracking url: http://ip-10-158-37-203:39645/proxy/application_1463559294241_0008/
2016-05-18 08:18:37,347 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0008_01_000003 is : 143
2016-05-18 08:18:38,230 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0008_01_000002 is : 143
2016-05-18 08:18:38,817 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0008_01_000005 is : 143
2016-05-18 08:18:39,376 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0008_01_000004 is : 143
2016-05-18 08:18:39,469 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0008_01_000007 is : 143
2016-05-18 08:18:39,518 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0008_01_000006 is : 143
2016-05-18 08:18:39,709 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0008_01_000008 is : 143
2016-05-18 08:18:40,908 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/fourth/_temporary
2016-05-18 08:18:40,909 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  completed in: 00:31.351, using cpu time: 00:07.430
2016-05-18 08:18:40,910 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second++first] completed flow: fourth
2016-05-18 08:18:40,937 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/unusedpath
2016-05-18 08:18:40,951 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/second
2016-05-18 08:18:40,963 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/fourth
2016-05-18 08:18:40,977 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/first
2016-05-18 08:18:40,987 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testCheckpointTapCascade/checkpoint/third
2016-05-18 08:18:41,015 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:18:41,015 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:18:41,043 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.024
2016-05-18 08:18:41,044 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:18:41,044 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:18:41,068 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:18:41,069 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:18:41,093 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.021
2016-05-18 08:18:41,094 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:18:41,094 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:18:41,114 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:18:41,115 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:18:41,141 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.023
2016-05-18 08:18:41,142 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:18:41,142 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:18:41,162 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:18:41,163 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:18:41,190 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.023
2016-05-18 08:18:41,191 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:18:41,191 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:18:41,201 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] starting
2016-05-18 08:18:41,202 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first]  parallel execution of flows is enabled: true
2016-05-18 08:18:41,202 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first]  executing total flows: 4
2016-05-18 08:18:41,202 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first]  allocating management threads: 4
2016-05-18 08:18:41,203 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] starting flow: first
2016-05-18 08:18:41,204 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] at least one sink is marked for delete
2016-05-18 08:18:41,204 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 08:18:41,207 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting
2016-05-18 08:18:41,208 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/ips.20.txt"]
2016-05-18 08:18:41,208 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascadeFail/simple/first"]
2016-05-18 08:18:41,208 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  parallel execution of steps is enabled: true
2016-05-18 08:18:41,208 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  executing total steps: 1
2016-05-18 08:18:41,208 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  allocating management threads: 1
2016-05-18 08:18:41,209 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting step: (1/1) ...eCascadeFail/simple/first
2016-05-18 08:18:41,319 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] submitted hadoop job: job_1463559294241_0009
2016-05-18 08:18:41,319 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] tracking url: http://ip-10-158-37-203:39645/proxy/application_1463559294241_0009/
2016-05-18 08:19:02,380 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0009_01_000004 is : 143
2016-05-18 08:19:02,445 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0009_01_000005 is : 143
2016-05-18 08:19:05,697 WARN  containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(1067)) - Event EventType: KILL_CONTAINER sent to absent container container_1463559294241_0009_01_000010
2016-05-18 08:19:06,015 WARN  containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(1067)) - Event EventType: KILL_CONTAINER sent to absent container container_1463559294241_0009_01_000011
2016-05-18 08:19:06,429 WARN  containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(1067)) - Event EventType: KILL_CONTAINER sent to absent container container_1463559294241_0009_01_000012
2016-05-18 08:19:06,520 WARN  containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(1067)) - Event EventType: KILL_CONTAINER sent to absent container container_1463559294241_0009_01_000013
2016-05-18 08:19:11,565 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0009_01_000006 is : 143
2016-05-18 08:19:12,578 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0009_01_000008 is : 143
2016-05-18 08:19:13,097 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0009_01_000009 is : 143
2016-05-18 08:19:16,019 WARN  containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(1067)) - Event EventType: KILL_CONTAINER sent to absent container container_1463559294241_0009_01_000018
2016-05-18 08:19:16,082 WARN  containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(1067)) - Event EventType: KILL_CONTAINER sent to absent container container_1463559294241_0009_01_000019
2016-05-18 08:19:16,544 WARN  containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(1067)) - Event EventType: KILL_CONTAINER sent to absent container container_1463559294241_0009_01_000020
2016-05-18 08:19:16,701 WARN  containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(1067)) - Event EventType: KILL_CONTAINER sent to absent container container_1463559294241_0009_01_000021
2016-05-18 08:19:20,358 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0009_01_000015 is : 143
2016-05-18 08:19:21,130 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0009_01_000014 is : 143
2016-05-18 08:19:22,239 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0009_01_000016 is : 143
2016-05-18 08:19:25,023 WARN  containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(1067)) - Event EventType: KILL_CONTAINER sent to absent container container_1463559294241_0009_01_000025
2016-05-18 08:19:25,081 WARN  containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(1067)) - Event EventType: KILL_CONTAINER sent to absent container container_1463559294241_0009_01_000026
2016-05-18 08:19:27,024 WARN  containermanager.ContainerManagerImpl (ContainerManagerImpl.java:handle(1067)) - Event EventType: KILL_CONTAINER sent to absent container container_1463559294241_0009_01_000028
2016-05-18 08:19:30,769 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0009_01_000023 is : 143
2016-05-18 08:19:30,771 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0009_01_000022 is : 143
2016-05-18 08:19:30,878 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0009_01_000027 is : 143
2016-05-18 08:19:30,916 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0009_01_000024 is : 143
2016-05-18 08:19:32,003 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [first] hadoop job job_1463559294241_0009 state at FAILED
2016-05-18 08:19:32,004 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [first] failure info: Task failed task_1463559294241_0009_m_000001
Job failed as tasks failed. failedMaps:1 failedReduces:0

2016-05-18 08:19:32,030 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [first] task completion events identify failed tasks
2016-05-18 08:19:32,030 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [first] task completion events count: 10
2016-05-18 08:19:32,030 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [first] event = Task Id : attempt_1463559294241_0009_m_000000_0, Status : FAILED
2016-05-18 08:19:32,031 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [first] event = Task Id : attempt_1463559294241_0009_m_000001_0, Status : FAILED
2016-05-18 08:19:32,031 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [first] event = Task Id : attempt_1463559294241_0009_m_000002_0, Status : FAILED
2016-05-18 08:19:32,031 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [first] event = Task Id : attempt_1463559294241_0009_m_000003_0, Status : FAILED
2016-05-18 08:19:32,031 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [first] event = Task Id : attempt_1463559294241_0009_m_000001_1, Status : FAILED
2016-05-18 08:19:32,031 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [first] event = Task Id : attempt_1463559294241_0009_m_000000_1, Status : FAILED
2016-05-18 08:19:32,032 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [first] event = Task Id : attempt_1463559294241_0009_m_000002_1, Status : FAILED
2016-05-18 08:19:32,032 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [first] event = Task Id : attempt_1463559294241_0009_m_000003_1, Status : FAILED
2016-05-18 08:19:32,032 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [first] event = Task Id : attempt_1463559294241_0009_m_000000_2, Status : FAILED
2016-05-18 08:19:32,032 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [first] event = Task Id : attempt_1463559294241_0009_m_000001_2, Status : FAILED
2016-05-18 08:19:32,064 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] stopping all jobs
2016-05-18 08:19:32,065 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] stopping: (1/1) ...eCascadeFail/simple/first
2016-05-18 08:19:32,066 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] stopped all jobs
2016-05-18 08:19:32,068 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascadeFail/simple/first/_temporary
2016-05-18 08:19:32,069 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  completed in: 00:50.860
2016-05-18 08:19:32,070 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: FF8854E72F1A4EDB9C630F5234E5884B, job id: job_1463559294241_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-05-18 08:19:32,073 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] stopping all flows
2016-05-18 08:19:32,073 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] stopping flow: fourth
2016-05-18 08:19:32,074 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] stopping all jobs
2016-05-18 08:19:32,074 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] stopping: (1/1) ...CascadeFail/simple/fourth
2016-05-18 08:19:32,074 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] stopped all jobs
2016-05-18 08:19:32,075 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] stopping flow: third
2016-05-18 08:19:32,075 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] stopping all jobs
2016-05-18 08:19:32,075 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] stopping: (1/1) ...eCascadeFail/simple/third
2016-05-18 08:19:32,076 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] stopped all jobs
2016-05-18 08:19:32,076 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] stopping flow: second
2016-05-18 08:19:32,076 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] stopping all jobs
2016-05-18 08:19:32,076 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] stopping: (1/1) ...CascadeFail/simple/second
2016-05-18 08:19:32,077 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] stopped all jobs
2016-05-18 08:19:32,077 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] stopping flow: first
2016-05-18 08:19:32,077 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] stopping all jobs
2016-05-18 08:19:32,077 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] stopping: (1/1) ...eCascadeFail/simple/first
2016-05-18 08:19:32,078 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] stopped all jobs
2016-05-18 08:19:32,078 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] stopped all flows
2016-05-18 08:19:32,078 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeFail/simple/third
2016-05-18 08:19:32,079 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeFail/simple/first
2016-05-18 08:19:32,081 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeFail/simple/fourth
2016-05-18 08:19:32,082 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeFail/simple/second
2016-05-18 08:19:32,097 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:19:32,097 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:19:32,131 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.029
2016-05-18 08:19:32,132 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:19:32,132 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:19:32,151 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:19:32,151 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:19:32,176 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-05-18 08:19:32,177 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:19:32,177 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:19:32,195 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:19:32,195 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:19:32,220 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-05-18 08:19:32,222 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:19:32,222 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:19:32,240 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:19:32,240 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:19:32,265 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-05-18 08:19:32,267 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:19:32,267 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
calling start
2016-05-18 08:19:32,276 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] starting
2016-05-18 08:19:32,277 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth]  parallel execution of flows is enabled: true
2016-05-18 08:19:32,277 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth]  executing total flows: 4
2016-05-18 08:19:32,277 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth]  allocating management threads: 4
2016-05-18 08:19:32,278 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] starting flow: first
2016-05-18 08:19:32,278 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] at least one sink is marked for delete
2016-05-18 08:19:32,278 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
testing if running
2016-05-18 08:19:32,281 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting
2016-05-18 08:19:32,282 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/ips.20.txt"]
2016-05-18 08:19:32,282 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascadeStop/stopped/first-nondeterministic"]
2016-05-18 08:19:32,282 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  parallel execution of steps is enabled: true
2016-05-18 08:19:32,282 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  executing total steps: 1
2016-05-18 08:19:32,282 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  allocating management threads: 1
2016-05-18 08:19:32,283 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting step: (1/1) ...ed/first-nondeterministic
2016-05-18 08:19:32,404 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] submitted hadoop job: job_1463559294241_0010
2016-05-18 08:19:32,404 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] tracking url: http://ip-10-158-37-203:39645/proxy/application_1463559294241_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
testing if running
testing if running
testing if running
testing if running
testing if running
testing if running
2016-05-18 08:19:54,190 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0010_01_000003 is : 143
calling stop
2016-05-18 08:19:54,307 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] stopping all flows
2016-05-18 08:19:54,307 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] stopping flow: fourth
2016-05-18 08:19:54,308 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] stopping all jobs
2016-05-18 08:19:54,308 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] stopping: (1/1) ...d/fourth-nondeterministic
2016-05-18 08:19:54,308 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] stopped all jobs
2016-05-18 08:19:54,309 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] stopping flow: third
2016-05-18 08:19:54,309 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] stopping all jobs
2016-05-18 08:19:54,309 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] stopping: (1/1) ...ed/third-nondeterministic
2016-05-18 08:19:54,309 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] stopped all jobs
2016-05-18 08:19:54,310 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] stopping flow: second
2016-05-18 08:19:54,310 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] stopping all jobs
2016-05-18 08:19:54,310 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] stopping: (1/1) ...d/second-nondeterministic
2016-05-18 08:19:54,310 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] stopped all jobs
2016-05-18 08:19:54,311 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] stopping flow: first
2016-05-18 08:19:54,311 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] stopping all jobs
2016-05-18 08:19:54,313 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] stopping: (1/1) ...ed/first-nondeterministic
2016-05-18 08:19:54,369 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] did not capture all completed node details, will retry in 00:00.010, prior retries: 0
2016-05-18 08:19:54,483 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0010_01_000002 is : 143
2016-05-18 08:19:54,530 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0010_01_000004 is : 143
2016-05-18 08:19:54,591 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0010_01_000005 is : 143
2016-05-18 08:19:56,415 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] stopped all jobs
2016-05-18 08:19:56,416 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] stopped all flows
2016-05-18 08:19:56,417 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] shutting down flow executor
2016-05-18 08:19:56,417 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  completed in: 00:22.030, using cpu time: 00:01.160
2016-05-18 08:19:56,417 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] completed flow: first
2016-05-18 08:19:56,418 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first+second+third+fourth] shutdown complete
2016-05-18 08:19:56,419 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeStop/stopped/third-nondeterministic
2016-05-18 08:19:56,421 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeStop/stopped/second-nondeterministic
2016-05-18 08:19:56,421 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeStop/stopped/fourth-nondeterministic
2016-05-18 08:19:56,422 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascadeStop/stopped/first-nondeterministic
2016-05-18 08:19:56,439 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:19:56,439 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:19:56,472 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.029
2016-05-18 08:19:56,473 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:19:56,473 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:19:56,492 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:19:56,492 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:19:56,517 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-05-18 08:19:56,518 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:19:56,518 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:19:56,537 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:19:56,537 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:19:56,577 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.037
2016-05-18 08:19:56,578 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:19:56,578 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:19:56,598 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:19:56,598 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:19:56,623 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-05-18 08:19:56,624 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:19:56,624 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:19:56,633 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] starting
2016-05-18 08:19:56,634 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first]  parallel execution of flows is enabled: true
2016-05-18 08:19:56,634 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first]  executing total flows: 4
2016-05-18 08:19:56,634 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first]  allocating management threads: 4
2016-05-18 08:19:56,634 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] starting flow: first
2016-05-18 08:19:56,634 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] at least one sink is marked for delete
2016-05-18 08:19:56,635 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 08:19:56,637 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting
2016-05-18 08:19:56,638 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/ips.20.txt"]
2016-05-18 08:19:56,638 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/first"]
2016-05-18 08:19:56,638 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  parallel execution of steps is enabled: true
2016-05-18 08:19:56,639 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  executing total steps: 1
2016-05-18 08:19:56,639 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  allocating management threads: 1
2016-05-18 08:19:56,640 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] starting step: (1/1) ...impleCascade/simple/first
2016-05-18 08:19:56,757 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] submitted hadoop job: job_1463559294241_0011
2016-05-18 08:19:56,758 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] tracking url: http://ip-10-158-37-203:39645/proxy/application_1463559294241_0011/
2016-05-18 08:20:17,285 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0011_01_000003 is : 143
2016-05-18 08:20:17,549 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0011_01_000002 is : 143
2016-05-18 08:20:17,979 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0011_01_000005 is : 143
2016-05-18 08:20:18,097 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0011_01_000004 is : 143
2016-05-18 08:20:19,269 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/first/_temporary
2016-05-18 08:20:19,270 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first]  completed in: 00:22.630, using cpu time: 00:04.480
2016-05-18 08:20:19,270 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] completed flow: first
2016-05-18 08:20:19,271 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] starting flow: second
2016-05-18 08:20:19,271 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] at least one sink is marked for delete
2016-05-18 08:20:19,271 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 08:20:19,273 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting
2016-05-18 08:20:19,274 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/first"]
2016-05-18 08:20:19,274 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  sink: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/second"]
2016-05-18 08:20:19,274 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  parallel execution of steps is enabled: true
2016-05-18 08:20:19,274 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  executing total steps: 1
2016-05-18 08:20:19,274 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  allocating management threads: 1
2016-05-18 08:20:19,276 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] starting step: (1/1) ...mpleCascade/simple/second
2016-05-18 08:20:19,384 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] submitted hadoop job: job_1463559294241_0012
2016-05-18 08:20:19,385 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] tracking url: http://ip-10-158-37-203:39645/proxy/application_1463559294241_0012/
2016-05-18 08:20:43,607 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0012_01_000006 is : 143
2016-05-18 08:20:43,787 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0012_01_000004 is : 143
2016-05-18 08:20:44,038 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0012_01_000003 is : 143
2016-05-18 08:20:45,217 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/second/_temporary
2016-05-18 08:20:45,218 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second]  completed in: 00:25.942, using cpu time: 00:05.480
2016-05-18 08:20:45,219 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] completed flow: second
2016-05-18 08:20:45,219 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] starting flow: third
2016-05-18 08:20:45,219 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] at least one sink is marked for delete
2016-05-18 08:20:45,219 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 08:20:45,222 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] starting
2016-05-18 08:20:45,222 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  source: Hfs["TextDelimited[['first', 'second', 'third', 'fourth']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/second"]
2016-05-18 08:20:45,222 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/third"]
2016-05-18 08:20:45,222 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  parallel execution of steps is enabled: true
2016-05-18 08:20:45,222 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  executing total steps: 1
2016-05-18 08:20:45,222 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  allocating management threads: 1
2016-05-18 08:20:45,224 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] starting step: (1/1) ...impleCascade/simple/third
2016-05-18 08:20:45,332 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] submitted hadoop job: job_1463559294241_0013
2016-05-18 08:20:45,332 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] tracking url: http://ip-10-158-37-203:39645/proxy/application_1463559294241_0013/
2016-05-18 08:21:11,969 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0013_01_000007 is : 143
2016-05-18 08:21:12,282 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0013_01_000004 is : 143
2016-05-18 08:21:12,339 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0013_01_000006 is : 143
2016-05-18 08:21:12,531 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0013_01_000002 is : 143
2016-05-18 08:21:12,699 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0013_01_000003 is : 143
2016-05-18 08:21:12,829 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0013_01_000005 is : 143
2016-05-18 08:21:14,035 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/third/_temporary
2016-05-18 08:21:14,036 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third]  completed in: 00:28.811, using cpu time: 00:06.630
2016-05-18 08:21:14,037 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] completed flow: third
2016-05-18 08:21:14,037 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] starting flow: fourth
2016-05-18 08:21:14,037 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] at least one sink is marked for delete
2016-05-18 08:21:14,037 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 08:21:14,042 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] starting
2016-05-18 08:21:14,042 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/third"]
2016-05-18 08:21:14,042 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/fourth"]
2016-05-18 08:21:14,042 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  parallel execution of steps is enabled: true
2016-05-18 08:21:14,043 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  executing total steps: 1
2016-05-18 08:21:14,043 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  allocating management threads: 1
2016-05-18 08:21:14,043 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] starting step: (1/1) ...mpleCascade/simple/fourth
2016-05-18 08:21:14,100 WARN  blockmanagement.BlockPlacementPolicy (BlockPlacementPolicyDefault.java:chooseTarget(381)) - Failed to place enough replicas, still in need of 1 to reach 4 (unavailableStorages=[], storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]}, newBlock=true) For more information, please enable DEBUG log level on org.apache.hadoop.hdfs.server.blockmanagement.BlockPlacementPolicy
2016-05-18 08:21:14,101 WARN  protocol.BlockStoragePolicy (BlockStoragePolicy.java:chooseStorageTypes(160)) - Failed to place enough replicas: expected size is 1 but only 0 storage types can be selected (replication=4, selected=[], unavailable=[DISK], removed=[DISK], policy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]})
2016-05-18 08:21:14,101 WARN  blockmanagement.BlockPlacementPolicy (BlockPlacementPolicyDefault.java:chooseTarget(381)) - Failed to place enough replicas, still in need of 1 to reach 4 (unavailableStorages=[DISK], storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]}, newBlock=true) All required storage types are unavailable:  unavailableStorages=[DISK], storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]}
2016-05-18 08:21:14,155 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] submitted hadoop job: job_1463559294241_0014
2016-05-18 08:21:14,155 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] tracking url: http://ip-10-158-37-203:39645/proxy/application_1463559294241_0014/
2016-05-18 08:21:14,853 WARN  blockmanagement.BlockPlacementPolicy (BlockPlacementPolicyDefault.java:chooseTarget(381)) - Failed to place enough replicas, still in need of 1 to reach 4 (unavailableStorages=[], storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]}, newBlock=false) For more information, please enable DEBUG log level on org.apache.hadoop.hdfs.server.blockmanagement.BlockPlacementPolicy
2016-05-18 08:21:14,853 WARN  blockmanagement.BlockPlacementPolicy (BlockPlacementPolicyDefault.java:chooseTarget(381)) - Failed to place enough replicas, still in need of 1 to reach 4 (unavailableStorages=[DISK], storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]}, newBlock=false) For more information, please enable DEBUG log level on org.apache.hadoop.hdfs.server.blockmanagement.BlockPlacementPolicy
2016-05-18 08:21:14,853 WARN  protocol.BlockStoragePolicy (BlockStoragePolicy.java:chooseStorageTypes(160)) - Failed to place enough replicas: expected size is 1 but only 0 storage types can be selected (replication=4, selected=[], unavailable=[DISK, ARCHIVE], removed=[DISK], policy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]})
2016-05-18 08:21:14,854 WARN  blockmanagement.BlockPlacementPolicy (BlockPlacementPolicyDefault.java:chooseTarget(381)) - Failed to place enough replicas, still in need of 1 to reach 4 (unavailableStorages=[DISK, ARCHIVE], storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]}, newBlock=false) All required storage types are unavailable:  unavailableStorages=[DISK, ARCHIVE], storagePolicy=BlockStoragePolicy{HOT:7, storageTypes=[DISK], creationFallbacks=[], replicationFallbacks=[ARCHIVE]}
2016-05-18 08:21:41,807 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0014_01_000006 is : 143
2016-05-18 08:21:43,034 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0014_01_000007 is : 143
2016-05-18 08:21:43,352 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0014_01_000004 is : 143
2016-05-18 08:21:43,740 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0014_01_000003 is : 143
2016-05-18 08:21:43,773 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0014_01_000008 is : 143
2016-05-18 08:21:43,800 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0014_01_000005 is : 143
2016-05-18 08:21:43,973 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(224)) - Exit code from container container_1463559294241_0014_01_000002 is : 143
2016-05-18 08:21:45,168 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/fourth/_temporary
2016-05-18 08:21:45,170 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth]  completed in: 00:31.125, using cpu time: 00:07.500
2016-05-18 08:21:45,170 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [fourth+second+third+first] completed flow: fourth
2016-05-18 08:21:45,197 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/fourth
2016-05-18 08:21:45,211 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/third
2016-05-18 08:21:45,225 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/second
2016-05-18 08:21:45,238 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testSimpleCascade/simple/first
2016-05-18 08:21:45,265 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:21:45,266 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:21:45,299 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.029
2016-05-18 08:21:45,300 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:21:45,300 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:21:45,336 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:21:45,336 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:21:45,359 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.019
2016-05-18 08:21:45,360 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:21:45,360 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:21:45,380 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:21:45,381 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:21:45,403 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.019
2016-05-18 08:21:45,404 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:21:45,404 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [third] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:21:45,423 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:21:45,424 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:21:45,446 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.019
2016-05-18 08:21:45,447 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:21:45,447 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [fourth] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:21:45,456 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testCascadeID/idtest/first
2016-05-18 08:21:45,457 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testCascadeID/idtest/fourth
2016-05-18 08:21:45,458 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testCascadeID/idtest/third
2016-05-18 08:21:45,459 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/cascadeplatform/testCascadeID/idtest/second
2016-05-18 08:21:45,474 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:21:45,474 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:21:45,494 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.016
2016-05-18 08:21:45,495 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 08:21:45,495 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:21:45,527 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:21:45,527 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:21:45,557 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.027
2016-05-18 08:21:45,558 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 2
2016-05-18 08:21:45,558 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'

Standard error

Exception in thread "org.apache.hadoop.util.JvmPauseMonitor$Monitor@4c4b9e08" java.lang.NoSuchMethodError: com.google.common.base.Stopwatch.elapsedMillis()J
	at org.apache.hadoop.util.JvmPauseMonitor$Monitor.run(JvmPauseMonitor.java:186)
	at java.lang.Thread.run(Thread.java:745)
Exception in thread "org.apache.hadoop.util.JvmPauseMonitor$Monitor@64503824" java.lang.NoSuchMethodError: com.google.common.base.Stopwatch.elapsedMillis()J
	at org.apache.hadoop.util.JvmPauseMonitor$Monitor.run(JvmPauseMonitor.java:186)
	at java.lang.Thread.run(Thread.java:745)
Exception in thread "org.apache.hadoop.util.JvmPauseMonitor$Monitor@6159dea6" java.lang.NoSuchMethodError: com.google.common.base.Stopwatch.elapsedMillis()J
	at org.apache.hadoop.util.JvmPauseMonitor$Monitor.run(JvmPauseMonitor.java:186)
	at java.lang.Thread.run(Thread.java:745)
Exception in thread "org.apache.hadoop.util.JvmPauseMonitor$Monitor@49c6b334" java.lang.NoSuchMethodError: com.google.common.base.Stopwatch.elapsedMillis()J
	at org.apache.hadoop.util.JvmPauseMonitor$Monitor.run(JvmPauseMonitor.java:186)
	at java.lang.Thread.run(Thread.java:745)
Exception in thread "org.apache.hadoop.util.JvmPauseMonitor$Monitor@7404b78b" java.lang.NoSuchMethodError: com.google.common.base.Stopwatch.elapsedMillis()J
	at org.apache.hadoop.util.JvmPauseMonitor$Monitor.run(JvmPauseMonitor.java:186)
	at java.lang.Thread.run(Thread.java:745)
May 18, 2016 8:14:54 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.mapreduce.v2.hs.webapp.HsWebServices as a root resource class
May 18, 2016 8:14:54 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.mapreduce.v2.hs.webapp.JAXBContextResolver as a provider class
May 18, 2016 8:14:54 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.webapp.GenericExceptionHandler as a provider class
May 18, 2016 8:14:54 AM com.sun.jersey.server.impl.application.WebApplicationImpl _initiate
INFO: Initiating Jersey application, version 'Jersey: 1.9 09/02/2011 11:17 AM'
May 18, 2016 8:14:54 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
INFO: Binding org.apache.hadoop.mapreduce.v2.hs.webapp.JAXBContextResolver to GuiceManagedComponentProvider with the scope "Singleton"
May 18, 2016 8:14:54 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
INFO: Binding org.apache.hadoop.yarn.webapp.GenericExceptionHandler to GuiceManagedComponentProvider with the scope "Singleton"
May 18, 2016 8:14:55 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
INFO: Binding org.apache.hadoop.mapreduce.v2.hs.webapp.HsWebServices to GuiceManagedComponentProvider with the scope "PerRequest"
May 18, 2016 8:14:55 AM com.google.inject.servlet.GuiceFilter setPipeline
WARNING: Multiple Servlet injectors detected. This is a warning indicating that you have more than one GuiceFilter running in your web application. If this is deliberate, you may safely ignore this message. If this is NOT deliberate however, your application may not work as expected.
May 18, 2016 8:14:55 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.server.resourcemanager.webapp.JAXBContextResolver as a provider class
May 18, 2016 8:14:55 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.server.resourcemanager.webapp.RMWebServices as a root resource class
May 18, 2016 8:14:55 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.webapp.GenericExceptionHandler as a provider class
May 18, 2016 8:14:55 AM com.sun.jersey.server.impl.application.WebApplicationImpl _initiate
INFO: Initiating Jersey application, version 'Jersey: 1.9 09/02/2011 11:17 AM'
May 18, 2016 8:14:55 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
INFO: Binding org.apache.hadoop.yarn.server.resourcemanager.webapp.JAXBContextResolver to GuiceManagedComponentProvider with the scope "Singleton"
May 18, 2016 8:14:56 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
INFO: Binding org.apache.hadoop.yarn.webapp.GenericExceptionHandler to GuiceManagedComponentProvider with the scope "Singleton"
May 18, 2016 8:14:56 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
INFO: Binding org.apache.hadoop.yarn.server.resourcemanager.webapp.RMWebServices to GuiceManagedComponentProvider with the scope "Singleton"
May 18, 2016 8:14:56 AM com.google.inject.servlet.GuiceFilter setPipeline
WARNING: Multiple Servlet injectors detected. This is a warning indicating that you have more than one GuiceFilter running in your web application. If this is deliberate, you may safely ignore this message. If this is NOT deliberate however, your application may not work as expected.
May 18, 2016 8:14:56 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.server.nodemanager.webapp.NMWebServices as a root resource class
May 18, 2016 8:14:56 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.webapp.GenericExceptionHandler as a provider class
May 18, 2016 8:14:56 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.server.nodemanager.webapp.JAXBContextResolver as a provider class
May 18, 2016 8:14:56 AM com.sun.jersey.server.impl.application.WebApplicationImpl _initiate
INFO: Initiating Jersey application, version 'Jersey: 1.9 09/02/2011 11:17 AM'
May 18, 2016 8:14:56 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
INFO: Binding org.apache.hadoop.yarn.server.nodemanager.webapp.JAXBContextResolver to GuiceManagedComponentProvider with the scope "Singleton"
May 18, 2016 8:14:56 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
INFO: Binding org.apache.hadoop.yarn.webapp.GenericExceptionHandler to GuiceManagedComponentProvider with the scope "Singleton"
May 18, 2016 8:14:57 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
INFO: Binding org.apache.hadoop.yarn.server.nodemanager.webapp.NMWebServices to GuiceManagedComponentProvider with the scope "Singleton"
May 18, 2016 8:14:57 AM com.google.inject.servlet.GuiceFilter setPipeline
WARNING: Multiple Servlet injectors detected. This is a warning indicating that you have more than one GuiceFilter running in your web application. If this is deliberate, you may safely ignore this message. If this is NOT deliberate however, your application may not work as expected.
May 18, 2016 8:14:57 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.server.nodemanager.webapp.NMWebServices as a root resource class
May 18, 2016 8:14:57 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.webapp.GenericExceptionHandler as a provider class
May 18, 2016 8:14:57 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.server.nodemanager.webapp.JAXBContextResolver as a provider class
May 18, 2016 8:14:57 AM com.sun.jersey.server.impl.application.WebApplicationImpl _initiate
INFO: Initiating Jersey application, version 'Jersey: 1.9 09/02/2011 11:17 AM'
May 18, 2016 8:14:57 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
INFO: Binding org.apache.hadoop.yarn.server.nodemanager.webapp.JAXBContextResolver to GuiceManagedComponentProvider with the scope "Singleton"
May 18, 2016 8:14:57 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
INFO: Binding org.apache.hadoop.yarn.webapp.GenericExceptionHandler to GuiceManagedComponentProvider with the scope "Singleton"
May 18, 2016 8:14:58 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
INFO: Binding org.apache.hadoop.yarn.server.nodemanager.webapp.NMWebServices to GuiceManagedComponentProvider with the scope "Singleton"
May 18, 2016 8:14:58 AM com.google.inject.servlet.GuiceFilter setPipeline
WARNING: Multiple Servlet injectors detected. This is a warning indicating that you have more than one GuiceFilter running in your web application. If this is deliberate, you may safely ignore this message. If this is NOT deliberate however, your application may not work as expected.
May 18, 2016 8:14:58 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.server.nodemanager.webapp.NMWebServices as a root resource class
May 18, 2016 8:14:58 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.webapp.GenericExceptionHandler as a provider class
May 18, 2016 8:14:58 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.server.nodemanager.webapp.JAXBContextResolver as a provider class
May 18, 2016 8:14:58 AM com.sun.jersey.server.impl.application.WebApplicationImpl _initiate
INFO: Initiating Jersey application, version 'Jersey: 1.9 09/02/2011 11:17 AM'
May 18, 2016 8:14:58 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
INFO: Binding org.apache.hadoop.yarn.server.nodemanager.webapp.JAXBContextResolver to GuiceManagedComponentProvider with the scope "Singleton"
May 18, 2016 8:14:58 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
INFO: Binding org.apache.hadoop.yarn.webapp.GenericExceptionHandler to GuiceManagedComponentProvider with the scope "Singleton"
May 18, 2016 8:14:59 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory getComponentProvider
INFO: Binding org.apache.hadoop.yarn.server.nodemanager.webapp.NMWebServices to GuiceManagedComponentProvider with the scope "Singleton"
May 18, 2016 8:14:59 AM com.google.inject.servlet.GuiceFilter setPipeline
WARNING: Multiple Servlet injectors detected. This is a warning indicating that you have more than one GuiceFilter running in your web application. If this is deliberate, you may safely ignore this message. If this is NOT deliberate however, your application may not work as expected.