Class cascading.RegressionPipesPlatformTest

18

tests

0

failures

0

ignored

12.154s

duration

100%

successful

Tests

Test Duration Result
testCoGroupSplitPipe 1.183s passed
testComplexLogicAnd 0.246s passed
testComplexLogicOr 2.426s passed
testComplexLogicXor 0.279s passed
testCopy 0.295s passed
testDeepPipeline 4.384s passed
testDupeHeadNames 0.019s passed
testDupeTailNames 0.026s passed
testGroupBySplitPipe 0.471s passed
testGroupNoneSortUnknown 0.491s passed
testIllegalCharsInTempFiles 0.468s passed
testLastEachNotModified 0.323s passed
testOOMEPostGroup 0.383s passed
testOOMEPreGroup 0.247s passed
testUnGroupUnknown 0.194s passed
testUnknown 0.236s passed
testUnknownReplace 0.255s passed
testVarWidth 0.228s passed

Standard output

2016-05-17 23:49:25,871 INFO  platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-17 23:49:25,892 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.RegressionPipesPlatformTest, with platform: hadoop2-mr1
2016-05-17 23:49:25,918 INFO  hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-05-17 23:49:26,497 WARN  util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-05-17 23:49:26,694 INFO  platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides: 
2016-05-17 23:49:26,847 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:26,849 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-17 23:49:26,959 INFO  property.AppProps (AppProps.java:getAppID(177)) - using app.id: 6139DBD5C876418A87731BD75933224E
2016-05-17 23:49:27,111 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.091
2016-05-17 23:49:27,114 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 23:49:27,115 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-17 23:49:27,276 INFO  util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-17 23:49:27,278 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 23:49:27,279 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lhs.txt"]
2016-05-17 23:49:27,279 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor"]
2016-05-17 23:49:27,280 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-17 23:49:27,281 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-17 23:49:27,282 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-17 23:49:27,283 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...regression/complexlogicor
2016-05-17 23:49:27,808 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1329072951/.staging/job_local1329072951_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:27,810 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1329072951/.staging/job_local1329072951_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:28,010 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1329072951_0001/job_local1329072951_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:28,011 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1329072951_0001/job_local1329072951_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:28,025 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1329072951_0001
2016-05-17 23:49:28,026 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-17 23:49:28,135 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lhs.txt
2016-05-17 23:49:28,163 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:28,163 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:28,185 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D1F1969F602A4384B77E401E4A58F56A, ordinal: 0
2016-05-17 23:49:28,230 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lhs.txt"]
2016-05-17 23:49:28,230 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor"]
2016-05-17 23:49:28,232 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D1F1969F602A4384B77E401E4A58F56A, mem on start (mb), free: 245, total: 281, max: 672
2016-05-17 23:49:28,250 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D1F1969F602A4384B77E401E4A58F56A, mem on close (mb), free: 244, total: 281, max: 672
2016-05-17 23:49:28,299 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor/_temporary
2016-05-17 23:49:28,299 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:01.019
2016-05-17 23:49:28,341 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor
2016-05-17 23:49:28,375 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:28,376 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-17 23:49:28,435 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.049
2016-05-17 23:49:28,436 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 23:49:28,437 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-17 23:49:28,459 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting
2016-05-17 23:49:28,459 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split]  source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower.txt"]
2016-05-17 23:49:28,460 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split]  sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-17 23:49:28,460 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split]  parallel execution of steps is enabled: false
2016-05-17 23:49:28,460 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split]  executing total steps: 1
2016-05-17 23:49:28,460 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split]  allocating management threads: 1
2016-05-17 23:49:28,460 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting step: (1/1) ...oupSplitPipe/intermediate
2016-05-17 23:49:28,539 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity2009473088/.staging/job_local2009473088_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:28,539 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity2009473088/.staging/job_local2009473088_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:28,611 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2009473088_0002/job_local2009473088_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:28,612 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2009473088_0002/job_local2009473088_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:28,615 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split] submitted hadoop job: job_local2009473088_0002
2016-05-17 23:49:28,616 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split] tracking url: http://localhost:8080/
2016-05-17 23:49:28,624 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower.txt
2016-05-17 23:49:28,637 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:28,637 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:28,650 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CC0A851CB91D4456A81E4A3AF5C13F4D, ordinal: 0
2016-05-17 23:49:28,651 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower.txt"]
2016-05-17 23:49:28,652 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-17 23:49:28,652 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CC0A851CB91D4456A81E4A3AF5C13F4D, mem on start (mb), free: 200, total: 281, max: 672
2016-05-17 23:49:28,655 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CC0A851CB91D4456A81E4A3AF5C13F4D, mem on close (mb), free: 200, total: 281, max: 672
2016-05-17 23:49:28,672 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate/_temporary
2016-05-17 23:49:28,672 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split]  completed in: 00:00.212
2016-05-17 23:49:28,710 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:28,710 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-17 23:49:28,815 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.096
2016-05-17 23:49:28,816 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 23:49:28,817 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-17 23:49:28,851 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] starting
2016-05-17 23:49:28,852 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-17 23:49:28,852 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit"]
2016-05-17 23:49:28,853 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  parallel execution of steps is enabled: false
2016-05-17 23:49:28,853 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  executing total steps: 1
2016-05-17 23:49:28,853 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  allocating management threads: 1
2016-05-17 23:49:28,855 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] starting step: (1/1) ...oupSplitPipe/cogroupsplit
2016-05-17 23:49:28,979 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity397489050/.staging/job_local397489050_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:28,983 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity397489050/.staging/job_local397489050_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:29,054 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local397489050_0003/job_local397489050_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:29,055 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local397489050_0003/job_local397489050_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:29,056 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] submitted hadoop job: job_local397489050_0003
2016-05-17 23:49:29,056 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] tracking url: http://localhost:8080/
2016-05-17 23:49:29,063 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate/part-00000
2016-05-17 23:49:29,193 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:29,194 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:29,206 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B84E9AA2B6794C1E8E9F3763E85996D3, ordinal: 0
2016-05-17 23:49:29,213 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-17 23:49:29,213 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lhs*rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num2']]
2016-05-17 23:49:29,214 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B84E9AA2B6794C1E8E9F3763E85996D3, mem on start (mb), free: 56, total: 281, max: 672
2016-05-17 23:49:29,219 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B84E9AA2B6794C1E8E9F3763E85996D3, mem on close (mb), free: 56, total: 281, max: 672
2016-05-17 23:49:29,355 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-17 23:49:29,355 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-17 23:49:29,367 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E3A33DF17E2D4B2DA69AFCFBE8023130, ordinal: 1
2016-05-17 23:49:29,369 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lhs*rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num2']]
2016-05-17 23:49:29,369 INFO  hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit"]
2016-05-17 23:49:29,369 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E3A33DF17E2D4B2DA69AFCFBE8023130, mem on start (mb), free: 159, total: 281, max: 672
2016-05-17 23:49:29,388 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-17 23:49:29,388 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-17 23:49:29,398 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E3A33DF17E2D4B2DA69AFCFBE8023130, mem on close (mb), free: 158, total: 281, max: 672
2016-05-17 23:49:29,436 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit/_temporary
2016-05-17 23:49:29,436 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs]  completed in: 00:00.584
2016-05-17 23:49:29,526 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate
2016-05-17 23:49:29,527 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit
2016-05-17 23:49:29,555 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:29,556 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-17 23:49:29,625 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.061
2016-05-17 23:49:29,627 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 23:49:29,627 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-17 23:49:29,657 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 23:49:29,658 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.3.x/build/classes/test/data/lower+upper.txt"]
2016-05-17 23:49:29,658 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown"]
2016-05-17 23:49:29,660 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-17 23:49:29,660 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-17 23:49:29,660 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-17 23:49:29,661 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...eSortUnknown/none-unknown
2016-05-17 23:49:29,754 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1019221182/.staging/job_local1019221182_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:29,756 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1019221182/.staging/job_local1019221182_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:29,798 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1019221182_0004/job_local1019221182_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:29,798 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1019221182_0004/job_local1019221182_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:29,800 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1019221182_0004
2016-05-17 23:49:29,800 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-17 23:49:29,808 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower+upper.txt
2016-05-17 23:49:29,908 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:29,909 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:29,916 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A2DE287876094C56B345E207A610156D, ordinal: 0
2016-05-17 23:49:29,917 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.3.x/build/classes/test/data/lower+upper.txt"]
2016-05-17 23:49:29,917 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{?}:NONE]]
2016-05-17 23:49:29,918 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A2DE287876094C56B345E207A610156D, mem on start (mb), free: 110, total: 382, max: 672
2016-05-17 23:49:29,919 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A2DE287876094C56B345E207A610156D, mem on close (mb), free: 110, total: 382, max: 672
2016-05-17 23:49:29,941 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-17 23:49:29,941 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-17 23:49:29,949 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E4A43924150444168B2FA6FC2BABC6DB, ordinal: 1
2016-05-17 23:49:29,949 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{?}:NONE]]
2016-05-17 23:49:29,950 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown"]
2016-05-17 23:49:29,950 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E4A43924150444168B2FA6FC2BABC6DB, mem on start (mb), free: 105, total: 382, max: 672
2016-05-17 23:49:29,961 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E4A43924150444168B2FA6FC2BABC6DB, mem on close (mb), free: 104, total: 382, max: 672
2016-05-17 23:49:29,988 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown/_temporary
2016-05-17 23:49:29,988 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.330
2016-05-17 23:49:30,018 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown
2016-05-17 23:49:30,033 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:30,033 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-17 23:49:30,063 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.026
2016-05-17 23:49:30,064 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 23:49:30,064 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-17 23:49:30,083 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 23:49:30,083 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.3.x/build/classes/test/data/apache.10.txt"]
2016-05-17 23:49:30,084 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre"]
2016-05-17 23:49:30,084 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-17 23:49:30,084 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-17 23:49:30,084 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-17 23:49:30,086 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) .../testOOMEPreGroup/oomepre
2016-05-17 23:49:30,167 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1418007561/.staging/job_local1418007561_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:30,168 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1418007561/.staging/job_local1418007561_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:30,215 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1418007561_0005/job_local1418007561_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:30,215 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1418007561_0005/job_local1418007561_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:30,218 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1418007561_0005
2016-05-17 23:49:30,219 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-17 23:49:30,226 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/apache.10.txt
2016-05-17 23:49:30,237 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:30,237 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:30,245 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E7BFCC22B94A43BA97ACBFB93F17E2C8, ordinal: 0
2016-05-17 23:49:30,246 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.3.x/build/classes/test/data/apache.10.txt"]
2016-05-17 23:49:30,246 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre"]
2016-05-17 23:49:30,247 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E7BFCC22B94A43BA97ACBFB93F17E2C8, mem on start (mb), free: 59, total: 382, max: 672
2016-05-17 23:49:30,249 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-17 23:49:30,252 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E7BFCC22B94A43BA97ACBFB93F17E2C8, mem on close (mb), free: 59, total: 382, max: 672
2016-05-17 23:49:30,254 WARN  mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local1418007561_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-17 23:49:30,260 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [test] hadoop job job_local1418007561_0005 state at FAILED
2016-05-17 23:49:30,260 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [test] failure info: NA
2016-05-17 23:49:30,261 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [test] task completion events identify failed tasks
2016-05-17 23:49:30,261 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [test] task completion events count: 0
2016-05-17 23:49:30,262 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopping all jobs
2016-05-17 23:49:30,262 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopping: (1/1) .../testOOMEPreGroup/oomepre
2016-05-17 23:49:30,263 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopped all jobs
2016-05-17 23:49:30,263 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre/_temporary
2016-05-17 23:49:30,264 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.180
exception = cascading.flow.FlowException: local step failed: (1/1) .../testOOMEPreGroup/oomepre
2016-05-17 23:49:30,264 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre
2016-05-17 23:49:30,282 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:30,283 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-17 23:49:30,343 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.057
2016-05-17 23:49:30,344 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 23:49:30,344 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-17 23:49:30,356 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 23:49:30,357 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.3.x/build/classes/test/data/lower+upper.txt"]
2016-05-17 23:49:30,357 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCopy/copy"]
2016-05-17 23:49:30,358 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-17 23:49:30,359 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-17 23:49:30,359 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-17 23:49:30,360 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...pesplatform/testCopy/copy
2016-05-17 23:49:30,429 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity799381287/.staging/job_local799381287_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:30,430 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity799381287/.staging/job_local799381287_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:30,478 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local799381287_0006/job_local799381287_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:30,479 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local799381287_0006/job_local799381287_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:30,479 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local799381287_0006
2016-05-17 23:49:30,480 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-17 23:49:30,491 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower+upper.txt
2016-05-17 23:49:30,500 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:30,500 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:30,509 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BA2661005DF14407918765C6E3FA43CA, ordinal: 0
2016-05-17 23:49:30,510 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.3.x/build/classes/test/data/lower+upper.txt"]
2016-05-17 23:49:30,510 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCopy/copy"]
2016-05-17 23:49:30,510 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BA2661005DF14407918765C6E3FA43CA, mem on start (mb), free: 247, total: 498, max: 672
2016-05-17 23:49:30,512 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BA2661005DF14407918765C6E3FA43CA, mem on close (mb), free: 247, total: 498, max: 672
2016-05-17 23:49:30,535 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCopy/copy/_temporary
2016-05-17 23:49:30,536 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.179
2016-05-17 23:49:30,559 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testCopy/copy
2016-05-17 23:49:30,580 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:30,581 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-17 23:49:30,612 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.027
2016-05-17 23:49:30,613 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 23:49:30,613 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-17 23:49:30,628 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 23:49:30,628 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower+upper.txt"]
2016-05-17 23:49:30,628 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  sink: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace"]
2016-05-17 23:49:30,628 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-17 23:49:30,628 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-17 23:49:30,629 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-17 23:49:30,629 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...wnReplace/unknown-replace
2016-05-17 23:49:30,684 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity635704015/.staging/job_local635704015_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:30,684 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity635704015/.staging/job_local635704015_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:30,721 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local635704015_0007/job_local635704015_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:30,721 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local635704015_0007/job_local635704015_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:30,722 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local635704015_0007
2016-05-17 23:49:30,722 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-17 23:49:30,729 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower+upper.txt
2016-05-17 23:49:30,737 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:30,737 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:30,747 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B51CF7986052478DACEE4FE9F41D3E7A, ordinal: 0
2016-05-17 23:49:30,748 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower+upper.txt"]
2016-05-17 23:49:30,748 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace"]
2016-05-17 23:49:30,748 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B51CF7986052478DACEE4FE9F41D3E7A, mem on start (mb), free: 197, total: 498, max: 672
2016-05-17 23:49:30,750 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B51CF7986052478DACEE4FE9F41D3E7A, mem on close (mb), free: 197, total: 498, max: 672
2016-05-17 23:49:30,766 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace/_temporary
2016-05-17 23:49:30,766 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.137
2016-05-17 23:49:30,814 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace
2016-05-17 23:49:30,833 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:30,834 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-17 23:49:30,871 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.033
2016-05-17 23:49:30,872 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 23:49:30,872 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-17 23:49:30,885 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 23:49:30,885 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lhs.txt"]
2016-05-17 23:49:30,886 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand"]
2016-05-17 23:49:30,886 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-17 23:49:30,886 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-17 23:49:30,887 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-17 23:49:30,888 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...egression/complexlogicand
2016-05-17 23:49:30,944 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1788538071/.staging/job_local1788538071_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:30,944 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1788538071/.staging/job_local1788538071_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:30,988 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1788538071_0008/job_local1788538071_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:30,988 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1788538071_0008/job_local1788538071_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:30,990 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1788538071_0008
2016-05-17 23:49:30,990 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-17 23:49:30,996 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lhs.txt
2016-05-17 23:49:31,003 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:31,004 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:31,012 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C71E6DC4E6C64A6381A9E56D70381C6E, ordinal: 0
2016-05-17 23:49:31,013 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lhs.txt"]
2016-05-17 23:49:31,013 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand"]
2016-05-17 23:49:31,014 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C71E6DC4E6C64A6381A9E56D70381C6E, mem on start (mb), free: 139, total: 498, max: 672
2016-05-17 23:49:31,016 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C71E6DC4E6C64A6381A9E56D70381C6E, mem on close (mb), free: 139, total: 498, max: 672
2016-05-17 23:49:31,036 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand/_temporary
2016-05-17 23:49:31,036 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.150
2016-05-17 23:49:31,061 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand
2016-05-17 23:49:31,083 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:31,083 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-17 23:49:31,123 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.034
2016-05-17 23:49:31,126 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 23:49:31,126 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-17 23:49:31,145 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 23:49:31,145 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lhs.txt"]
2016-05-17 23:49:31,146 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor"]
2016-05-17 23:49:31,146 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-17 23:49:31,146 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-17 23:49:31,146 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-17 23:49:31,147 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...egression/complexlogicxor
2016-05-17 23:49:31,214 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1716308937/.staging/job_local1716308937_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:31,215 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1716308937/.staging/job_local1716308937_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:31,263 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1716308937_0009/job_local1716308937_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:31,263 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1716308937_0009/job_local1716308937_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:31,265 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1716308937_0009
2016-05-17 23:49:31,265 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-17 23:49:31,270 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lhs.txt
2016-05-17 23:49:31,278 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:31,278 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:31,286 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BBF0111F78204725A3DB1A4C9AB3B455, ordinal: 0
2016-05-17 23:49:31,287 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lhs.txt"]
2016-05-17 23:49:31,287 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor"]
2016-05-17 23:49:31,288 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BBF0111F78204725A3DB1A4C9AB3B455, mem on start (mb), free: 90, total: 498, max: 672
2016-05-17 23:49:31,290 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BBF0111F78204725A3DB1A4C9AB3B455, mem on close (mb), free: 90, total: 498, max: 672
2016-05-17 23:49:31,310 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor/_temporary
2016-05-17 23:49:31,311 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.165
2016-05-17 23:49:31,340 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor
2016-05-17 23:49:31,360 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:31,360 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-17 23:49:31,420 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.055
2016-05-17 23:49:31,421 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 23:49:31,421 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-17 23:49:31,442 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting
2016-05-17 23:49:31,442 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/upper.txt"]
2016-05-17 23:49:31,443 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower.txt"]
2016-05-17 23:49:31,443 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper]  sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost"]
2016-05-17 23:49:31,443 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper]  parallel execution of steps is enabled: false
2016-05-17 23:49:31,443 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper]  executing total steps: 1
2016-05-17 23:49:31,443 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper]  allocating management threads: 1
2016-05-17 23:49:31,444 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting step: (1/1) ...estOOMEPostGroup/oomepost
2016-05-17 23:49:31,540 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity530477144/.staging/job_local530477144_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:31,543 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity530477144/.staging/job_local530477144_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:31,578 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local530477144_0010/job_local530477144_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:31,578 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local530477144_0010/job_local530477144_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:31,579 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] submitted hadoop job: job_local530477144_0010
2016-05-17 23:49:31,580 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] tracking url: http://localhost:8080/
2016-05-17 23:49:31,588 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/upper.txt
2016-05-17 23:49:31,604 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:31,604 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:31,613 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F98685EF9A694F4DAF62DF486339F308, ordinal: 0
2016-05-17 23:49:31,614 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/upper.txt"]
2016-05-17 23:49:31,614 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-17 23:49:31,614 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F98685EF9A694F4DAF62DF486339F308, mem on start (mb), free: 168, total: 498, max: 672
2016-05-17 23:49:31,615 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F98685EF9A694F4DAF62DF486339F308, mem on close (mb), free: 168, total: 498, max: 672
2016-05-17 23:49:31,623 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower.txt
2016-05-17 23:49:31,659 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:31,659 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:31,666 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F98685EF9A694F4DAF62DF486339F308, ordinal: 0
2016-05-17 23:49:31,667 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower.txt"]
2016-05-17 23:49:31,667 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-17 23:49:31,667 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F98685EF9A694F4DAF62DF486339F308, mem on start (mb), free: 65, total: 498, max: 672
2016-05-17 23:49:31,669 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F98685EF9A694F4DAF62DF486339F308, mem on close (mb), free: 65, total: 498, max: 672
2016-05-17 23:49:31,689 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-17 23:49:31,689 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-17 23:49:31,696 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D23830AB2DB8487EA8C7A55EECDE9DBD, ordinal: 1
2016-05-17 23:49:31,696 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-17 23:49:31,697 INFO  hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost"]
2016-05-17 23:49:31,697 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D23830AB2DB8487EA8C7A55EECDE9DBD, mem on start (mb), free: 57, total: 498, max: 672
2016-05-17 23:49:31,705 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-17 23:49:31,705 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-17 23:49:31,706 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-17 23:49:31,706 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D23830AB2DB8487EA8C7A55EECDE9DBD, mem on close (mb), free: 56, total: 498, max: 672
2016-05-17 23:49:31,709 WARN  mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local530477144_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-17 23:49:31,709 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] hadoop job job_local530477144_0010 state at FAILED
2016-05-17 23:49:31,712 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] failure info: NA
2016-05-17 23:49:31,712 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] task completion events identify failed tasks
2016-05-17 23:49:31,712 WARN  flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] task completion events count: 0
2016-05-17 23:49:31,720 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] stopping all jobs
2016-05-17 23:49:31,720 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] stopping: (1/1) ...estOOMEPostGroup/oomepost
2016-05-17 23:49:31,721 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] stopped all jobs
2016-05-17 23:49:31,721 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost/_temporary
2016-05-17 23:49:31,722 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper]  completed in: 00:00.279
exception = cascading.flow.FlowException: local step failed: (1/1) ...estOOMEPostGroup/oomepost
2016-05-17 23:49:31,722 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost
2016-05-17 23:49:31,753 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:31,755 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-17 23:49:31,791 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.033
2016-05-17 23:49:31,792 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 23:49:31,792 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-17 23:49:31,805 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 23:49:31,808 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.3.x/build/classes/test/data/apache.10.txt"]
2016-05-17 23:49:31,808 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified"]
2016-05-17 23:49:31,808 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-17 23:49:31,809 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-17 23:49:31,809 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-17 23:49:31,810 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...Modified/lasteachmodified
2016-05-17 23:49:31,871 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1615900236/.staging/job_local1615900236_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:31,872 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1615900236/.staging/job_local1615900236_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:31,922 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1615900236_0011/job_local1615900236_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:31,922 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1615900236_0011/job_local1615900236_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:31,923 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1615900236_0011
2016-05-17 23:49:31,924 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-17 23:49:31,929 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/apache.10.txt
2016-05-17 23:49:31,946 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:31,946 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:31,953 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CE0DC9F26E894734BBA346C2DDD593A5, ordinal: 0
2016-05-17 23:49:31,953 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.3.x/build/classes/test/data/apache.10.txt"]
2016-05-17 23:49:31,953 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'insert']]
2016-05-17 23:49:31,954 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CE0DC9F26E894734BBA346C2DDD593A5, mem on start (mb), free: 137, total: 490, max: 672
2016-05-17 23:49:31,956 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CE0DC9F26E894734BBA346C2DDD593A5, mem on close (mb), free: 137, total: 490, max: 672
2016-05-17 23:49:31,980 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-17 23:49:31,980 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-17 23:49:31,986 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B65879736A8843818929626CCB85D8FB, ordinal: 1
2016-05-17 23:49:31,987 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'insert']]
2016-05-17 23:49:31,987 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified"]
2016-05-17 23:49:31,987 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B65879736A8843818929626CCB85D8FB, mem on start (mb), free: 129, total: 490, max: 672
2016-05-17 23:49:31,999 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B65879736A8843818929626CCB85D8FB, mem on close (mb), free: 128, total: 490, max: 672
2016-05-17 23:49:32,023 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified/_temporary
2016-05-17 23:49:32,023 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.218
2016-05-17 23:49:32,046 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified
2016-05-17 23:49:32,063 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:32,063 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-17 23:49:32,094 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.028
2016-05-17 23:49:32,095 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 23:49:32,095 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-17 23:49:32,104 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 23:49:32,104 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.3.x/build/classes/test/data/lower+upper.txt"]
2016-05-17 23:49:32,104 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknown/unknown"]
2016-05-17 23:49:32,105 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-17 23:49:32,105 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-17 23:49:32,105 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-17 23:49:32,106 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...tform/testUnknown/unknown
2016-05-17 23:49:32,169 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1034292278/.staging/job_local1034292278_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:32,169 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1034292278/.staging/job_local1034292278_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:32,209 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1034292278_0012/job_local1034292278_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:32,209 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1034292278_0012/job_local1034292278_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:32,211 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1034292278_0012
2016-05-17 23:49:32,211 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-17 23:49:32,215 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower+upper.txt
2016-05-17 23:49:32,221 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:32,221 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:32,229 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A9B6F5A7FBFF4F258F711D0021383057, ordinal: 0
2016-05-17 23:49:32,230 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.3.x/build/classes/test/data/lower+upper.txt"]
2016-05-17 23:49:32,230 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknown/unknown"]
2016-05-17 23:49:32,230 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A9B6F5A7FBFF4F258F711D0021383057, mem on start (mb), free: 73, total: 490, max: 672
2016-05-17 23:49:32,232 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A9B6F5A7FBFF4F258F711D0021383057, mem on close (mb), free: 73, total: 490, max: 672
2016-05-17 23:49:32,254 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknown/unknown/_temporary
2016-05-17 23:49:32,255 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.150
2016-05-17 23:49:32,282 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testUnknown/unknown
2016-05-17 23:49:32,299 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:32,300 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-17 23:49:32,331 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.028
2016-05-17 23:49:32,332 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 23:49:32,332 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-17 23:49:32,347 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 23:49:32,347 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.3.x/build/classes/test/data/critics.txt"]
2016-05-17 23:49:32,347 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth"]
2016-05-17 23:49:32,347 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-17 23:49:32,347 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-17 23:49:32,348 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-17 23:49:32,348 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...orm/testVarWidth/varwidth
2016-05-17 23:49:32,415 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1608735912/.staging/job_local1608735912_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:32,415 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1608735912/.staging/job_local1608735912_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:32,446 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1608735912_0013/job_local1608735912_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:32,446 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1608735912_0013/job_local1608735912_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:32,447 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1608735912_0013
2016-05-17 23:49:32,447 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-17 23:49:32,452 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/critics.txt
2016-05-17 23:49:32,458 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:32,458 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:32,464 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FB52190F464544708F60905B8675C619, ordinal: 0
2016-05-17 23:49:32,465 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.3.x/build/classes/test/data/critics.txt"]
2016-05-17 23:49:32,465 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth"]
2016-05-17 23:49:32,466 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FB52190F464544708F60905B8675C619, mem on start (mb), free: 237, total: 485, max: 672
2016-05-17 23:49:32,468 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FB52190F464544708F60905B8675C619, mem on close (mb), free: 237, total: 485, max: 672
2016-05-17 23:49:32,482 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth/_temporary
2016-05-17 23:49:32,482 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.134
2016-05-17 23:49:32,509 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth
2016-05-17 23:49:32,524 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:32,524 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-17 23:49:32,527 WARN  planner.FlowPlanner (FlowPlanner.java:verifyPipeAssemblyEndPoints(464)) - duplicate head name found, not an error but heads should have unique names: 'test'
2016-05-17 23:49:32,529 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testDupeHeadNames/unknown
2016-05-17 23:49:32,551 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:32,552 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-17 23:49:32,555 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testDupeTailNames/unknown
2016-05-17 23:49:32,850 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:32,850 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-17 23:49:35,724 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:02.853
2016-05-17 23:49:35,730 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 23:49:35,731 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-17 23:49:35,940 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] starting
2016-05-17 23:49:35,940 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline]  source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/apache.200.txt"]
2016-05-17 23:49:35,940 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline"]
2016-05-17 23:49:35,940 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline]  parallel execution of steps is enabled: false
2016-05-17 23:49:35,940 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline]  executing total steps: 1
2016-05-17 23:49:35,940 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline]  allocating management threads: 1
2016-05-17 23:49:35,941 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] starting step: (1/1) ...tDeepPipeline/deeppipline
2016-05-17 23:49:35,999 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity981894623/.staging/job_local981894623_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:36,000 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity981894623/.staging/job_local981894623_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:36,033 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local981894623_0014/job_local981894623_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:36,033 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local981894623_0014/job_local981894623_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:36,034 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] submitted hadoop job: job_local981894623_0014
2016-05-17 23:49:36,034 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] tracking url: http://localhost:8080/
2016-05-17 23:49:36,038 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/apache.200.txt
2016-05-17 23:49:36,053 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:36,053 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:36,174 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D8409B60F02D4CA09DE2749FB70C29EA, ordinal: 0
2016-05-17 23:49:36,198 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/apache.200.txt"]
2016-05-17 23:49:36,198 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(pipeline)[by:[{1}:'hash']]
2016-05-17 23:49:36,198 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D8409B60F02D4CA09DE2749FB70C29EA, mem on start (mb), free: 125, total: 493, max: 672
2016-05-17 23:49:36,404 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D8409B60F02D4CA09DE2749FB70C29EA, mem on close (mb), free: 116, total: 493, max: 672
2016-05-17 23:49:36,443 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-17 23:49:36,443 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-17 23:49:36,522 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B1210A624A374CCE87BA054B8E60E62E, ordinal: 1
2016-05-17 23:49:36,538 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(pipeline)[by:[{1}:'hash']]
2016-05-17 23:49:36,538 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline"]
2016-05-17 23:49:36,539 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B1210A624A374CCE87BA054B8E60E62E, mem on start (mb), free: 101, total: 493, max: 672
2016-05-17 23:49:36,877 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B1210A624A374CCE87BA054B8E60E62E, mem on close (mb), free: 91, total: 493, max: 672
2016-05-17 23:49:36,902 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline/_temporary
2016-05-17 23:49:36,902 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline]  completed in: 00:00.961
2016-05-17 23:49:36,940 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline
2016-05-17 23:49:36,960 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:36,961 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-17 23:49:36,984 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.018
2016-05-17 23:49:36,984 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 23:49:36,985 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-17 23:49:36,993 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting
2016-05-17 23:49:36,993 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split]  source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower.txt"]
2016-05-17 23:49:36,994 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split]  sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-17 23:49:36,994 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split]  parallel execution of steps is enabled: false
2016-05-17 23:49:36,994 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split]  executing total steps: 1
2016-05-17 23:49:36,994 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split]  allocating management threads: 1
2016-05-17 23:49:36,995 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting step: (1/1) ...litPipe/splitintermediate
2016-05-17 23:49:37,061 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity2043020711/.staging/job_local2043020711_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:37,062 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity2043020711/.staging/job_local2043020711_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:37,094 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2043020711_0015/job_local2043020711_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:37,094 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2043020711_0015/job_local2043020711_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:37,095 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split] submitted hadoop job: job_local2043020711_0015
2016-05-17 23:49:37,096 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split] tracking url: http://localhost:8080/
2016-05-17 23:49:37,101 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower.txt
2016-05-17 23:49:37,107 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:37,107 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:37,111 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E121696FA12E4A7590077CF9217473AE, ordinal: 0
2016-05-17 23:49:37,111 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower.txt"]
2016-05-17 23:49:37,111 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-17 23:49:37,112 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E121696FA12E4A7590077CF9217473AE, mem on start (mb), free: 248, total: 482, max: 672
2016-05-17 23:49:37,113 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E121696FA12E4A7590077CF9217473AE, mem on close (mb), free: 248, total: 482, max: 672
2016-05-17 23:49:37,129 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate/_temporary
2016-05-17 23:49:37,130 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [split]  completed in: 00:00.136
2016-05-17 23:49:37,142 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:37,142 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-17 23:49:37,178 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.033
2016-05-17 23:49:37,179 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 23:49:37,179 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-17 23:49:37,191 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] starting
2016-05-17 23:49:37,192 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-17 23:49:37,192 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs]  sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit"]
2016-05-17 23:49:37,192 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs]  parallel execution of steps is enabled: false
2016-05-17 23:49:37,192 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs]  executing total steps: 1
2016-05-17 23:49:37,193 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs]  allocating management threads: 1
2016-05-17 23:49:37,195 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] starting step: (1/1) ...pBySplitPipe/groupbysplit
2016-05-17 23:49:37,262 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1758800620/.staging/job_local1758800620_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:37,264 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1758800620/.staging/job_local1758800620_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:37,298 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1758800620_0016/job_local1758800620_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:37,298 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1758800620_0016/job_local1758800620_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:37,299 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] submitted hadoop job: job_local1758800620_0016
2016-05-17 23:49:37,300 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] tracking url: http://localhost:8080/
2016-05-17 23:49:37,305 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate/part-00000
2016-05-17 23:49:37,318 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:37,319 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:37,324 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FD0C450704204B5FB3143DF79A0D7A4F, ordinal: 0
2016-05-17 23:49:37,325 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-17 23:49:37,325 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2016-05-17 23:49:37,325 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FD0C450704204B5FB3143DF79A0D7A4F, mem on start (mb), free: 98, total: 482, max: 672
2016-05-17 23:49:37,327 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FD0C450704204B5FB3143DF79A0D7A4F, mem on close (mb), free: 98, total: 482, max: 672
2016-05-17 23:49:37,341 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-17 23:49:37,341 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-17 23:49:37,344 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: EECFFA5116494E3BB1545C18D8FB6542, ordinal: 1
2016-05-17 23:49:37,344 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2016-05-17 23:49:37,345 INFO  hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit"]
2016-05-17 23:49:37,345 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: EECFFA5116494E3BB1545C18D8FB6542, mem on start (mb), free: 90, total: 482, max: 672
2016-05-17 23:49:37,352 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: EECFFA5116494E3BB1545C18D8FB6542, mem on close (mb), free: 89, total: 482, max: 672
2016-05-17 23:49:37,367 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit/_temporary
2016-05-17 23:49:37,367 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs]  completed in: 00:00.176
2016-05-17 23:49:37,412 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate
2016-05-17 23:49:37,412 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit
2016-05-17 23:49:37,424 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:37,425 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-17 23:49:37,469 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.039
2016-05-17 23:49:37,470 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-17 23:49:37,471 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-17 23:49:37,497 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] starting
2016-05-17 23:49:37,497 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.3.x/build/classes/test/data/lower+upper.txt"]
2016-05-17 23:49:37,497 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars"]
2016-05-17 23:49:37,497 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...]  parallel execution of steps is enabled: false
2016-05-17 23:49:37,497 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...]  executing total steps: 2
2016-05-17 23:49:37,497 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...]  allocating management threads: 1
2016-05-17 23:49:37,499 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] starting step: (1/2)
2016-05-17 23:49:37,566 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1248213076/.staging/job_local1248213076_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:37,567 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1248213076/.staging/job_local1248213076_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:37,601 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1248213076_0017/job_local1248213076_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:37,601 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1248213076_0017/job_local1248213076_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:37,602 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] submitted hadoop job: job_local1248213076_0017
2016-05-17 23:49:37,602 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] tracking url: http://localhost:8080/
2016-05-17 23:49:37,606 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower+upper.txt
2016-05-17 23:49:37,620 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:37,620 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:37,624 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: EAD23E8E3F304595BF6364E5834F4F9F, ordinal: 0
2016-05-17 23:49:37,625 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.3.x/build/classes/test/data/lower+upper.txt"]
2016-05-17 23:49:37,625 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(**&%&%bar:bar@foo://blah/	(*(**^**&%&%^@#@&&() :::: ///\\ 	 illegal chars in it)[by:[{1}:0]]
2016-05-17 23:49:37,625 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EAD23E8E3F304595BF6364E5834F4F9F, mem on start (mb), free: 162, total: 493, max: 672
2016-05-17 23:49:37,627 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EAD23E8E3F304595BF6364E5834F4F9F, mem on close (mb), free: 162, total: 493, max: 672
2016-05-17 23:49:37,639 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-17 23:49:37,640 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-17 23:49:37,644 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A7F587406A974FC5AE3A58DD6C29F78D, ordinal: 1
2016-05-17 23:49:37,644 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(**&%&%bar:bar@foo://blah/	(*(**^**&%&%^@#@&&() :::: ///\\ 	 illegal chars in it)[by:[{1}:0]]
2016-05-17 23:49:37,644 INFO  hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[[UNKNOWN]->[ALL]]"][2446853595/__&%&%bar:bar@foo:_blah_/]
2016-05-17 23:49:37,645 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A7F587406A974FC5AE3A58DD6C29F78D, mem on start (mb), free: 155, total: 493, max: 672
2016-05-17 23:49:37,663 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A7F587406A974FC5AE3A58DD6C29F78D, mem on close (mb), free: 153, total: 493, max: 672
2016-05-17 23:49:37,682 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] starting step: (2/2) ...sInTempFiles/illegalchars
2016-05-17 23:49:37,739 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1603231305/.staging/job_local1603231305_0018/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:37,740 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1603231305/.staging/job_local1603231305_0018/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:37,771 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1603231305_0018/job_local1603231305_0018.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:37,772 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1603231305_0018/job_local1603231305_0018.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:37,773 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] submitted hadoop job: job_local1603231305_0018
2016-05-17 23:49:37,774 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] tracking url: http://localhost:8080/
2016-05-17 23:49:37,778 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/2446853595____bar_bar_foo__blah__DDA3E9E1AAC74DDB9B183B0EE3086594/part-00000
2016-05-17 23:49:37,804 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:37,805 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:37,809 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CBF388CA0F6A454297442AA6EE3FE967, ordinal: 0
2016-05-17 23:49:37,809 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[[UNKNOWN]->[ALL]]"][2446853595/__&%&%bar:bar@foo:_blah_/]
2016-05-17 23:49:37,810 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(**&%&%bar:bar@foo://blah/	(*(**^**&%&%^@#@&&() :::: ///\\ 	 illegal chars in it)[by:[{1}:0]]
2016-05-17 23:49:37,810 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CBF388CA0F6A454297442AA6EE3FE967, mem on start (mb), free: 164, total: 480, max: 672
2016-05-17 23:49:37,812 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CBF388CA0F6A454297442AA6EE3FE967, mem on close (mb), free: 164, total: 480, max: 672
2016-05-17 23:49:37,827 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-17 23:49:37,827 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-17 23:49:37,832 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B0BA7689C5E54A108D82FD7A5CC1F1D2, ordinal: 1
2016-05-17 23:49:37,832 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(**&%&%bar:bar@foo://blah/	(*(**^**&%&%^@#@&&() :::: ///\\ 	 illegal chars in it)[by:[{1}:0]]
2016-05-17 23:49:37,832 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars"]
2016-05-17 23:49:37,833 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B0BA7689C5E54A108D82FD7A5CC1F1D2, mem on start (mb), free: 157, total: 480, max: 672
2016-05-17 23:49:37,841 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B0BA7689C5E54A108D82FD7A5CC1F1D2, mem on close (mb), free: 155, total: 480, max: 672
2016-05-17 23:49:37,860 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars/_temporary
2016-05-17 23:49:37,861 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...]  completed in: 00:00.362
2016-05-17 23:49:37,881 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars
2016-05-17 23:49:37,897 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:49:37,898 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-17 23:49:37,922 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.019
2016-05-17 23:49:37,922 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 23:49:37,923 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-17 23:49:37,932 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-17 23:49:37,932 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.3.x/build/classes/test/data/lower+upper.txt"]
2016-05-17 23:49:37,932 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic"]
2016-05-17 23:49:37,933 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-17 23:49:37,933 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-17 23:49:37,933 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-17 23:49:37,934 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...-unknown-nondeterministic
2016-05-17 23:49:37,987 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1194008995/.staging/job_local1194008995_0019/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:37,987 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/tmp/cascading/staging/teamcity1194008995/.staging/job_local1194008995_0019/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:38,020 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1194008995_0019/job_local1194008995_0019.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2016-05-17 23:49:38,020 WARN  conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1194008995_0019/job_local1194008995_0019.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2016-05-17 23:49:38,021 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1194008995_0019
2016-05-17 23:49:38,021 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-17 23:49:38,024 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/classes/test/data/lower+upper.txt
2016-05-17 23:49:38,030 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:49:38,030 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:49:38,034 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E6FA687106FD4F5DB6BF56F14CA5CEDD, ordinal: 0
2016-05-17 23:49:38,035 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.3.x/build/classes/test/data/lower+upper.txt"]
2016-05-17 23:49:38,035 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic"]
2016-05-17 23:49:38,035 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E6FA687106FD4F5DB6BF56F14CA5CEDD, mem on start (mb), free: 105, total: 480, max: 672
2016-05-17 23:49:38,038 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E6FA687106FD4F5DB6BF56F14CA5CEDD, mem on close (mb), free: 105, total: 480, max: 672
2016-05-17 23:49:38,055 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic/_temporary
2016-05-17 23:49:38,055 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.122
2016-05-17 23:49:38,075 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic

Standard error

rhs-pre: ['num', 'char']
rhs-pre: ['1', 'a']
rhs-post: ['num2']
rhs-post: ['1']
rhs-pre: ['2', 'b']
rhs-post: ['2']
rhs-pre: ['3', 'c']
rhs-post: ['3']
rhs-pre: ['4', 'd']
rhs-post: ['4']
rhs-pre: ['5', 'e']
rhs-post: ['5']
rhs-pre: tuples count: 5
rhs-post: tuples count: 5
cascading.flow.FlowException: local step failed: (1/1) .../testOOMEPreGroup/oomepre
	at cascading.flow.planner.FlowStepJob.blockOnJob(FlowStepJob.java:293)
	at cascading.flow.planner.FlowStepJob.start(FlowStepJob.java:184)
	at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:146)
	at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:48)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
cascading.flow.FlowException: local step failed: (1/1) ...estOOMEPostGroup/oomepost
	at cascading.flow.planner.FlowStepJob.blockOnJob(FlowStepJob.java:293)
	at cascading.flow.planner.FlowStepJob.start(FlowStepJob.java:184)
	at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:146)
	at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:48)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)