2016-05-18 04:40:42,048 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 04:40:42,077 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.RegressionPipesPlatformTest, with platform: hadoop2-mr1
2016-05-18 04:40:42,113 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-05-18 04:40:42,759 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-05-18 04:40:42,916 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 04:40:43,050 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:43,052 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 04:40:43,155 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 9EE9E2D84AB84413A9251A753728F7FC
2016-05-18 04:40:43,302 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.095
2016-05-18 04:40:43,305 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:40:43,306 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:43,465 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 04:40:43,469 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 04:40:43,469 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lhs.txt"]
2016-05-18 04:40:43,470 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor"]
2016-05-18 04:40:43,470 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 04:40:43,472 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 04:40:43,472 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 04:40:43,472 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...regression/complexlogicor
2016-05-18 04:40:44,032 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity608579808/.staging/job_local608579808_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:44,047 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity608579808/.staging/job_local608579808_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:44,201 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local608579808_0001/job_local608579808_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:44,210 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local608579808_0001/job_local608579808_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:44,220 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local608579808_0001
2016-05-18 04:40:44,221 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 04:40:44,296 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lhs.txt
2016-05-18 04:40:44,323 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:44,323 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:44,339 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: EFC1FEC3569145D8AE5FD65DE639445B, ordinal: 0
2016-05-18 04:40:44,374 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lhs.txt"]
2016-05-18 04:40:44,375 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor"]
2016-05-18 04:40:44,375 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EFC1FEC3569145D8AE5FD65DE639445B, mem on start (mb), free: 244, total: 281, max: 672
2016-05-18 04:40:44,387 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EFC1FEC3569145D8AE5FD65DE639445B, mem on close (mb), free: 244, total: 281, max: 672
2016-05-18 04:40:44,431 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor/_temporary
2016-05-18 04:40:44,432 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.962
2016-05-18 04:40:44,465 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor
2016-05-18 04:40:44,489 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:44,490 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 04:40:44,541 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.041
2016-05-18 04:40:44,542 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:40:44,542 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:44,558 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting
2016-05-18 04:40:44,558 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower.txt"]
2016-05-18 04:40:44,558 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-18 04:40:44,559 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] parallel execution of steps is enabled: false
2016-05-18 04:40:44,559 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] executing total steps: 1
2016-05-18 04:40:44,559 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] allocating management threads: 1
2016-05-18 04:40:44,560 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting step: (1/1) ...oupSplitPipe/intermediate
2016-05-18 04:40:44,639 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1366216664/.staging/job_local1366216664_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:44,640 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1366216664/.staging/job_local1366216664_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:44,702 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1366216664_0002/job_local1366216664_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:44,704 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1366216664_0002/job_local1366216664_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:44,705 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] submitted hadoop job: job_local1366216664_0002
2016-05-18 04:40:44,706 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] tracking url: http://localhost:8080/
2016-05-18 04:40:44,713 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower.txt
2016-05-18 04:40:44,723 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:44,723 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:44,733 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B839181D2C744F7A85E6AC46EF180036, ordinal: 0
2016-05-18 04:40:44,735 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower.txt"]
2016-05-18 04:40:44,735 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-18 04:40:44,736 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B839181D2C744F7A85E6AC46EF180036, mem on start (mb), free: 196, total: 281, max: 672
2016-05-18 04:40:44,738 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B839181D2C744F7A85E6AC46EF180036, mem on close (mb), free: 196, total: 281, max: 672
2016-05-18 04:40:44,761 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate/_temporary
2016-05-18 04:40:44,761 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] completed in: 00:00.202
2016-05-18 04:40:44,807 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:44,808 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 04:40:44,916 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.094
2016-05-18 04:40:44,918 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 04:40:44,919 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:44,970 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] starting
2016-05-18 04:40:44,970 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-18 04:40:44,971 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit"]
2016-05-18 04:40:44,971 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] parallel execution of steps is enabled: false
2016-05-18 04:40:44,971 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] executing total steps: 1
2016-05-18 04:40:44,971 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] allocating management threads: 1
2016-05-18 04:40:44,973 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] starting step: (1/1) ...oupSplitPipe/cogroupsplit
2016-05-18 04:40:45,173 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1314043058/.staging/job_local1314043058_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:45,177 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1314043058/.staging/job_local1314043058_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:45,259 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1314043058_0003/job_local1314043058_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:45,278 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1314043058_0003/job_local1314043058_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:45,279 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] submitted hadoop job: job_local1314043058_0003
2016-05-18 04:40:45,280 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] tracking url: http://localhost:8080/
2016-05-18 04:40:45,289 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate/part-00000
2016-05-18 04:40:45,342 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:45,342 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:45,354 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B4375472A6FD4A248C5DD713942C12CB, ordinal: 0
2016-05-18 04:40:45,360 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-18 04:40:45,361 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lhs*rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num2']]
2016-05-18 04:40:45,361 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B4375472A6FD4A248C5DD713942C12CB, mem on start (mb), free: 165, total: 281, max: 672
2016-05-18 04:40:45,365 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B4375472A6FD4A248C5DD713942C12CB, mem on close (mb), free: 165, total: 281, max: 672
2016-05-18 04:40:45,488 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 04:40:45,489 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 04:40:45,506 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D5C1CFF17992435FA6BA7CF75FE81FDF, ordinal: 1
2016-05-18 04:40:45,509 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lhs*rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num2']]
2016-05-18 04:40:45,510 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit"]
2016-05-18 04:40:45,510 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D5C1CFF17992435FA6BA7CF75FE81FDF, mem on start (mb), free: 154, total: 281, max: 672
2016-05-18 04:40:45,553 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 04:40:45,554 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 04:40:45,570 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D5C1CFF17992435FA6BA7CF75FE81FDF, mem on close (mb), free: 386, total: 397, max: 672
2016-05-18 04:40:45,623 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit/_temporary
2016-05-18 04:40:45,623 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] completed in: 00:00.653
2016-05-18 04:40:45,684 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit
2016-05-18 04:40:45,684 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate
2016-05-18 04:40:45,707 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:45,708 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 04:40:45,758 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.042
2016-05-18 04:40:45,759 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 04:40:45,760 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:45,782 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 04:40:45,782 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 04:40:45,783 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown"]
2016-05-18 04:40:45,783 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 04:40:45,783 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 04:40:45,783 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 04:40:45,784 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...eSortUnknown/none-unknown
2016-05-18 04:40:45,859 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity644394551/.staging/job_local644394551_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:45,861 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity644394551/.staging/job_local644394551_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:45,909 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local644394551_0004/job_local644394551_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:45,911 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local644394551_0004/job_local644394551_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:45,912 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local644394551_0004
2016-05-18 04:40:45,912 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 04:40:45,919 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt
2016-05-18 04:40:45,966 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:45,966 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:45,974 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CA41628DF720451690CF10A8D3F15A44, ordinal: 0
2016-05-18 04:40:45,975 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 04:40:45,975 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{?}:NONE]]
2016-05-18 04:40:45,976 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CA41628DF720451690CF10A8D3F15A44, mem on start (mb), free: 218, total: 397, max: 672
2016-05-18 04:40:45,978 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CA41628DF720451690CF10A8D3F15A44, mem on close (mb), free: 218, total: 397, max: 672
2016-05-18 04:40:46,002 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 04:40:46,002 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 04:40:46,011 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A0EC0785AD6A4DB6AAE18A9707F9786A, ordinal: 1
2016-05-18 04:40:46,012 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{?}:NONE]]
2016-05-18 04:40:46,012 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown"]
2016-05-18 04:40:46,013 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A0EC0785AD6A4DB6AAE18A9707F9786A, mem on start (mb), free: 210, total: 397, max: 672
2016-05-18 04:40:46,025 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A0EC0785AD6A4DB6AAE18A9707F9786A, mem on close (mb), free: 207, total: 397, max: 672
2016-05-18 04:40:46,054 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown/_temporary
2016-05-18 04:40:46,054 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.271
2016-05-18 04:40:46,084 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown
2016-05-18 04:40:46,104 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:46,105 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 04:40:46,142 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.033
2016-05-18 04:40:46,143 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:40:46,143 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:46,165 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 04:40:46,165 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2016-05-18 04:40:46,166 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre"]
2016-05-18 04:40:46,167 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 04:40:46,167 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 04:40:46,167 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 04:40:46,168 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) .../testOOMEPreGroup/oomepre
2016-05-18 04:40:46,246 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1249689830/.staging/job_local1249689830_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:46,247 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1249689830/.staging/job_local1249689830_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:46,302 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1249689830_0005/job_local1249689830_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:46,303 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1249689830_0005/job_local1249689830_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:46,304 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1249689830_0005
2016-05-18 04:40:46,323 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 04:40:46,331 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/apache.10.txt
2016-05-18 04:40:46,339 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:46,339 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:46,350 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BBD6382563DE44F686D274FB5A0F9E64, ordinal: 0
2016-05-18 04:40:46,351 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2016-05-18 04:40:46,351 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre"]
2016-05-18 04:40:46,351 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BBD6382563DE44F686D274FB5A0F9E64, mem on start (mb), free: 382, total: 396, max: 672
2016-05-18 04:40:46,355 ERROR element.TrapHandler (TrapHandler.java:handleReThrowableException(115)) - caught OutOfMemoryException, will not trap, rethrowing
java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$1.throwIntentionalException(RegressionPipesPlatformTest.java:583)
at cascading.TestFunction.operate(TestFunction.java:75)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:100)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:40)
at cascading.flow.stream.element.SourceStage.map(SourceStage.java:110)
at cascading.flow.stream.element.SourceStage.run(SourceStage.java:66)
at cascading.flow.hadoop.FlowMapper.run(FlowMapper.java:142)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:430)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:342)
at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:243)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-18 04:40:46,360 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BBD6382563DE44F686D274FB5A0F9E64, mem on close (mb), free: 381, total: 396, max: 672
2016-05-18 04:40:46,362 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local1249689830_0005
java.lang.Exception: java.lang.OutOfMemoryError: fake error
at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:522)
Caused by: java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$1.throwIntentionalException(RegressionPipesPlatformTest.java:583)
at cascading.TestFunction.operate(TestFunction.java:75)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:100)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:40)
at cascading.flow.stream.element.SourceStage.map(SourceStage.java:110)
at cascading.flow.stream.element.SourceStage.run(SourceStage.java:66)
at cascading.flow.hadoop.FlowMapper.run(FlowMapper.java:142)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:430)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:342)
at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:243)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-18 04:40:46,365 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [test] hadoop job job_local1249689830_0005 state at FAILED
2016-05-18 04:40:46,365 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [test] failure info: NA
2016-05-18 04:40:46,365 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [test] task completion events identify failed tasks
2016-05-18 04:40:46,365 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [test] task completion events count: 0
2016-05-18 04:40:46,366 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopping all jobs
2016-05-18 04:40:46,366 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopping: (1/1) .../testOOMEPreGroup/oomepre
2016-05-18 04:40:46,367 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopped all jobs
2016-05-18 04:40:46,368 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre/_temporary
2016-05-18 04:40:46,368 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.202
exception = cascading.flow.FlowException: local step failed: (1/1) .../testOOMEPreGroup/oomepre
2016-05-18 04:40:46,369 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre
2016-05-18 04:40:46,388 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:46,388 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 04:40:46,417 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-05-18 04:40:46,418 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:40:46,418 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:46,427 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 04:40:46,428 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 04:40:46,429 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCopy/copy"]
2016-05-18 04:40:46,430 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 04:40:46,430 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 04:40:46,430 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 04:40:46,431 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...pesplatform/testCopy/copy
2016-05-18 04:40:46,494 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1378930198/.staging/job_local1378930198_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:46,495 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1378930198/.staging/job_local1378930198_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:46,532 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1378930198_0006/job_local1378930198_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:46,533 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1378930198_0006/job_local1378930198_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:46,534 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1378930198_0006
2016-05-18 04:40:46,534 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 04:40:46,540 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt
2016-05-18 04:40:46,548 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:46,548 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:46,554 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D257DC365985431DBC1D349E3886E508, ordinal: 0
2016-05-18 04:40:46,554 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 04:40:46,555 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCopy/copy"]
2016-05-18 04:40:46,555 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D257DC365985431DBC1D349E3886E508, mem on start (mb), free: 336, total: 396, max: 672
2016-05-18 04:40:46,556 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D257DC365985431DBC1D349E3886E508, mem on close (mb), free: 336, total: 396, max: 672
2016-05-18 04:40:46,578 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCopy/copy/_temporary
2016-05-18 04:40:46,579 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.151
2016-05-18 04:40:46,602 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testCopy/copy
2016-05-18 04:40:46,624 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:46,625 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 04:40:46,657 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.027
2016-05-18 04:40:46,658 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:40:46,659 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:46,677 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 04:40:46,677 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 04:40:46,677 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace"]
2016-05-18 04:40:46,677 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 04:40:46,678 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 04:40:46,678 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 04:40:46,679 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...wnReplace/unknown-replace
2016-05-18 04:40:46,737 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1014826785/.staging/job_local1014826785_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:46,738 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1014826785/.staging/job_local1014826785_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:46,774 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1014826785_0007/job_local1014826785_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:46,774 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1014826785_0007/job_local1014826785_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:46,775 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1014826785_0007
2016-05-18 04:40:46,775 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 04:40:46,783 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt
2016-05-18 04:40:46,791 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:46,791 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:46,803 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F36F61845C5B45F6BB7CD049E0732DB0, ordinal: 0
2016-05-18 04:40:46,804 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 04:40:46,804 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace"]
2016-05-18 04:40:46,804 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F36F61845C5B45F6BB7CD049E0732DB0, mem on start (mb), free: 282, total: 396, max: 672
2016-05-18 04:40:46,806 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F36F61845C5B45F6BB7CD049E0732DB0, mem on close (mb), free: 281, total: 396, max: 672
2016-05-18 04:40:46,822 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace/_temporary
2016-05-18 04:40:46,822 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.144
2016-05-18 04:40:46,876 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace
2016-05-18 04:40:46,893 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:46,893 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 04:40:46,927 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.030
2016-05-18 04:40:46,928 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:40:46,928 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:46,941 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 04:40:46,941 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lhs.txt"]
2016-05-18 04:40:46,942 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand"]
2016-05-18 04:40:46,942 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 04:40:46,942 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 04:40:46,942 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 04:40:46,943 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...egression/complexlogicand
2016-05-18 04:40:47,004 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1728310593/.staging/job_local1728310593_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:47,006 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1728310593/.staging/job_local1728310593_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:47,046 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1728310593_0008/job_local1728310593_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:47,047 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1728310593_0008/job_local1728310593_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:47,047 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1728310593_0008
2016-05-18 04:40:47,048 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 04:40:47,053 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lhs.txt
2016-05-18 04:40:47,061 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:47,061 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:47,069 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D3DC842DDA884F4EA62BF75EC8B9DFB9, ordinal: 0
2016-05-18 04:40:47,070 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lhs.txt"]
2016-05-18 04:40:47,070 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand"]
2016-05-18 04:40:47,070 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D3DC842DDA884F4EA62BF75EC8B9DFB9, mem on start (mb), free: 225, total: 396, max: 672
2016-05-18 04:40:47,073 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D3DC842DDA884F4EA62BF75EC8B9DFB9, mem on close (mb), free: 224, total: 396, max: 672
2016-05-18 04:40:47,092 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand/_temporary
2016-05-18 04:40:47,092 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.150
2016-05-18 04:40:47,116 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand
2016-05-18 04:40:47,136 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:47,137 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 04:40:47,176 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.034
2016-05-18 04:40:47,178 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:40:47,178 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:47,194 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 04:40:47,194 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lhs.txt"]
2016-05-18 04:40:47,195 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor"]
2016-05-18 04:40:47,195 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 04:40:47,195 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 04:40:47,195 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 04:40:47,196 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...egression/complexlogicxor
2016-05-18 04:40:47,264 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1268387951/.staging/job_local1268387951_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:47,265 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1268387951/.staging/job_local1268387951_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:47,313 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1268387951_0009/job_local1268387951_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:47,314 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1268387951_0009/job_local1268387951_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:47,315 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1268387951_0009
2016-05-18 04:40:47,315 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 04:40:47,322 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lhs.txt
2016-05-18 04:40:47,329 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:47,329 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:47,337 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BBBD816ECEAE46F1AC931B2107740F0B, ordinal: 0
2016-05-18 04:40:47,338 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lhs.txt"]
2016-05-18 04:40:47,339 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor"]
2016-05-18 04:40:47,339 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BBBD816ECEAE46F1AC931B2107740F0B, mem on start (mb), free: 171, total: 396, max: 672
2016-05-18 04:40:47,342 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BBBD816ECEAE46F1AC931B2107740F0B, mem on close (mb), free: 170, total: 396, max: 672
2016-05-18 04:40:47,361 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor/_temporary
2016-05-18 04:40:47,361 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.166
2016-05-18 04:40:47,388 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor
2016-05-18 04:40:47,405 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:47,406 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 04:40:47,472 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.062
2016-05-18 04:40:47,473 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 04:40:47,473 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:47,507 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting
2016-05-18 04:40:47,511 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/upper.txt"]
2016-05-18 04:40:47,512 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower.txt"]
2016-05-18 04:40:47,512 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost"]
2016-05-18 04:40:47,512 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] parallel execution of steps is enabled: false
2016-05-18 04:40:47,513 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executing total steps: 1
2016-05-18 04:40:47,513 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] allocating management threads: 1
2016-05-18 04:40:47,514 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting step: (1/1) ...estOOMEPostGroup/oomepost
2016-05-18 04:40:47,579 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1538883839/.staging/job_local1538883839_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:47,580 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1538883839/.staging/job_local1538883839_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:47,617 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1538883839_0010/job_local1538883839_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:47,618 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1538883839_0010/job_local1538883839_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:47,619 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] submitted hadoop job: job_local1538883839_0010
2016-05-18 04:40:47,619 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] tracking url: http://localhost:8080/
2016-05-18 04:40:47,625 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/upper.txt
2016-05-18 04:40:47,639 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:47,640 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:47,651 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F316533F86A64958B2457817DAD52712, ordinal: 0
2016-05-18 04:40:47,652 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/upper.txt"]
2016-05-18 04:40:47,652 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 04:40:47,652 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F316533F86A64958B2457817DAD52712, mem on start (mb), free: 246, total: 395, max: 672
2016-05-18 04:40:47,654 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F316533F86A64958B2457817DAD52712, mem on close (mb), free: 246, total: 395, max: 672
2016-05-18 04:40:47,662 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower.txt
2016-05-18 04:40:47,690 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:47,690 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:47,698 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F316533F86A64958B2457817DAD52712, ordinal: 0
2016-05-18 04:40:47,699 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower.txt"]
2016-05-18 04:40:47,699 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 04:40:47,699 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F316533F86A64958B2457817DAD52712, mem on start (mb), free: 276, total: 386, max: 672
2016-05-18 04:40:47,700 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F316533F86A64958B2457817DAD52712, mem on close (mb), free: 276, total: 386, max: 672
2016-05-18 04:40:47,722 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 04:40:47,722 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 04:40:47,729 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: C330A9E7643344C9981DA23DC2932744, ordinal: 1
2016-05-18 04:40:47,729 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 04:40:47,729 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost"]
2016-05-18 04:40:47,730 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C330A9E7643344C9981DA23DC2932744, mem on start (mb), free: 267, total: 386, max: 672
2016-05-18 04:40:47,737 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 04:40:47,737 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 04:40:47,738 ERROR element.TrapHandler (TrapHandler.java:handleReThrowableException(115)) - caught OutOfMemoryException, will not trap, rethrowing
java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$2.throwIntentionalException(RegressionPipesPlatformTest.java:635)
at cascading.TestFunction.operate(TestFunction.java:75)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:100)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:40)
at cascading.flow.stream.duct.OpenDuct.receive(OpenDuct.java:45)
at cascading.flow.stream.duct.OpenDuct.receive(OpenDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.accept(HadoopGroupGate.java:147)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:146)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-18 04:40:47,738 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C330A9E7643344C9981DA23DC2932744, mem on close (mb), free: 264, total: 386, max: 672
2016-05-18 04:40:47,740 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local1538883839_0010
java.lang.Exception: java.lang.OutOfMemoryError: fake error
at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$2.throwIntentionalException(RegressionPipesPlatformTest.java:635)
at cascading.TestFunction.operate(TestFunction.java:75)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:100)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:40)
at cascading.flow.stream.duct.OpenDuct.receive(OpenDuct.java:45)
at cascading.flow.stream.duct.OpenDuct.receive(OpenDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.accept(HadoopGroupGate.java:147)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:146)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-18 04:40:47,749 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] hadoop job job_local1538883839_0010 state at FAILED
2016-05-18 04:40:47,749 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] failure info: NA
2016-05-18 04:40:47,750 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] task completion events identify failed tasks
2016-05-18 04:40:47,750 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] task completion events count: 0
2016-05-18 04:40:47,759 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] stopping all jobs
2016-05-18 04:40:47,760 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] stopping: (1/1) ...estOOMEPostGroup/oomepost
2016-05-18 04:40:47,760 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] stopped all jobs
2016-05-18 04:40:47,761 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost/_temporary
2016-05-18 04:40:47,761 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] completed in: 00:00.254
exception = cascading.flow.FlowException: local step failed: (1/1) ...estOOMEPostGroup/oomepost
2016-05-18 04:40:47,762 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost
2016-05-18 04:40:47,782 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:47,783 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 04:40:47,817 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.031
2016-05-18 04:40:47,817 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 04:40:47,818 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:47,831 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 04:40:47,833 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2016-05-18 04:40:47,834 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified"]
2016-05-18 04:40:47,834 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 04:40:47,834 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 04:40:47,834 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 04:40:47,835 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...Modified/lasteachmodified
2016-05-18 04:40:47,910 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity822696545/.staging/job_local822696545_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:47,912 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity822696545/.staging/job_local822696545_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:47,956 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local822696545_0011/job_local822696545_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:47,957 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local822696545_0011/job_local822696545_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:47,958 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local822696545_0011
2016-05-18 04:40:47,959 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 04:40:47,964 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/apache.10.txt
2016-05-18 04:40:47,985 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:47,985 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:47,993 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D9D65DA93B594912A6001A8EE52C1884, ordinal: 0
2016-05-18 04:40:47,994 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2016-05-18 04:40:47,994 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'insert']]
2016-05-18 04:40:47,995 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D9D65DA93B594912A6001A8EE52C1884, mem on start (mb), free: 281, total: 393, max: 672
2016-05-18 04:40:47,997 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D9D65DA93B594912A6001A8EE52C1884, mem on close (mb), free: 281, total: 393, max: 672
2016-05-18 04:40:48,015 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 04:40:48,016 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 04:40:48,023 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: BCC27DEAABD641F7B8BC4DF2D49F0602, ordinal: 1
2016-05-18 04:40:48,024 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'insert']]
2016-05-18 04:40:48,024 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified"]
2016-05-18 04:40:48,024 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BCC27DEAABD641F7B8BC4DF2D49F0602, mem on start (mb), free: 273, total: 393, max: 672
2016-05-18 04:40:48,036 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BCC27DEAABD641F7B8BC4DF2D49F0602, mem on close (mb), free: 272, total: 393, max: 672
2016-05-18 04:40:48,063 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified/_temporary
2016-05-18 04:40:48,065 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.231
2016-05-18 04:40:48,089 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified
2016-05-18 04:40:48,104 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:48,104 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 04:40:48,133 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.026
2016-05-18 04:40:48,133 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:40:48,134 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:48,144 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 04:40:48,144 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 04:40:48,145 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknown/unknown"]
2016-05-18 04:40:48,145 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 04:40:48,145 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 04:40:48,145 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 04:40:48,146 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...tform/testUnknown/unknown
2016-05-18 04:40:48,211 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1016399148/.staging/job_local1016399148_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:48,212 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1016399148/.staging/job_local1016399148_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:48,248 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1016399148_0012/job_local1016399148_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:48,249 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1016399148_0012/job_local1016399148_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:48,250 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1016399148_0012
2016-05-18 04:40:48,250 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 04:40:48,255 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt
2016-05-18 04:40:48,261 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:48,261 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:48,269 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E794B1DACB7944C78339BDDA3CFFFB9E, ordinal: 0
2016-05-18 04:40:48,269 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 04:40:48,270 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknown/unknown"]
2016-05-18 04:40:48,270 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E794B1DACB7944C78339BDDA3CFFFB9E, mem on start (mb), free: 219, total: 393, max: 672
2016-05-18 04:40:48,272 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E794B1DACB7944C78339BDDA3CFFFB9E, mem on close (mb), free: 218, total: 393, max: 672
2016-05-18 04:40:48,284 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknown/unknown/_temporary
2016-05-18 04:40:48,284 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.140
2016-05-18 04:40:48,308 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testUnknown/unknown
2016-05-18 04:40:48,329 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:48,329 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 04:40:48,365 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.032
2016-05-18 04:40:48,365 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:40:48,366 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:48,376 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 04:40:48,376 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/critics.txt"]
2016-05-18 04:40:48,376 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth"]
2016-05-18 04:40:48,376 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 04:40:48,376 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 04:40:48,377 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 04:40:48,377 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...orm/testVarWidth/varwidth
2016-05-18 04:40:48,430 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity488155254/.staging/job_local488155254_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:48,431 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity488155254/.staging/job_local488155254_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:48,465 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local488155254_0013/job_local488155254_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:48,466 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local488155254_0013/job_local488155254_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:48,466 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local488155254_0013
2016-05-18 04:40:48,467 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 04:40:48,471 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/critics.txt
2016-05-18 04:40:48,477 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:48,478 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:48,484 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D753E3A062CE4622B5E6EC987A1D2375, ordinal: 0
2016-05-18 04:40:48,485 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/critics.txt"]
2016-05-18 04:40:48,486 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth"]
2016-05-18 04:40:48,486 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D753E3A062CE4622B5E6EC987A1D2375, mem on start (mb), free: 167, total: 393, max: 672
2016-05-18 04:40:48,488 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D753E3A062CE4622B5E6EC987A1D2375, mem on close (mb), free: 166, total: 393, max: 672
2016-05-18 04:40:48,501 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth/_temporary
2016-05-18 04:40:48,502 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.125
2016-05-18 04:40:48,533 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth
2016-05-18 04:40:48,549 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:48,549 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 04:40:48,553 WARN planner.FlowPlanner (FlowPlanner.java:verifyPipeAssemblyEndPoints(464)) - duplicate head name found, not an error but heads should have unique names: 'test'
2016-05-18 04:40:48,553 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testDupeHeadNames/unknown
2016-05-18 04:40:48,571 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:48,571 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 04:40:48,575 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testDupeTailNames/unknown
2016-05-18 04:40:48,875 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:48,875 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 04:40:51,437 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:02.541
2016-05-18 04:40:51,442 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 04:40:51,442 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:51,648 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] starting
2016-05-18 04:40:51,648 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/apache.200.txt"]
2016-05-18 04:40:51,648 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline"]
2016-05-18 04:40:51,648 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] parallel execution of steps is enabled: false
2016-05-18 04:40:51,648 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] executing total steps: 1
2016-05-18 04:40:51,649 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] allocating management threads: 1
2016-05-18 04:40:51,649 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] starting step: (1/1) ...tDeepPipeline/deeppipline
2016-05-18 04:40:51,704 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1501075159/.staging/job_local1501075159_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:51,706 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1501075159/.staging/job_local1501075159_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:51,746 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1501075159_0014/job_local1501075159_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:51,747 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1501075159_0014/job_local1501075159_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:51,748 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] submitted hadoop job: job_local1501075159_0014
2016-05-18 04:40:51,748 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] tracking url: http://localhost:8080/
2016-05-18 04:40:51,753 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/apache.200.txt
2016-05-18 04:40:51,767 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:51,767 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:51,896 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D2C549F77F504AA7BB382A6ADCF4B591, ordinal: 0
2016-05-18 04:40:51,917 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/apache.200.txt"]
2016-05-18 04:40:51,917 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(pipeline)[by:[{1}:'hash']]
2016-05-18 04:40:51,918 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D2C549F77F504AA7BB382A6ADCF4B591, mem on start (mb), free: 273, total: 394, max: 672
2016-05-18 04:40:52,107 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D2C549F77F504AA7BB382A6ADCF4B591, mem on close (mb), free: 264, total: 394, max: 672
2016-05-18 04:40:52,145 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 04:40:52,145 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 04:40:52,226 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D63838E33C3E44D998BBA9A70AEF26BF, ordinal: 1
2016-05-18 04:40:52,241 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(pipeline)[by:[{1}:'hash']]
2016-05-18 04:40:52,242 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline"]
2016-05-18 04:40:52,242 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D63838E33C3E44D998BBA9A70AEF26BF, mem on start (mb), free: 254, total: 394, max: 672
2016-05-18 04:40:52,610 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D63838E33C3E44D998BBA9A70AEF26BF, mem on close (mb), free: 244, total: 394, max: 672
2016-05-18 04:40:52,629 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline/_temporary
2016-05-18 04:40:52,630 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] completed in: 00:00.981
2016-05-18 04:40:52,667 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline
2016-05-18 04:40:52,684 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:52,684 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 04:40:52,706 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.018
2016-05-18 04:40:52,707 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:40:52,707 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:52,715 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting
2016-05-18 04:40:52,716 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower.txt"]
2016-05-18 04:40:52,716 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-18 04:40:52,717 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] parallel execution of steps is enabled: false
2016-05-18 04:40:52,717 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] executing total steps: 1
2016-05-18 04:40:52,718 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] allocating management threads: 1
2016-05-18 04:40:52,720 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting step: (1/1) ...litPipe/splitintermediate
2016-05-18 04:40:52,774 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity665875660/.staging/job_local665875660_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:52,775 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity665875660/.staging/job_local665875660_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:52,826 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local665875660_0015/job_local665875660_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:52,827 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local665875660_0015/job_local665875660_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:52,828 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] submitted hadoop job: job_local665875660_0015
2016-05-18 04:40:52,828 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] tracking url: http://localhost:8080/
2016-05-18 04:40:52,835 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower.txt
2016-05-18 04:40:52,844 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:52,844 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:52,849 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D1DC61EA9C66428E9D4D85C6A24AD6BB, ordinal: 0
2016-05-18 04:40:52,849 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower.txt"]
2016-05-18 04:40:52,849 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-18 04:40:52,850 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D1DC61EA9C66428E9D4D85C6A24AD6BB, mem on start (mb), free: 192, total: 394, max: 672
2016-05-18 04:40:52,852 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D1DC61EA9C66428E9D4D85C6A24AD6BB, mem on close (mb), free: 191, total: 394, max: 672
2016-05-18 04:40:52,873 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate/_temporary
2016-05-18 04:40:52,873 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] completed in: 00:00.158
2016-05-18 04:40:52,889 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:52,889 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 04:40:52,919 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-05-18 04:40:52,920 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 04:40:52,921 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:52,932 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] starting
2016-05-18 04:40:52,933 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-18 04:40:52,933 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit"]
2016-05-18 04:40:52,933 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] parallel execution of steps is enabled: false
2016-05-18 04:40:52,933 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] executing total steps: 1
2016-05-18 04:40:52,933 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] allocating management threads: 1
2016-05-18 04:40:52,934 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] starting step: (1/1) ...pBySplitPipe/groupbysplit
2016-05-18 04:40:52,999 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity771170236/.staging/job_local771170236_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:52,999 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity771170236/.staging/job_local771170236_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:53,038 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local771170236_0016/job_local771170236_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:53,040 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local771170236_0016/job_local771170236_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:53,040 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] submitted hadoop job: job_local771170236_0016
2016-05-18 04:40:53,041 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] tracking url: http://localhost:8080/
2016-05-18 04:40:53,045 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate/part-00000
2016-05-18 04:40:53,059 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:53,060 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:53,065 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D6B854F26F7140E2BD0E7C5B10CCAA55, ordinal: 0
2016-05-18 04:40:53,066 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-18 04:40:53,066 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2016-05-18 04:40:53,066 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D6B854F26F7140E2BD0E7C5B10CCAA55, mem on start (mb), free: 270, total: 393, max: 672
2016-05-18 04:40:53,067 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D6B854F26F7140E2BD0E7C5B10CCAA55, mem on close (mb), free: 270, total: 393, max: 672
2016-05-18 04:40:53,081 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 04:40:53,081 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 04:40:53,084 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D2A3931D40C5450BB60E7854AFE42B69, ordinal: 1
2016-05-18 04:40:53,085 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2016-05-18 04:40:53,085 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit"]
2016-05-18 04:40:53,085 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D2A3931D40C5450BB60E7854AFE42B69, mem on start (mb), free: 262, total: 393, max: 672
2016-05-18 04:40:53,093 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D2A3931D40C5450BB60E7854AFE42B69, mem on close (mb), free: 261, total: 393, max: 672
2016-05-18 04:40:53,107 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit/_temporary
2016-05-18 04:40:53,107 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] completed in: 00:00.174
2016-05-18 04:40:53,147 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate
2016-05-18 04:40:53,148 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit
2016-05-18 04:40:53,162 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:53,162 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 04:40:53,210 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.043
2016-05-18 04:40:53,211 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-18 04:40:53,212 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:53,238 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] starting
2016-05-18 04:40:53,238 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 04:40:53,238 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars"]
2016-05-18 04:40:53,238 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] parallel execution of steps is enabled: false
2016-05-18 04:40:53,239 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] executing total steps: 2
2016-05-18 04:40:53,239 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] allocating management threads: 1
2016-05-18 04:40:53,239 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] starting step: (1/2)
2016-05-18 04:40:53,307 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1587625822/.staging/job_local1587625822_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:53,308 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1587625822/.staging/job_local1587625822_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:53,340 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1587625822_0017/job_local1587625822_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:53,341 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1587625822_0017/job_local1587625822_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:53,342 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] submitted hadoop job: job_local1587625822_0017
2016-05-18 04:40:53,342 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] tracking url: http://localhost:8080/
2016-05-18 04:40:53,346 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt
2016-05-18 04:40:53,364 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:53,364 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:53,368 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F4C3CE720E4F4ED1B4A2B5C316B095DC, ordinal: 0
2016-05-18 04:40:53,369 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 04:40:53,369 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-05-18 04:40:53,369 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F4C3CE720E4F4ED1B4A2B5C316B095DC, mem on start (mb), free: 279, total: 393, max: 672
2016-05-18 04:40:53,371 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F4C3CE720E4F4ED1B4A2B5C316B095DC, mem on close (mb), free: 279, total: 393, max: 672
2016-05-18 04:40:53,384 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 04:40:53,384 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 04:40:53,388 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E19AD9312B93442782B0E3C867FE4BB3, ordinal: 1
2016-05-18 04:40:53,388 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-05-18 04:40:53,389 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[[UNKNOWN]->[ALL]]"][3600994542/__&%&%bar:bar@foo:_blah_/]
2016-05-18 04:40:53,389 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E19AD9312B93442782B0E3C867FE4BB3, mem on start (mb), free: 273, total: 393, max: 672
2016-05-18 04:40:53,406 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E19AD9312B93442782B0E3C867FE4BB3, mem on close (mb), free: 271, total: 393, max: 672
2016-05-18 04:40:53,420 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] starting step: (2/2) ...sInTempFiles/illegalchars
2016-05-18 04:40:53,479 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity204323024/.staging/job_local204323024_0018/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:53,480 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity204323024/.staging/job_local204323024_0018/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:53,512 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local204323024_0018/job_local204323024_0018.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:53,513 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local204323024_0018/job_local204323024_0018.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:53,514 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] submitted hadoop job: job_local204323024_0018
2016-05-18 04:40:53,514 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] tracking url: http://localhost:8080/
2016-05-18 04:40:53,518 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/3600994542____bar_bar_foo__blah__37287F9691804CABA172C9C22B17CD65/part-00000
2016-05-18 04:40:53,541 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:53,541 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:53,545 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B067AC0861B143F9BA0E0A91B2254BB9, ordinal: 0
2016-05-18 04:40:53,545 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[[UNKNOWN]->[ALL]]"][3600994542/__&%&%bar:bar@foo:_blah_/]
2016-05-18 04:40:53,545 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-05-18 04:40:53,546 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B067AC0861B143F9BA0E0A91B2254BB9, mem on start (mb), free: 279, total: 393, max: 672
2016-05-18 04:40:53,547 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B067AC0861B143F9BA0E0A91B2254BB9, mem on close (mb), free: 279, total: 393, max: 672
2016-05-18 04:40:53,561 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 04:40:53,561 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 04:40:53,565 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: EE338E4AA8364A07809BA330B49C3544, ordinal: 1
2016-05-18 04:40:53,565 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-05-18 04:40:53,565 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars"]
2016-05-18 04:40:53,565 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: EE338E4AA8364A07809BA330B49C3544, mem on start (mb), free: 273, total: 393, max: 672
2016-05-18 04:40:53,573 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: EE338E4AA8364A07809BA330B49C3544, mem on close (mb), free: 272, total: 393, max: 672
2016-05-18 04:40:53,590 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars/_temporary
2016-05-18 04:40:53,591 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] completed in: 00:00.351
2016-05-18 04:40:53,612 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars
2016-05-18 04:40:53,626 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 04:40:53,626 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 04:40:53,642 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.012
2016-05-18 04:40:53,642 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 04:40:53,642 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 04:40:53,651 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 04:40:53,651 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 04:40:53,651 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic"]
2016-05-18 04:40:53,651 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 04:40:53,651 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 04:40:53,651 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 04:40:53,652 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...-unknown-nondeterministic
2016-05-18 04:40:53,704 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1140340796/.staging/job_local1140340796_0019/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:53,705 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/tmp/cascading/staging/teamcity1140340796/.staging/job_local1140340796_0019/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:53,747 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1140340796_0019/job_local1140340796_0019.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 04:40:53,747 WARN conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1140340796_0019/job_local1140340796_0019.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 04:40:53,748 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1140340796_0019
2016-05-18 04:40:53,749 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 04:40:53,752 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt
2016-05-18 04:40:53,758 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 04:40:53,758 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 04:40:53,762 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F7AA2210A52E4D25856A5CABFBC46527, ordinal: 0
2016-05-18 04:40:53,763 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 04:40:53,763 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic"]
2016-05-18 04:40:53,763 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F7AA2210A52E4D25856A5CABFBC46527, mem on start (mb), free: 221, total: 393, max: 672
2016-05-18 04:40:53,766 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F7AA2210A52E4D25856A5CABFBC46527, mem on close (mb), free: 221, total: 393, max: 672
2016-05-18 04:40:53,782 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic/_temporary
2016-05-18 04:40:53,782 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.131
2016-05-18 04:40:53,803 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.5.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic