Class cascading.cascade.ParallelCascadePlatformTest

2016-05-18 03:00:58,182 INFO  platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 03:00:58,203 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.cascade.ParallelCascadePlatformTest, with platform: hadoop2-mr1
2016-05-18 03:00:58,228 INFO  hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(136)) - using cluster
2016-05-18 03:00:58,970 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 03:00:59,601 WARN  impl.MetricsConfig (MetricsConfig.java:loadFirst(124)) - Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
2016-05-18 03:01:00,114 WARN  server.AuthenticationFilter (AuthenticationFilter.java:init(162)) - 'signature.secret' configuration not set, using a random value as secret
2016-05-18 03:01:03,270 WARN  containermanager.AuxServices (AuxServices.java:serviceInit(114)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for class class org.apache.hadoop.mapred.ShuffleHandler which has a name of 'httpshuffle'. Because these are not the same tools trying to send ServiceData and read Service Meta Data may have issues unless the refer to the name in the config.
2016-05-18 03:01:03,413 WARN  containermanager.AuxServices (AuxServices.java:serviceInit(114)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for class class org.apache.hadoop.mapred.ShuffleHandler which has a name of 'httpshuffle'. Because these are not the same tools trying to send ServiceData and read Service Meta Data may have issues unless the refer to the name in the config.
2016-05-18 03:01:03,523 WARN  containermanager.AuxServices (AuxServices.java:serviceInit(114)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for class class org.apache.hadoop.mapred.ShuffleHandler which has a name of 'httpshuffle'. Because these are not the same tools trying to send ServiceData and read Service Meta Data may have issues unless the refer to the name in the config.
2016-05-18 03:01:03,638 WARN  containermanager.AuxServices (AuxServices.java:serviceInit(114)) - The Auxilurary Service named 'mapreduce_shuffle' in the configuration is for class class org.apache.hadoop.mapred.ShuffleHandler which has a name of 'httpshuffle'. Because these are not the same tools trying to send ServiceData and read Service Meta Data may have issues unless the refer to the name in the config.
2016-05-18 03:01:20,709 INFO  platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides: 
2016-05-18 03:01:20,813 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:20,814 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 03:01:20,884 INFO  property.AppProps (AppProps.java:getAppID(177)) - using app.id: 222EB0006A294CB3BD01E486376442E1
2016-05-18 03:01:20,993 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-0/first-nondeterm...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.071
2016-05-18 03:01:20,995 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-0/first-nondeterm...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 03:01:20,997 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-0/first-nondeterm...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:21,108 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] stopping all flows
2016-05-18 03:01:21,109 INFO  util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 03:01:21,109 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] stopped all flows
2016-05-18 03:01:21,110 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-0/first-nondeterm...] starting
2016-05-18 03:01:21,131 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:21,132 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 03:01:21,186 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.047
2016-05-18 03:01:21,187 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 03:01:21,187 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:21,203 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] starting
2016-05-18 03:01:21,205 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...]  parallel execution of flows is enabled: false
2016-05-18 03:01:21,206 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...]  executing total flows: 1
2016-05-18 03:01:21,206 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...]  allocating management threads: 1
2016-05-18 03:01:21,206 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] starting flow: race-50/first-nondeterministic
2016-05-18 03:01:21,207 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] at least one sink is marked for delete
2016-05-18 03:01:21,207 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 03:01:21,229 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] starting
2016-05-18 03:01:21,230 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 03:01:21,230 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-50/first-nondeterministic"]
2016-05-18 03:01:21,231 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...]  parallel execution of steps is enabled: true
2016-05-18 03:01:21,231 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...]  executing total steps: 1
2016-05-18 03:01:21,232 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...]  allocating management threads: 1
2016-05-18 03:01:21,233 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] starting step: (1/1) ...50/first-nondeterministic
2016-05-18 03:01:21,253 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopping all flows
2016-05-18 03:01:21,254 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopping flow: race-50/first-nondeterministic
2016-05-18 03:01:21,254 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] stopping all jobs
2016-05-18 03:01:21,255 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] stopping: (1/1) ...50/first-nondeterministic
2016-05-18 03:01:21,255 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] stopped all jobs
2016-05-18 03:01:22,147 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] submitted hadoop job: job_1463540475208_0001
2016-05-18 03:01:22,148 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...] tracking url: http://ip-10-158-37-203:43768/proxy/application_1463540475208_0001/
2016-05-18 03:01:22,200 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] stopped all flows
2016-05-18 03:01:22,200 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] shutting down flow executor
2016-05-18 03:01:22,236 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-50/first-nondeter...]  completed in: 00:00.025
2016-05-18 03:01:22,237 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] completed flow: race-50/first-nondeterministic
2016-05-18 03:01:22,237 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-50/first-nondeter...] shutdown complete
2016-05-18 03:01:22,276 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:22,276 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 03:01:22,355 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.060
2016-05-18 03:01:22,356 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 03:01:22,356 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:22,381 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] starting
2016-05-18 03:01:22,382 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 03:01:22,382 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...]  executing total flows: 1
2016-05-18 03:01:22,382 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:22,385 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] starting flow: race-100/first-nondeterministic
2016-05-18 03:01:22,385 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] at least one sink is marked for delete
2016-05-18 03:01:22,385 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 03:01:22,417 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] starting
2016-05-18 03:01:22,418 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 03:01:22,418 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-100/first-nondeterministic"]
2016-05-18 03:01:22,418 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 03:01:22,418 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...]  executing total steps: 1
2016-05-18 03:01:22,418 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:22,422 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-05-18 03:01:22,481 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopping all flows
2016-05-18 03:01:22,483 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopping flow: race-100/first-nondeterministic
2016-05-18 03:01:22,483 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] stopping all jobs
2016-05-18 03:01:22,484 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-05-18 03:01:22,485 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] stopped all jobs
2016-05-18 03:01:22,720 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] submitted hadoop job: job_1463540475208_0002
2016-05-18 03:01:22,720 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...] tracking url: http://ip-10-158-37-203:43768/proxy/application_1463540475208_0002/
2016-05-18 03:01:22,723 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] stopped all flows
2016-05-18 03:01:22,723 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-100/first-nondete...]  completed in: 00:00.066
2016-05-18 03:01:22,723 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] shutting down flow executor
2016-05-18 03:01:22,724 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] completed flow: race-100/first-nondeterministic
2016-05-18 03:01:22,725 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-100/first-nondete...] shutdown complete
2016-05-18 03:01:22,743 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:22,743 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 03:01:22,810 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.058
2016-05-18 03:01:22,811 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 03:01:22,812 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:22,834 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] starting
2016-05-18 03:01:22,835 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 03:01:22,835 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...]  executing total flows: 1
2016-05-18 03:01:22,835 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:22,835 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] starting flow: race-150/first-nondeterministic
2016-05-18 03:01:22,836 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] at least one sink is marked for delete
2016-05-18 03:01:22,836 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 03:01:22,841 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] starting
2016-05-18 03:01:22,842 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 03:01:22,842 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-150/first-nondeterministic"]
2016-05-18 03:01:22,842 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 03:01:22,843 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...]  executing total steps: 1
2016-05-18 03:01:22,843 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:22,846 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-05-18 03:01:22,984 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopping all flows
2016-05-18 03:01:22,984 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopping flow: race-150/first-nondeterministic
2016-05-18 03:01:22,985 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] stopping all jobs
2016-05-18 03:01:22,985 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-05-18 03:01:22,986 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] stopped all jobs
2016-05-18 03:01:23,142 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] submitted hadoop job: job_1463540475208_0003
2016-05-18 03:01:23,142 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...] tracking url: http://ip-10-158-37-203:43768/proxy/application_1463540475208_0003/
2016-05-18 03:01:23,149 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] stopped all flows
2016-05-18 03:01:23,149 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-150/first-nondete...]  completed in: 00:00.143
2016-05-18 03:01:23,149 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] completed flow: race-150/first-nondeterministic
2016-05-18 03:01:23,149 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] shutting down flow executor
2016-05-18 03:01:23,150 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-150/first-nondete...] shutdown complete
2016-05-18 03:01:23,170 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:23,170 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 03:01:23,218 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.042
2016-05-18 03:01:23,220 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 03:01:23,220 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:23,237 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] starting
2016-05-18 03:01:23,238 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 03:01:23,238 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...]  executing total flows: 1
2016-05-18 03:01:23,238 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:23,239 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] starting flow: race-200/first-nondeterministic
2016-05-18 03:01:23,239 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] at least one sink is marked for delete
2016-05-18 03:01:23,239 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 03:01:23,246 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] starting
2016-05-18 03:01:23,246 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 03:01:23,247 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-200/first-nondeterministic"]
2016-05-18 03:01:23,247 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 03:01:23,247 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...]  executing total steps: 1
2016-05-18 03:01:23,247 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:23,248 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-05-18 03:01:23,436 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopping all flows
2016-05-18 03:01:23,437 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopping flow: race-200/first-nondeterministic
2016-05-18 03:01:23,437 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] stopping all jobs
2016-05-18 03:01:23,438 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-05-18 03:01:23,438 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] stopped all jobs
2016-05-18 03:01:23,497 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] submitted hadoop job: job_1463540475208_0004
2016-05-18 03:01:23,498 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...] tracking url: http://ip-10-158-37-203:43768/proxy/application_1463540475208_0004/
2016-05-18 03:01:23,505 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] stopped all flows
2016-05-18 03:01:23,505 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] shutting down flow executor
2016-05-18 03:01:23,505 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-200/first-nondete...]  completed in: 00:00.191
2016-05-18 03:01:23,506 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] completed flow: race-200/first-nondeterministic
2016-05-18 03:01:23,506 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-200/first-nondete...] shutdown complete
2016-05-18 03:01:23,520 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:23,520 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 03:01:23,554 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.030
2016-05-18 03:01:23,556 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 03:01:23,556 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:23,571 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] starting
2016-05-18 03:01:23,572 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 03:01:23,572 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...]  executing total flows: 1
2016-05-18 03:01:23,572 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:23,573 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] starting flow: race-250/first-nondeterministic
2016-05-18 03:01:23,573 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] at least one sink is marked for delete
2016-05-18 03:01:23,574 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 03:01:23,579 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] starting
2016-05-18 03:01:23,580 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 03:01:23,580 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-250/first-nondeterministic"]
2016-05-18 03:01:23,580 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 03:01:23,580 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...]  executing total steps: 1
2016-05-18 03:01:23,581 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:23,581 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-05-18 03:01:23,821 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopping all flows
2016-05-18 03:01:23,823 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopping flow: race-250/first-nondeterministic
2016-05-18 03:01:23,824 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] stopping all jobs
2016-05-18 03:01:23,826 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-05-18 03:01:23,826 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] stopped all jobs
2016-05-18 03:01:23,882 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] submitted hadoop job: job_1463540475208_0005
2016-05-18 03:01:23,882 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...] tracking url: http://ip-10-158-37-203:43768/proxy/application_1463540475208_0005/
2016-05-18 03:01:23,886 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] stopped all flows
2016-05-18 03:01:23,887 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-250/first-nondete...]  completed in: 00:00.245
2016-05-18 03:01:23,887 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] completed flow: race-250/first-nondeterministic
2016-05-18 03:01:23,887 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] shutting down flow executor
2016-05-18 03:01:23,888 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-250/first-nondete...] shutdown complete
2016-05-18 03:01:23,910 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:23,911 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 03:01:23,943 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.028
2016-05-18 03:01:23,944 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 03:01:23,945 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:23,973 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] starting
2016-05-18 03:01:23,974 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 03:01:23,974 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...]  executing total flows: 1
2016-05-18 03:01:23,974 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:23,975 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] starting flow: race-300/first-nondeterministic
2016-05-18 03:01:23,975 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] at least one sink is marked for delete
2016-05-18 03:01:23,976 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 03:01:23,987 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] starting
2016-05-18 03:01:23,987 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 03:01:23,989 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-300/first-nondeterministic"]
2016-05-18 03:01:23,989 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 03:01:23,990 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...]  executing total steps: 1
2016-05-18 03:01:23,990 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:23,991 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-05-18 03:01:24,255 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] submitted hadoop job: job_1463540475208_0006
2016-05-18 03:01:24,255 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] tracking url: http://ip-10-158-37-203:43768/proxy/application_1463540475208_0006/
2016-05-18 03:01:24,273 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopping all flows
2016-05-18 03:01:24,274 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopping flow: race-300/first-nondeterministic
2016-05-18 03:01:24,274 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] stopping all jobs
2016-05-18 03:01:24,275 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-05-18 03:01:24,489 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...] stopped all jobs
2016-05-18 03:01:24,494 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] stopped all flows
2016-05-18 03:01:24,494 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-300/first-nondete...]  completed in: 00:00.287
2016-05-18 03:01:24,494 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] shutting down flow executor
2016-05-18 03:01:24,495 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] completed flow: race-300/first-nondeterministic
2016-05-18 03:01:24,495 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-300/first-nondete...] shutdown complete
2016-05-18 03:01:24,515 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:24,515 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 03:01:24,559 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.039
2016-05-18 03:01:24,563 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 03:01:24,564 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:24,584 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] starting
2016-05-18 03:01:24,585 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 03:01:24,585 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...]  executing total flows: 1
2016-05-18 03:01:24,586 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:24,586 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] starting flow: race-350/first-nondeterministic
2016-05-18 03:01:24,587 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] at least one sink is marked for delete
2016-05-18 03:01:24,587 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 03:01:24,592 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] starting
2016-05-18 03:01:24,592 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 03:01:24,593 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-350/first-nondeterministic"]
2016-05-18 03:01:24,593 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 03:01:24,593 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...]  executing total steps: 1
2016-05-18 03:01:24,594 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:24,595 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-05-18 03:01:24,916 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] submitted hadoop job: job_1463540475208_0007
2016-05-18 03:01:24,916 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] tracking url: http://ip-10-158-37-203:43768/proxy/application_1463540475208_0007/
2016-05-18 03:01:24,934 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopping all flows
2016-05-18 03:01:24,934 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopping flow: race-350/first-nondeterministic
2016-05-18 03:01:24,935 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] stopping all jobs
2016-05-18 03:01:24,935 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-05-18 03:01:25,142 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...] stopped all jobs
2016-05-18 03:01:25,147 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] stopped all flows
2016-05-18 03:01:25,148 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] shutting down flow executor
2016-05-18 03:01:25,149 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-350/first-nondete...]  completed in: 00:00.343
2016-05-18 03:01:25,149 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] completed flow: race-350/first-nondeterministic
2016-05-18 03:01:25,150 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-350/first-nondete...] shutdown complete
2016-05-18 03:01:25,183 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:25,184 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 03:01:25,236 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.037
2016-05-18 03:01:25,237 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 03:01:25,237 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:25,277 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] starting
2016-05-18 03:01:25,279 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 03:01:25,279 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...]  executing total flows: 1
2016-05-18 03:01:25,279 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:25,280 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] starting flow: race-400/first-nondeterministic
2016-05-18 03:01:25,281 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] at least one sink is marked for delete
2016-05-18 03:01:25,281 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 03:01:25,287 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] starting
2016-05-18 03:01:25,287 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 03:01:25,288 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-400/first-nondeterministic"]
2016-05-18 03:01:25,288 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 03:01:25,288 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...]  executing total steps: 1
2016-05-18 03:01:25,288 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:25,289 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-05-18 03:01:25,677 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopping all flows
2016-05-18 03:01:25,678 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopping flow: race-400/first-nondeterministic
2016-05-18 03:01:25,678 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] stopping all jobs
2016-05-18 03:01:25,688 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-05-18 03:01:25,688 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] stopped all jobs
2016-05-18 03:01:26,070 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] submitted hadoop job: job_1463540475208_0008
2016-05-18 03:01:26,070 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...] tracking url: http://ip-10-158-37-203:43768/proxy/application_1463540475208_0008/
2016-05-18 03:01:26,074 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] stopped all flows
2016-05-18 03:01:26,075 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] shutting down flow executor
2016-05-18 03:01:26,074 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-400/first-nondete...]  completed in: 00:00.391
2016-05-18 03:01:26,075 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] completed flow: race-400/first-nondeterministic
2016-05-18 03:01:26,079 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-400/first-nondete...] shutdown complete
2016-05-18 03:01:26,099 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:26,099 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 03:01:26,165 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.062
2016-05-18 03:01:26,168 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 03:01:26,168 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:26,188 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] starting
2016-05-18 03:01:26,189 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 03:01:26,190 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...]  executing total flows: 1
2016-05-18 03:01:26,190 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:26,191 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] starting flow: race-450/first-nondeterministic
2016-05-18 03:01:26,192 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] at least one sink is marked for delete
2016-05-18 03:01:26,192 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 03:01:26,198 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] starting
2016-05-18 03:01:26,198 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 03:01:26,199 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-450/first-nondeterministic"]
2016-05-18 03:01:26,199 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 03:01:26,199 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...]  executing total steps: 1
2016-05-18 03:01:26,199 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:26,200 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] starting step: (1/1) ...50/first-nondeterministic
2016-05-18 03:01:26,502 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] submitted hadoop job: job_1463540475208_0009
2016-05-18 03:01:26,503 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] tracking url: http://ip-10-158-37-203:43768/proxy/application_1463540475208_0009/
2016-05-18 03:01:26,638 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopping all flows
2016-05-18 03:01:26,639 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopping flow: race-450/first-nondeterministic
2016-05-18 03:01:26,640 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] stopping all jobs
2016-05-18 03:01:26,640 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] stopping: (1/1) ...50/first-nondeterministic
2016-05-18 03:01:26,854 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...] stopped all jobs
2016-05-18 03:01:26,859 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] stopped all flows
2016-05-18 03:01:26,859 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] shutting down flow executor
2016-05-18 03:01:26,859 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-450/first-nondete...]  completed in: 00:00.442
2016-05-18 03:01:26,859 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] completed flow: race-450/first-nondeterministic
2016-05-18 03:01:26,860 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-450/first-nondete...] shutdown complete
2016-05-18 03:01:26,882 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:26,882 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 03:01:26,957 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.068
2016-05-18 03:01:26,962 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 03:01:26,963 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:26,981 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] starting
2016-05-18 03:01:26,982 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...]  parallel execution of flows is enabled: false
2016-05-18 03:01:26,983 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...]  executing total flows: 1
2016-05-18 03:01:26,983 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:26,983 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] starting flow: race-500/first-nondeterministic
2016-05-18 03:01:26,984 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] at least one sink is marked for delete
2016-05-18 03:01:26,984 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 03:01:26,990 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] starting
2016-05-18 03:01:26,990 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 03:01:26,991 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-500/first-nondeterministic"]
2016-05-18 03:01:26,991 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...]  parallel execution of steps is enabled: true
2016-05-18 03:01:26,991 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...]  executing total steps: 1
2016-05-18 03:01:26,991 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...]  allocating management threads: 1
2016-05-18 03:01:26,992 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] starting step: (1/1) ...00/first-nondeterministic
2016-05-18 03:01:27,410 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] submitted hadoop job: job_1463540475208_0010
2016-05-18 03:01:27,410 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] tracking url: http://ip-10-158-37-203:43768/proxy/application_1463540475208_0010/
2016-05-18 03:01:27,477 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopping all flows
2016-05-18 03:01:27,482 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopping flow: race-500/first-nondeterministic
2016-05-18 03:01:27,482 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] stopping all jobs
2016-05-18 03:01:27,483 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] stopping: (1/1) ...00/first-nondeterministic
2016-05-18 03:01:27,697 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...] stopped all jobs
2016-05-18 03:01:27,701 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] stopped all flows
2016-05-18 03:01:27,702 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] shutting down flow executor
2016-05-18 03:01:27,702 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [race-500/first-nondete...]  completed in: 00:00.492
2016-05-18 03:01:27,702 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] completed flow: race-500/first-nondeterministic
2016-05-18 03:01:27,703 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [race-500/first-nondete...] shutdown complete
2016-05-18 03:01:27,703 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-400/first-nondeterministic
2016-05-18 03:01:27,705 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-150/first-nondeterministic
2016-05-18 03:01:27,706 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-300/first-nondeterministic
2016-05-18 03:01:27,707 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-500/first-nondeterministic
2016-05-18 03:01:27,709 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-450/first-nondeterministic
2016-05-18 03:01:27,710 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-350/first-nondeterministic
2016-05-18 03:01:27,711 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-200/first-nondeterministic
2016-05-18 03:01:27,718 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-100/first-nondeterministic
2016-05-18 03:01:27,719 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-250/first-nondeterministic
2016-05-18 03:01:27,720 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-0/first-nondeterministic
2016-05-18 03:01:27,721 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascadeRaceCondition/race-50/first-nondeterministic
2016-05-18 03:01:27,784 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:27,785 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 03:01:27,827 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.035
2016-05-18 03:01:27,828 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 03:01:27,829 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:27,865 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:27,866 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 03:01:27,909 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.037
2016-05-18 03:01:27,910 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 03:01:27,911 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:27,943 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:27,943 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 03:01:27,971 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.024
2016-05-18 03:01:27,972 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 03:01:27,972 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:28,013 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:28,014 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 03:01:28,055 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.037
2016-05-18 03:01:28,057 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 03:01:28,058 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:28,083 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:01:28,084 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 03:01:28,174 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.084
2016-05-18 03:01:28,184 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 03:01:28,184 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 03:01:28,223 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting
2016-05-18 03:01:28,225 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...]  parallel execution of flows is enabled: true
2016-05-18 03:01:28,226 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...]  executing total flows: 5
2016-05-18 03:01:28,226 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...]  allocating management threads: 5
2016-05-18 03:01:28,236 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: first2
2016-05-18 03:01:28,236 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] at least one sink is marked for delete
2016-05-18 03:01:28,236 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 03:01:28,245 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: first1
2016-05-18 03:01:28,245 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] at least one sink is marked for delete
2016-05-18 03:01:28,245 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 03:01:28,278 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] starting
2016-05-18 03:01:28,278 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 03:01:28,278 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascade/first2"]
2016-05-18 03:01:28,279 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2]  parallel execution of steps is enabled: true
2016-05-18 03:01:28,279 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2]  executing total steps: 1
2016-05-18 03:01:28,279 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2]  allocating management threads: 1
2016-05-18 03:01:28,284 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] starting
2016-05-18 03:01:28,285 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1]  source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 03:01:28,285 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1]  sink: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascade/first1"]
2016-05-18 03:01:28,285 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1]  parallel execution of steps is enabled: true
2016-05-18 03:01:28,285 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1]  executing total steps: 1
2016-05-18 03:01:28,285 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1]  allocating management threads: 1
2016-05-18 03:01:28,298 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] starting step: (1/1) ...atform/testCascade/first2
2016-05-18 03:01:28,299 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] starting step: (1/1) ...atform/testCascade/first1
2016-05-18 03:01:28,658 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] submitted hadoop job: job_1463540475208_0011
2016-05-18 03:01:28,658 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2] tracking url: http://ip-10-158-37-203:43768/proxy/application_1463540475208_0011/
2016-05-18 03:01:28,680 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] submitted hadoop job: job_1463540475208_0012
2016-05-18 03:01:28,680 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1] tracking url: http://ip-10-158-37-203:43768/proxy/application_1463540475208_0012/
2016-05-18 03:01:46,774 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0001_01_000004 is : 143
2016-05-18 03:01:47,034 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0001_01_000003 is : 143
2016-05-18 03:01:47,600 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0001_01_000005 is : 143
2016-05-18 03:01:47,900 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0001_01_000002 is : 143
2016-05-18 03:01:51,948 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0002_01_000002 is : 143
2016-05-18 03:01:52,058 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0002_01_000003 is : 143
2016-05-18 03:01:52,157 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0002_01_000005 is : 143
2016-05-18 03:01:52,298 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0002_01_000004 is : 143
2016-05-18 03:02:13,674 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0003_01_000003 is : 143
2016-05-18 03:02:14,201 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0003_01_000004 is : 143
2016-05-18 03:02:14,908 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0003_01_000002 is : 143
2016-05-18 03:02:15,392 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0003_01_000005 is : 143
2016-05-18 03:02:23,658 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0004_01_000005 is : 143
2016-05-18 03:02:23,755 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0004_01_000002 is : 143
2016-05-18 03:02:23,862 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0004_01_000003 is : 143
2016-05-18 03:02:24,648 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0004_01_000004 is : 143
2016-05-18 03:02:41,427 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0005_01_000005 is : 143
2016-05-18 03:02:41,916 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0005_01_000004 is : 143
2016-05-18 03:02:42,305 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0005_01_000003 is : 143
2016-05-18 03:02:42,428 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0005_01_000002 is : 143
2016-05-18 03:02:55,346 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0008_01_000002 is : 143
2016-05-18 03:02:55,695 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0008_01_000003 is : 143
2016-05-18 03:02:56,205 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0008_01_000005 is : 143
2016-05-18 03:02:56,246 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0008_01_000004 is : 143
2016-05-18 03:03:11,209 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0011_01_000002 is : 143
2016-05-18 03:03:11,693 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0011_01_000003 is : 143
2016-05-18 03:03:12,264 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0011_01_000005 is : 143
2016-05-18 03:03:12,345 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0011_01_000004 is : 143
2016-05-18 03:03:13,758 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascade/first2/_temporary
2016-05-18 03:03:13,759 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first2]  completed in: 01:45.478, using cpu time: 00:05.810
2016-05-18 03:03:13,760 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: first2
2016-05-18 03:03:13,760 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: second2
2016-05-18 03:03:13,760 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] at least one sink is marked for delete
2016-05-18 03:03:13,760 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 03:03:13,763 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] starting
2016-05-18 03:03:13,763 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2]  source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascade/first2"]
2016-05-18 03:03:13,763 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2]  sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascade/second2"]
2016-05-18 03:03:13,763 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2]  parallel execution of steps is enabled: true
2016-05-18 03:03:13,764 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2]  executing total steps: 1
2016-05-18 03:03:13,764 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2]  allocating management threads: 1
2016-05-18 03:03:13,765 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] starting step: (1/1) ...tform/testCascade/second2
2016-05-18 03:03:13,919 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] submitted hadoop job: job_1463540475208_0013
2016-05-18 03:03:13,919 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2] tracking url: http://ip-10-158-37-203:43768/proxy/application_1463540475208_0013/
2016-05-18 03:03:27,852 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0012_01_000005 is : 143
2016-05-18 03:03:28,375 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0012_01_000002 is : 143
2016-05-18 03:03:28,461 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0012_01_000003 is : 143
2016-05-18 03:03:28,558 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0012_01_000004 is : 143
2016-05-18 03:03:29,963 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascade/first1/_temporary
2016-05-18 03:03:29,964 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [first1]  completed in: 02:01.677, using cpu time: 00:05.620
2016-05-18 03:03:29,964 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: first1
2016-05-18 03:03:29,964 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: second1
2016-05-18 03:03:29,965 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] at least one sink is marked for delete
2016-05-18 03:03:29,965 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 03:03:29,968 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] starting
2016-05-18 03:03:29,968 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1]  source: Hfs["TextDelimited[['ip']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascade/first1"]
2016-05-18 03:03:29,969 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1]  sink: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascade/second1"]
2016-05-18 03:03:29,969 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1]  parallel execution of steps is enabled: true
2016-05-18 03:03:29,969 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1]  executing total steps: 1
2016-05-18 03:03:29,970 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1]  allocating management threads: 1
2016-05-18 03:03:29,972 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] starting step: (1/1) ...tform/testCascade/second1
2016-05-18 03:03:30,125 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] submitted hadoop job: job_1463540475208_0014
2016-05-18 03:03:30,126 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1] tracking url: http://ip-10-158-37-203:43768/proxy/application_1463540475208_0014/
2016-05-18 03:03:46,400 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0013_01_000004 is : 143
2016-05-18 03:03:46,518 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0013_01_000005 is : 143
2016-05-18 03:03:47,115 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0013_01_000002 is : 143
2016-05-18 03:03:47,831 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0013_01_000003 is : 143
2016-05-18 03:03:49,132 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascade/second2/_temporary
2016-05-18 03:03:49,134 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second2]  completed in: 00:35.367, using cpu time: 00:07.240
2016-05-18 03:03:49,134 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: second2
2016-05-18 03:04:02,056 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0014_01_000006 is : 143
2016-05-18 03:04:02,784 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0014_01_000002 is : 143
2016-05-18 03:04:03,006 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0014_01_000003 is : 143
2016-05-18 03:04:03,266 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0014_01_000004 is : 143
2016-05-18 03:04:03,454 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0014_01_000005 is : 143
2016-05-18 03:04:04,745 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascade/second1/_temporary
2016-05-18 03:04:04,747 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [second1]  completed in: 00:34.774, using cpu time: 00:06.900
2016-05-18 03:04:04,747 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: second1
2016-05-18 03:04:04,747 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] starting flow: lhs*rhs
2016-05-18 03:04:04,747 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] at least one sink is marked for delete
2016-05-18 03:04:04,747 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2016-05-18 03:04:04,750 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] starting
2016-05-18 03:04:04,750 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascade/second2"]
2016-05-18 03:04:04,750 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  source: Hfs["TextDelimited[['mangled']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascade/second1"]
2016-05-18 03:04:04,750 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascade/third"]
2016-05-18 03:04:04,750 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  parallel execution of steps is enabled: true
2016-05-18 03:04:04,750 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  executing total steps: 1
2016-05-18 03:04:04,750 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  allocating management threads: 1
2016-05-18 03:04:04,751 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] starting step: (1/1) ...latform/testCascade/third
2016-05-18 03:04:04,899 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] submitted hadoop job: job_1463540475208_0015
2016-05-18 03:04:04,899 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] tracking url: http://ip-10-158-37-203:43768/proxy/application_1463540475208_0015/
2016-05-18 03:04:32,509 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0015_01_000010 is : 143
2016-05-18 03:04:34,548 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0015_01_000005 is : 143
2016-05-18 03:04:34,596 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0015_01_000009 is : 143
2016-05-18 03:04:34,780 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0015_01_000004 is : 143
2016-05-18 03:04:34,804 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0015_01_000006 is : 143
2016-05-18 03:04:34,934 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0015_01_000002 is : 143
2016-05-18 03:04:34,942 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0015_01_000011 is : 143
2016-05-18 03:04:35,051 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0015_01_000003 is : 143
2016-05-18 03:04:39,038 WARN  nodemanager.DefaultContainerExecutor (DefaultContainerExecutor.java:launchContainer(207)) - Exit code from container container_1463540475208_0015_01_000012 is : 143
2016-05-18 03:04:40,257 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/parallelcascadeplatform/testCascade/third/_temporary
2016-05-18 03:04:40,259 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  completed in: 00:35.506, using cpu time: 00:12.390
2016-05-18 03:04:40,259 INFO  cascade.Cascade (BaseCascade.java:logInfo(860)) - [first1+second1+first2+...] completed flow: lhs*rhs
2016-05-18 03:04:40,284 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascade/second1
2016-05-18 03:04:40,295 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascade/first1
2016-05-18 03:04:40,305 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascade/second2
2016-05-18 03:04:40,315 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascade/first2
2016-05-18 03:04:40,324 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/parallelcascadeplatform/testCascade/third

May 18, 2016 3:01:15 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 3:01:15 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 3:01:15 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.webapp.GenericExceptionHandler as a provider class
May 18, 2016 3:01:15 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 3:01:15 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 3:01:15 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 3:01:16 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 3:01:16 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 3:01:16 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 3:01:16 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 3:01:16 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.webapp.GenericExceptionHandler as a provider class
May 18, 2016 3:01:16 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 3:01:16 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 3:01:17 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 3:01:17 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 3:01:17 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 3:01:17 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 3:01:17 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.webapp.GenericExceptionHandler as a provider class
May 18, 2016 3:01:17 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 3:01:17 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 3:01:17 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 3:01:17 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 3:01:18 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 3:01:18 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 3:01:18 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 3:01:18 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.webapp.GenericExceptionHandler as a provider class
May 18, 2016 3:01:18 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 3:01:18 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 3:01:18 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 3:01:18 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 3:01:18 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 3:01:19 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 3:01:19 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 3:01:19 AM com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory register
INFO: Registering org.apache.hadoop.yarn.webapp.GenericExceptionHandler as a provider class
May 18, 2016 3:01:19 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 3:01:19 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 3:01:19 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 3:01:19 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 3:01:20 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 3:01:20 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.