2016-05-18 02:13:34,257 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 02:13:34,279 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.RegressionPipesPlatformTest, with platform: hadoop2-mr1
2016-05-18 02:13:34,304 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-05-18 02:13:34,810 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-05-18 02:13:35,002 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 02:13:35,158 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:35,160 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:35,269 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: E0444B944D534AA1AADBE2780CE9DDCA
2016-05-18 02:13:35,424 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.095
2016-05-18 02:13:35,427 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 02:13:35,427 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:35,587 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 02:13:35,590 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 02:13:35,591 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lhs.txt"]
2016-05-18 02:13:35,592 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor"]
2016-05-18 02:13:35,592 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 02:13:35,594 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 02:13:35,594 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 02:13:35,595 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...regression/complexlogicor
2016-05-18 02:13:36,087 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1831111092/.staging/job_local1831111092_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:36,095 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1831111092/.staging/job_local1831111092_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:36,258 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1831111092_0001/job_local1831111092_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:36,262 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1831111092_0001/job_local1831111092_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:36,270 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1831111092_0001
2016-05-18 02:13:36,270 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 02:13:36,350 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lhs.txt
2016-05-18 02:13:36,368 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:36,369 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:36,384 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DEA09C9538AA45A59391889AB758F99F, ordinal: 0
2016-05-18 02:13:36,416 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lhs.txt"]
2016-05-18 02:13:36,417 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor"]
2016-05-18 02:13:36,418 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DEA09C9538AA45A59391889AB758F99F, mem on start (mb), free: 243, total: 281, max: 672
2016-05-18 02:13:36,430 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DEA09C9538AA45A59391889AB758F99F, mem on close (mb), free: 242, total: 281, max: 672
2016-05-18 02:13:36,471 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor/_temporary
2016-05-18 02:13:36,471 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.879
2016-05-18 02:13:36,510 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor
2016-05-18 02:13:36,545 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:36,546 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:36,609 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.050
2016-05-18 02:13:36,610 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 02:13:36,610 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:36,631 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting
2016-05-18 02:13:36,632 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-05-18 02:13:36,632 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-18 02:13:36,632 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] parallel execution of steps is enabled: false
2016-05-18 02:13:36,632 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] executing total steps: 1
2016-05-18 02:13:36,633 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] allocating management threads: 1
2016-05-18 02:13:36,633 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting step: (1/1) ...oupSplitPipe/intermediate
2016-05-18 02:13:36,711 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1929911284/.staging/job_local1929911284_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:36,712 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1929911284/.staging/job_local1929911284_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:36,786 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1929911284_0002/job_local1929911284_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:36,788 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1929911284_0002/job_local1929911284_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:36,789 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] submitted hadoop job: job_local1929911284_0002
2016-05-18 02:13:36,790 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] tracking url: http://localhost:8080/
2016-05-18 02:13:36,799 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt
2016-05-18 02:13:36,809 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:36,810 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:36,822 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D6B16FBF61EC4E0A9821971918C132D1, ordinal: 0
2016-05-18 02:13:36,823 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-05-18 02:13:36,824 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-18 02:13:36,824 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D6B16FBF61EC4E0A9821971918C132D1, mem on start (mb), free: 197, total: 281, max: 672
2016-05-18 02:13:36,826 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D6B16FBF61EC4E0A9821971918C132D1, mem on close (mb), free: 197, total: 281, max: 672
2016-05-18 02:13:36,845 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate/_temporary
2016-05-18 02:13:36,845 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] completed in: 00:00.213
2016-05-18 02:13:36,904 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:36,905 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:36,985 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.066
2016-05-18 02:13:36,987 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 02:13:36,987 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:37,041 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] starting
2016-05-18 02:13:37,041 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-18 02:13:37,042 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit"]
2016-05-18 02:13:37,042 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] parallel execution of steps is enabled: false
2016-05-18 02:13:37,042 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] executing total steps: 1
2016-05-18 02:13:37,043 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] allocating management threads: 1
2016-05-18 02:13:37,043 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] starting step: (1/1) ...oupSplitPipe/cogroupsplit
2016-05-18 02:13:37,169 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1737573631/.staging/job_local1737573631_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:37,172 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1737573631/.staging/job_local1737573631_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:37,245 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1737573631_0003/job_local1737573631_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:37,248 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1737573631_0003/job_local1737573631_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:37,249 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] submitted hadoop job: job_local1737573631_0003
2016-05-18 02:13:37,249 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] tracking url: http://localhost:8080/
2016-05-18 02:13:37,260 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate/part-00000
2016-05-18 02:13:37,427 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:37,427 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:37,443 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AB3D2A0965BA419AA2DAE795B991076A, ordinal: 0
2016-05-18 02:13:37,450 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-05-18 02:13:37,450 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lhs*rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num2']]
2016-05-18 02:13:37,450 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AB3D2A0965BA419AA2DAE795B991076A, mem on start (mb), free: 168, total: 281, max: 672
2016-05-18 02:13:37,455 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AB3D2A0965BA419AA2DAE795B991076A, mem on close (mb), free: 168, total: 281, max: 672
2016-05-18 02:13:37,576 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 02:13:37,576 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 02:13:37,594 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: FCB6518873D94200BDB3F6631D6E6F01, ordinal: 1
2016-05-18 02:13:37,598 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lhs*rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num2']]
2016-05-18 02:13:37,598 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit"]
2016-05-18 02:13:37,599 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FCB6518873D94200BDB3F6631D6E6F01, mem on start (mb), free: 158, total: 281, max: 672
2016-05-18 02:13:37,618 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 02:13:37,619 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 02:13:37,629 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FCB6518873D94200BDB3F6631D6E6F01, mem on close (mb), free: 156, total: 281, max: 672
2016-05-18 02:13:37,659 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit/_temporary
2016-05-18 02:13:37,660 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs*rhs] completed in: 00:00.618
2016-05-18 02:13:37,724 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit
2016-05-18 02:13:37,724 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate
2016-05-18 02:13:37,744 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:37,745 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:37,796 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.045
2016-05-18 02:13:37,798 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 02:13:37,798 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:37,820 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 02:13:37,820 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.4.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 02:13:37,821 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown"]
2016-05-18 02:13:37,822 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 02:13:37,822 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 02:13:37,822 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 02:13:37,824 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...eSortUnknown/none-unknown
2016-05-18 02:13:37,913 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity231740733/.staging/job_local231740733_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:37,916 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity231740733/.staging/job_local231740733_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:37,979 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local231740733_0004/job_local231740733_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:37,981 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local231740733_0004/job_local231740733_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:37,981 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local231740733_0004
2016-05-18 02:13:37,982 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 02:13:37,995 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower+upper.txt
2016-05-18 02:13:38,106 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:38,107 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:38,115 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DDEEDBA4070245789FDA529AFC698B8F, ordinal: 0
2016-05-18 02:13:38,116 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.4.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 02:13:38,116 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{?}:NONE]]
2016-05-18 02:13:38,117 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DDEEDBA4070245789FDA529AFC698B8F, mem on start (mb), free: 106, total: 382, max: 672
2016-05-18 02:13:38,119 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DDEEDBA4070245789FDA529AFC698B8F, mem on close (mb), free: 106, total: 382, max: 672
2016-05-18 02:13:38,141 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 02:13:38,141 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 02:13:38,149 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B2EC86E494424E438993C60E60080ABF, ordinal: 1
2016-05-18 02:13:38,149 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{?}:NONE]]
2016-05-18 02:13:38,150 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown"]
2016-05-18 02:13:38,150 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B2EC86E494424E438993C60E60080ABF, mem on start (mb), free: 101, total: 382, max: 672
2016-05-18 02:13:38,162 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B2EC86E494424E438993C60E60080ABF, mem on close (mb), free: 100, total: 382, max: 672
2016-05-18 02:13:38,191 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown/_temporary
2016-05-18 02:13:38,191 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.370
2016-05-18 02:13:38,216 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown
2016-05-18 02:13:38,231 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:38,232 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:38,268 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.032
2016-05-18 02:13:38,271 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 02:13:38,271 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:38,293 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 02:13:38,293 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.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 02:13:38,293 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre"]
2016-05-18 02:13:38,294 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 02:13:38,294 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 02:13:38,294 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 02:13:38,295 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) .../testOOMEPreGroup/oomepre
2016-05-18 02:13:38,373 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity147047980/.staging/job_local147047980_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:38,373 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity147047980/.staging/job_local147047980_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:38,411 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local147047980_0005/job_local147047980_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:38,412 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local147047980_0005/job_local147047980_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:38,412 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local147047980_0005
2016-05-18 02:13:38,413 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 02:13:38,419 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt
2016-05-18 02:13:38,427 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:38,427 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:38,437 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: EE6099F7F19F4FCDB3500EA2E9141BF2, ordinal: 0
2016-05-18 02:13:38,437 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.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 02:13:38,438 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre"]
2016-05-18 02:13:38,438 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EE6099F7F19F4FCDB3500EA2E9141BF2, mem on start (mb), free: 58, total: 382, max: 672
2016-05-18 02:13:38,440 ERROR element.TrapHandler (TrapHandler.java:handleReThrowableException(115)) - caught OutOfMemoryException, will not trap, rethrowing
java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$1.throwIntentionalException(RegressionPipesPlatformTest.java:583)
at cascading.TestFunction.operate(TestFunction.java:75)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:100)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:40)
at cascading.flow.stream.element.SourceStage.map(SourceStage.java:110)
at cascading.flow.stream.element.SourceStage.run(SourceStage.java:66)
at cascading.flow.hadoop.FlowMapper.run(FlowMapper.java:142)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:430)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:342)
at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:243)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-18 02:13:38,443 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EE6099F7F19F4FCDB3500EA2E9141BF2, mem on close (mb), free: 58, total: 382, max: 672
2016-05-18 02:13:38,444 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local147047980_0005
java.lang.Exception: java.lang.OutOfMemoryError: fake error
at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:522)
Caused by: java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$1.throwIntentionalException(RegressionPipesPlatformTest.java:583)
at cascading.TestFunction.operate(TestFunction.java:75)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:100)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:40)
at cascading.flow.stream.element.SourceStage.map(SourceStage.java:110)
at cascading.flow.stream.element.SourceStage.run(SourceStage.java:66)
at cascading.flow.hadoop.FlowMapper.run(FlowMapper.java:142)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:430)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:342)
at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:243)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-18 02:13:38,446 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [test] hadoop job job_local147047980_0005 state at FAILED
2016-05-18 02:13:38,446 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [test] failure info: NA
2016-05-18 02:13:38,447 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [test] task completion events identify failed tasks
2016-05-18 02:13:38,447 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [test] task completion events count: 0
2016-05-18 02:13:38,447 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopping all jobs
2016-05-18 02:13:38,450 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopping: (1/1) .../testOOMEPreGroup/oomepre
2016-05-18 02:13:38,450 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] stopped all jobs
2016-05-18 02:13:38,451 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre/_temporary
2016-05-18 02:13:38,451 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.157
exception = cascading.flow.FlowException: local step failed: (1/1) .../testOOMEPreGroup/oomepre
2016-05-18 02:13:38,452 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre
2016-05-18 02:13:38,498 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:38,499 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:38,529 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.026
2016-05-18 02:13:38,530 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 02:13:38,530 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:38,540 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 02:13:38,541 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.4.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 02:13:38,541 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCopy/copy"]
2016-05-18 02:13:38,542 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 02:13:38,542 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 02:13:38,543 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 02:13:38,544 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...pesplatform/testCopy/copy
2016-05-18 02:13:38,611 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1781392337/.staging/job_local1781392337_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:38,611 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1781392337/.staging/job_local1781392337_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:38,650 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1781392337_0006/job_local1781392337_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:38,652 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1781392337_0006/job_local1781392337_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:38,653 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1781392337_0006
2016-05-18 02:13:38,654 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 02:13:38,660 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower+upper.txt
2016-05-18 02:13:38,668 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:38,668 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:38,675 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C8F90C8BAEB949E0918F27240B5CB871, ordinal: 0
2016-05-18 02:13:38,676 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.4.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 02:13:38,676 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCopy/copy"]
2016-05-18 02:13:38,677 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C8F90C8BAEB949E0918F27240B5CB871, mem on start (mb), free: 241, total: 498, max: 672
2016-05-18 02:13:38,678 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C8F90C8BAEB949E0918F27240B5CB871, mem on close (mb), free: 241, total: 498, max: 672
2016-05-18 02:13:38,700 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCopy/copy/_temporary
2016-05-18 02:13:38,701 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.160
2016-05-18 02:13:38,724 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testCopy/copy
2016-05-18 02:13:38,740 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:38,741 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:38,774 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.029
2016-05-18 02:13:38,775 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 02:13:38,776 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:38,789 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 02:13:38,789 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 02:13:38,790 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace"]
2016-05-18 02:13:38,790 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 02:13:38,790 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 02:13:38,791 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 02:13:38,792 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...wnReplace/unknown-replace
2016-05-18 02:13:38,847 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1161638502/.staging/job_local1161638502_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:38,848 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1161638502/.staging/job_local1161638502_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:38,886 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1161638502_0007/job_local1161638502_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:38,888 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1161638502_0007/job_local1161638502_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:38,889 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1161638502_0007
2016-05-18 02:13:38,890 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 02:13:38,899 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower+upper.txt
2016-05-18 02:13:38,907 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:38,907 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:38,915 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E55B1441535D4330876D865570082C3E, ordinal: 0
2016-05-18 02:13:38,916 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 02:13:38,916 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace"]
2016-05-18 02:13:38,916 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E55B1441535D4330876D865570082C3E, mem on start (mb), free: 187, total: 498, max: 672
2016-05-18 02:13:38,918 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E55B1441535D4330876D865570082C3E, mem on close (mb), free: 187, total: 498, max: 672
2016-05-18 02:13:38,939 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace/_temporary
2016-05-18 02:13:38,940 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.150
2016-05-18 02:13:38,996 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace
2016-05-18 02:13:39,020 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:39,021 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:39,052 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.027
2016-05-18 02:13:39,053 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 02:13:39,053 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:39,066 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 02:13:39,067 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lhs.txt"]
2016-05-18 02:13:39,067 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand"]
2016-05-18 02:13:39,067 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 02:13:39,067 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 02:13:39,068 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 02:13:39,068 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...egression/complexlogicand
2016-05-18 02:13:39,133 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1701685966/.staging/job_local1701685966_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:39,134 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1701685966/.staging/job_local1701685966_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:39,183 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1701685966_0008/job_local1701685966_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:39,184 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1701685966_0008/job_local1701685966_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:39,185 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1701685966_0008
2016-05-18 02:13:39,185 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 02:13:39,190 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lhs.txt
2016-05-18 02:13:39,199 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:39,199 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:39,210 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E5CB6DB9CC5748CE9F55BA376C5259E4, ordinal: 0
2016-05-18 02:13:39,211 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lhs.txt"]
2016-05-18 02:13:39,211 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand"]
2016-05-18 02:13:39,212 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E5CB6DB9CC5748CE9F55BA376C5259E4, mem on start (mb), free: 128, total: 498, max: 672
2016-05-18 02:13:39,214 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E5CB6DB9CC5748CE9F55BA376C5259E4, mem on close (mb), free: 128, total: 498, max: 672
2016-05-18 02:13:39,230 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand/_temporary
2016-05-18 02:13:39,231 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.164
2016-05-18 02:13:39,257 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand
2016-05-18 02:13:39,280 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:39,281 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:39,316 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.030
2016-05-18 02:13:39,318 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 02:13:39,319 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:39,337 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 02:13:39,337 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lhs.txt"]
2016-05-18 02:13:39,337 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor"]
2016-05-18 02:13:39,337 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 02:13:39,338 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 02:13:39,338 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 02:13:39,339 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...egression/complexlogicxor
2016-05-18 02:13:39,405 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1444366096/.staging/job_local1444366096_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:39,406 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1444366096/.staging/job_local1444366096_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:39,454 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1444366096_0009/job_local1444366096_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:39,456 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1444366096_0009/job_local1444366096_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:39,456 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1444366096_0009
2016-05-18 02:13:39,456 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 02:13:39,461 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lhs.txt
2016-05-18 02:13:39,469 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:39,469 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:39,478 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C94AA9768F524CD5A7D7F899DC7DE118, ordinal: 0
2016-05-18 02:13:39,478 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lhs.txt"]
2016-05-18 02:13:39,479 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor"]
2016-05-18 02:13:39,479 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C94AA9768F524CD5A7D7F899DC7DE118, mem on start (mb), free: 74, total: 498, max: 672
2016-05-18 02:13:39,482 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C94AA9768F524CD5A7D7F899DC7DE118, mem on close (mb), free: 74, total: 498, max: 672
2016-05-18 02:13:39,502 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor/_temporary
2016-05-18 02:13:39,503 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.166
2016-05-18 02:13:39,530 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor
2016-05-18 02:13:39,551 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:39,551 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:39,628 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.071
2016-05-18 02:13:39,629 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 02:13:39,630 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:39,658 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting
2016-05-18 02:13:39,658 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/upper.txt"]
2016-05-18 02:13:39,658 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-05-18 02:13:39,659 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost"]
2016-05-18 02:13:39,659 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] parallel execution of steps is enabled: false
2016-05-18 02:13:39,659 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executing total steps: 1
2016-05-18 02:13:39,659 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] allocating management threads: 1
2016-05-18 02:13:39,661 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting step: (1/1) ...estOOMEPostGroup/oomepost
2016-05-18 02:13:39,744 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1858170448/.staging/job_local1858170448_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:39,745 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1858170448/.staging/job_local1858170448_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:39,782 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1858170448_0010/job_local1858170448_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:39,783 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1858170448_0010/job_local1858170448_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:39,784 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] submitted hadoop job: job_local1858170448_0010
2016-05-18 02:13:39,784 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] tracking url: http://localhost:8080/
2016-05-18 02:13:39,793 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt
2016-05-18 02:13:39,808 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:39,809 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:39,817 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C9201CD514184D94B9F4ED317E6B0AB8, ordinal: 0
2016-05-18 02:13:39,817 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-05-18 02:13:39,818 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 02:13:39,818 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C9201CD514184D94B9F4ED317E6B0AB8, mem on start (mb), free: 151, total: 498, max: 672
2016-05-18 02:13:39,820 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C9201CD514184D94B9F4ED317E6B0AB8, mem on close (mb), free: 151, total: 498, max: 672
2016-05-18 02:13:39,829 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/upper.txt
2016-05-18 02:13:39,856 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:39,856 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:39,863 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C9201CD514184D94B9F4ED317E6B0AB8, ordinal: 0
2016-05-18 02:13:39,864 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/upper.txt"]
2016-05-18 02:13:39,864 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 02:13:39,864 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C9201CD514184D94B9F4ED317E6B0AB8, mem on start (mb), free: 181, total: 493, max: 672
2016-05-18 02:13:39,866 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C9201CD514184D94B9F4ED317E6B0AB8, mem on close (mb), free: 181, total: 493, max: 672
2016-05-18 02:13:39,884 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 02:13:39,884 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 02:13:39,891 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D6C4A2758D4C4A498CC2DFA3FF7FCB14, ordinal: 1
2016-05-18 02:13:39,892 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 02:13:39,892 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost"]
2016-05-18 02:13:39,893 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D6C4A2758D4C4A498CC2DFA3FF7FCB14, mem on start (mb), free: 172, total: 493, max: 672
2016-05-18 02:13:39,900 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 02:13:39,901 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 02:13:39,901 ERROR element.TrapHandler (TrapHandler.java:handleReThrowableException(115)) - caught OutOfMemoryException, will not trap, rethrowing
java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$2.throwIntentionalException(RegressionPipesPlatformTest.java:635)
at cascading.TestFunction.operate(TestFunction.java:75)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:100)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:40)
at cascading.flow.stream.duct.OpenDuct.receive(OpenDuct.java:45)
at cascading.flow.stream.duct.OpenDuct.receive(OpenDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.accept(HadoopGroupGate.java:147)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:146)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-18 02:13:39,902 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D6C4A2758D4C4A498CC2DFA3FF7FCB14, mem on close (mb), free: 171, total: 493, max: 672
2016-05-18 02:13:39,904 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local1858170448_0010
java.lang.Exception: java.lang.OutOfMemoryError: fake error
at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$2.throwIntentionalException(RegressionPipesPlatformTest.java:635)
at cascading.TestFunction.operate(TestFunction.java:75)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:100)
at cascading.flow.stream.element.FunctionEachStage.receive(FunctionEachStage.java:40)
at cascading.flow.stream.duct.OpenDuct.receive(OpenDuct.java:45)
at cascading.flow.stream.duct.OpenDuct.receive(OpenDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.accept(HadoopGroupGate.java:147)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:146)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2016-05-18 02:13:39,904 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] hadoop job job_local1858170448_0010 state at FAILED
2016-05-18 02:13:39,905 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] failure info: NA
2016-05-18 02:13:39,905 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] task completion events identify failed tasks
2016-05-18 02:13:39,906 WARN flow.Flow (BaseFlow.java:logWarn(1516)) - [lower*upper] task completion events count: 0
2016-05-18 02:13:39,916 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] stopping all jobs
2016-05-18 02:13:39,916 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] stopping: (1/1) ...estOOMEPostGroup/oomepost
2016-05-18 02:13:39,916 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] stopped all jobs
2016-05-18 02:13:39,917 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost/_temporary
2016-05-18 02:13:39,917 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] completed in: 00:00.258
exception = cascading.flow.FlowException: local step failed: (1/1) ...estOOMEPostGroup/oomepost
2016-05-18 02:13:39,919 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost
2016-05-18 02:13:39,932 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:39,933 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:39,966 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.030
2016-05-18 02:13:39,967 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 02:13:39,967 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:39,980 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 02:13:39,980 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.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 02:13:39,981 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified"]
2016-05-18 02:13:39,981 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 02:13:39,981 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 02:13:39,981 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 02:13:39,981 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...Modified/lasteachmodified
2016-05-18 02:13:40,036 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity765879926/.staging/job_local765879926_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:40,037 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity765879926/.staging/job_local765879926_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:40,075 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local765879926_0011/job_local765879926_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:40,076 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local765879926_0011/job_local765879926_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:40,077 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local765879926_0011
2016-05-18 02:13:40,077 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 02:13:40,084 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt
2016-05-18 02:13:40,115 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:40,115 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:40,122 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C337EB3CB84848C2880A193F332FC9DE, ordinal: 0
2016-05-18 02:13:40,122 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.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 02:13:40,122 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'insert']]
2016-05-18 02:13:40,122 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C337EB3CB84848C2880A193F332FC9DE, mem on start (mb), free: 172, total: 486, max: 672
2016-05-18 02:13:40,124 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C337EB3CB84848C2880A193F332FC9DE, mem on close (mb), free: 172, total: 486, max: 672
2016-05-18 02:13:40,140 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 02:13:40,140 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 02:13:40,147 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: AB107C57A4FB46B89CD7F3C10F54E91A, ordinal: 1
2016-05-18 02:13:40,147 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'insert']]
2016-05-18 02:13:40,148 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified"]
2016-05-18 02:13:40,148 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AB107C57A4FB46B89CD7F3C10F54E91A, mem on start (mb), free: 165, total: 486, max: 672
2016-05-18 02:13:40,161 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AB107C57A4FB46B89CD7F3C10F54E91A, mem on close (mb), free: 163, total: 486, max: 672
2016-05-18 02:13:40,177 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified/_temporary
2016-05-18 02:13:40,180 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.197
2016-05-18 02:13:40,202 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified
2016-05-18 02:13:40,217 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:40,217 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:40,248 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.027
2016-05-18 02:13:40,249 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 02:13:40,249 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:40,259 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 02:13:40,259 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.4.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 02:13:40,259 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknown/unknown"]
2016-05-18 02:13:40,259 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 02:13:40,259 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 02:13:40,259 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 02:13:40,260 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...tform/testUnknown/unknown
2016-05-18 02:13:40,327 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1702283690/.staging/job_local1702283690_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:40,328 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1702283690/.staging/job_local1702283690_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:40,362 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1702283690_0012/job_local1702283690_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:40,363 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1702283690_0012/job_local1702283690_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:40,363 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1702283690_0012
2016-05-18 02:13:40,364 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 02:13:40,367 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower+upper.txt
2016-05-18 02:13:40,373 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:40,373 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:40,381 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FE378B8A64F945F29794A589F993468A, ordinal: 0
2016-05-18 02:13:40,381 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.4.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 02:13:40,382 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknown/unknown"]
2016-05-18 02:13:40,382 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FE378B8A64F945F29794A589F993468A, mem on start (mb), free: 112, total: 486, max: 672
2016-05-18 02:13:40,384 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FE378B8A64F945F29794A589F993468A, mem on close (mb), free: 112, total: 486, max: 672
2016-05-18 02:13:40,397 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknown/unknown/_temporary
2016-05-18 02:13:40,398 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.138
2016-05-18 02:13:40,425 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testUnknown/unknown
2016-05-18 02:13:40,443 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:40,444 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:40,479 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.031
2016-05-18 02:13:40,480 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 02:13:40,480 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:40,492 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 02:13:40,492 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.4.x/build/classes/test/data/critics.txt"]
2016-05-18 02:13:40,492 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth"]
2016-05-18 02:13:40,492 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 02:13:40,492 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 02:13:40,492 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 02:13:40,493 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...orm/testVarWidth/varwidth
2016-05-18 02:13:40,548 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1635460203/.staging/job_local1635460203_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:40,549 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1635460203/.staging/job_local1635460203_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:40,583 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1635460203_0013/job_local1635460203_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:40,584 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1635460203_0013/job_local1635460203_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:40,584 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1635460203_0013
2016-05-18 02:13:40,585 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 02:13:40,590 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/critics.txt
2016-05-18 02:13:40,596 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:40,596 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:40,603 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: EF22FD6FE91B4A0E9CC278EC2461B102, ordinal: 0
2016-05-18 02:13:40,604 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.4.x/build/classes/test/data/critics.txt"]
2016-05-18 02:13:40,604 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth"]
2016-05-18 02:13:40,604 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EF22FD6FE91B4A0E9CC278EC2461B102, mem on start (mb), free: 58, total: 486, max: 672
2016-05-18 02:13:40,606 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EF22FD6FE91B4A0E9CC278EC2461B102, mem on close (mb), free: 58, total: 486, max: 672
2016-05-18 02:13:40,620 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth/_temporary
2016-05-18 02:13:40,621 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.128
2016-05-18 02:13:40,648 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth
2016-05-18 02:13:40,679 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:40,680 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:40,684 WARN planner.FlowPlanner (FlowPlanner.java:verifyPipeAssemblyEndPoints(464)) - duplicate head name found, not an error but heads should have unique names: 'test'
2016-05-18 02:13:40,685 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testDupeHeadNames/unknown
2016-05-18 02:13:40,706 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:40,707 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:40,709 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testDupeTailNames/unknown
2016-05-18 02:13:40,993 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:40,994 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:43,843 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:02.828
2016-05-18 02:13:43,850 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 02:13:43,850 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:44,057 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] starting
2016-05-18 02:13:44,057 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.200.txt"]
2016-05-18 02:13:44,057 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline"]
2016-05-18 02:13:44,057 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] parallel execution of steps is enabled: false
2016-05-18 02:13:44,057 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] executing total steps: 1
2016-05-18 02:13:44,057 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] allocating management threads: 1
2016-05-18 02:13:44,059 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] starting step: (1/1) ...tDeepPipeline/deeppipline
2016-05-18 02:13:44,121 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity642718138/.staging/job_local642718138_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:44,123 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity642718138/.staging/job_local642718138_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:44,171 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local642718138_0014/job_local642718138_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:44,172 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local642718138_0014/job_local642718138_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:44,172 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] submitted hadoop job: job_local642718138_0014
2016-05-18 02:13:44,172 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] tracking url: http://localhost:8080/
2016-05-18 02:13:44,179 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.200.txt
2016-05-18 02:13:44,200 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:44,200 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:44,327 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C7C893F5B28E49CC9EBC3E9A8F82F0F0, ordinal: 0
2016-05-18 02:13:44,353 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.200.txt"]
2016-05-18 02:13:44,353 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(pipeline)[by:[{1}:'hash']]
2016-05-18 02:13:44,353 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C7C893F5B28E49CC9EBC3E9A8F82F0F0, mem on start (mb), free: 175, total: 494, max: 672
2016-05-18 02:13:44,556 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C7C893F5B28E49CC9EBC3E9A8F82F0F0, mem on close (mb), free: 166, total: 494, max: 672
2016-05-18 02:13:44,592 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 02:13:44,592 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 02:13:44,674 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DE95C67B23F0470EA12E7719F12D68AC, ordinal: 1
2016-05-18 02:13:44,690 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(pipeline)[by:[{1}:'hash']]
2016-05-18 02:13:44,690 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline"]
2016-05-18 02:13:44,690 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DE95C67B23F0470EA12E7719F12D68AC, mem on start (mb), free: 156, total: 494, max: 672
2016-05-18 02:13:45,052 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DE95C67B23F0470EA12E7719F12D68AC, mem on close (mb), free: 147, total: 494, max: 672
2016-05-18 02:13:45,075 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline/_temporary
2016-05-18 02:13:45,076 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [pipeline] completed in: 00:01.018
2016-05-18 02:13:45,103 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline
2016-05-18 02:13:45,122 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:45,123 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:45,146 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.019
2016-05-18 02:13:45,147 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 02:13:45,148 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:45,156 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting
2016-05-18 02:13:45,157 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-05-18 02:13:45,157 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-18 02:13:45,157 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] parallel execution of steps is enabled: false
2016-05-18 02:13:45,157 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] executing total steps: 1
2016-05-18 02:13:45,158 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] allocating management threads: 1
2016-05-18 02:13:45,158 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] starting step: (1/1) ...litPipe/splitintermediate
2016-05-18 02:13:45,211 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity2089674080/.staging/job_local2089674080_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:45,212 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity2089674080/.staging/job_local2089674080_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:45,244 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2089674080_0015/job_local2089674080_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:45,245 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2089674080_0015/job_local2089674080_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:45,246 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] submitted hadoop job: job_local2089674080_0015
2016-05-18 02:13:45,246 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] tracking url: http://localhost:8080/
2016-05-18 02:13:45,251 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt
2016-05-18 02:13:45,258 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:45,258 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:45,262 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F954752CB33141E2ADB069A9C52AD2B4, ordinal: 0
2016-05-18 02:13:45,262 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-05-18 02:13:45,262 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-18 02:13:45,263 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F954752CB33141E2ADB069A9C52AD2B4, mem on start (mb), free: 99, total: 494, max: 672
2016-05-18 02:13:45,265 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F954752CB33141E2ADB069A9C52AD2B4, mem on close (mb), free: 99, total: 494, max: 672
2016-05-18 02:13:45,280 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate/_temporary
2016-05-18 02:13:45,280 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [split] completed in: 00:00.124
2016-05-18 02:13:45,293 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:45,293 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:45,315 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.019
2016-05-18 02:13:45,316 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 02:13:45,316 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:45,324 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] starting
2016-05-18 02:13:45,325 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-18 02:13:45,325 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit"]
2016-05-18 02:13:45,325 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] parallel execution of steps is enabled: false
2016-05-18 02:13:45,325 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] executing total steps: 1
2016-05-18 02:13:45,326 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] allocating management threads: 1
2016-05-18 02:13:45,327 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] starting step: (1/1) ...pBySplitPipe/groupbysplit
2016-05-18 02:13:45,390 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity830136382/.staging/job_local830136382_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:45,391 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity830136382/.staging/job_local830136382_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:45,422 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local830136382_0016/job_local830136382_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:45,423 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local830136382_0016/job_local830136382_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:45,423 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] submitted hadoop job: job_local830136382_0016
2016-05-18 02:13:45,423 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] tracking url: http://localhost:8080/
2016-05-18 02:13:45,428 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate/part-00000
2016-05-18 02:13:45,447 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:45,447 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:45,451 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: ED0D10B517A24254882B543E9F410D99, ordinal: 0
2016-05-18 02:13:45,452 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-05-18 02:13:45,452 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2016-05-18 02:13:45,452 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: ED0D10B517A24254882B543E9F410D99, mem on start (mb), free: 179, total: 494, max: 672
2016-05-18 02:13:45,455 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: ED0D10B517A24254882B543E9F410D99, mem on close (mb), free: 179, total: 494, max: 672
2016-05-18 02:13:45,469 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 02:13:45,469 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 02:13:45,473 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: FDA5DCDFD1C243378A7500477FA6E988, ordinal: 1
2016-05-18 02:13:45,473 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2016-05-18 02:13:45,473 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit"]
2016-05-18 02:13:45,473 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FDA5DCDFD1C243378A7500477FA6E988, mem on start (mb), free: 174, total: 494, max: 672
2016-05-18 02:13:45,483 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FDA5DCDFD1C243378A7500477FA6E988, mem on close (mb), free: 173, total: 494, max: 672
2016-05-18 02:13:45,504 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit/_temporary
2016-05-18 02:13:45,505 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lhs+rhs] completed in: 00:00.180
2016-05-18 02:13:45,546 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit
2016-05-18 02:13:45,546 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate
2016-05-18 02:13:45,559 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:45,559 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:45,596 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.033
2016-05-18 02:13:45,597 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-18 02:13:45,597 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:45,614 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] starting
2016-05-18 02:13:45,614 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.4.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 02:13:45,614 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars"]
2016-05-18 02:13:45,614 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] parallel execution of steps is enabled: false
2016-05-18 02:13:45,615 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] executing total steps: 2
2016-05-18 02:13:45,615 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] allocating management threads: 1
2016-05-18 02:13:45,617 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] starting step: (1/2)
2016-05-18 02:13:45,668 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity926824901/.staging/job_local926824901_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:45,669 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity926824901/.staging/job_local926824901_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:45,702 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local926824901_0017/job_local926824901_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:45,703 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local926824901_0017/job_local926824901_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:45,704 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] submitted hadoop job: job_local926824901_0017
2016-05-18 02:13:45,704 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] tracking url: http://localhost:8080/
2016-05-18 02:13:45,709 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower+upper.txt
2016-05-18 02:13:45,729 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:45,730 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:45,734 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FD95B95448F14FCC8B84FF9A4472EC1E, ordinal: 0
2016-05-18 02:13:45,735 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.4.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 02:13:45,735 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-05-18 02:13:45,736 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FD95B95448F14FCC8B84FF9A4472EC1E, mem on start (mb), free: 169, total: 483, max: 672
2016-05-18 02:13:45,737 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FD95B95448F14FCC8B84FF9A4472EC1E, mem on close (mb), free: 169, total: 483, max: 672
2016-05-18 02:13:45,751 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 02:13:45,752 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 02:13:45,756 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F68FE470C60C44EB91AA1E495C34926E, ordinal: 1
2016-05-18 02:13:45,756 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-05-18 02:13:45,757 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[[UNKNOWN]->[ALL]]"][3562893392/__&%&%bar:bar@foo:_blah_/]
2016-05-18 02:13:45,757 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F68FE470C60C44EB91AA1E495C34926E, mem on start (mb), free: 163, total: 483, max: 672
2016-05-18 02:13:45,776 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F68FE470C60C44EB91AA1E495C34926E, mem on close (mb), free: 162, total: 483, max: 672
2016-05-18 02:13:45,792 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] starting step: (2/2) ...sInTempFiles/illegalchars
2016-05-18 02:13:45,852 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity507344119/.staging/job_local507344119_0018/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:45,852 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity507344119/.staging/job_local507344119_0018/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:45,884 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local507344119_0018/job_local507344119_0018.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:45,885 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local507344119_0018/job_local507344119_0018.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:45,886 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] submitted hadoop job: job_local507344119_0018
2016-05-18 02:13:45,887 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] tracking url: http://localhost:8080/
2016-05-18 02:13:45,890 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/3562893392____bar_bar_foo__blah__BDF328029D1D4A69AF286BAFB82B3F98/part-00000
2016-05-18 02:13:45,916 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:45,916 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:45,920 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AA2615C1588E4C9D8DAEF323D7758475, ordinal: 0
2016-05-18 02:13:45,921 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[[UNKNOWN]->[ALL]]"][3562893392/__&%&%bar:bar@foo:_blah_/]
2016-05-18 02:13:45,922 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-05-18 02:13:45,922 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AA2615C1588E4C9D8DAEF323D7758475, mem on start (mb), free: 180, total: 493, max: 672
2016-05-18 02:13:45,924 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AA2615C1588E4C9D8DAEF323D7758475, mem on close (mb), free: 180, total: 493, max: 672
2016-05-18 02:13:45,938 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 02:13:45,939 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 02:13:45,943 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E1452EF77F744E13895BCD985366B096, ordinal: 1
2016-05-18 02:13:45,944 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-05-18 02:13:45,945 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars"]
2016-05-18 02:13:45,945 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E1452EF77F744E13895BCD985366B096, mem on start (mb), free: 174, total: 493, max: 672
2016-05-18 02:13:45,952 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E1452EF77F744E13895BCD985366B096, mem on close (mb), free: 173, total: 493, max: 672
2016-05-18 02:13:45,975 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars/_temporary
2016-05-18 02:13:45,975 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [**&%&%bar:bar@foo://bl...] completed in: 00:00.360
2016-05-18 02:13:45,995 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars
2016-05-18 02:13:46,007 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 02:13:46,007 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 02:13:46,022 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.012
2016-05-18 02:13:46,022 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 02:13:46,022 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 02:13:46,028 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 02:13:46,028 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.4.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 02:13:46,028 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic"]
2016-05-18 02:13:46,028 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 02:13:46,028 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 02:13:46,028 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 02:13:46,030 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...-unknown-nondeterministic
2016-05-18 02:13:46,082 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1358845679/.staging/job_local1358845679_0019/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:46,083 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1358845679/.staging/job_local1358845679_0019/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:46,114 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1358845679_0019/job_local1358845679_0019.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 02:13:46,114 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1358845679_0019/job_local1358845679_0019.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 02:13:46,115 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1358845679_0019
2016-05-18 02:13:46,115 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 02:13:46,119 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower+upper.txt
2016-05-18 02:13:46,124 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 02:13:46,124 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 02:13:46,128 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AD6B7C3419BB46D4AE062AF3CAFD68CE, ordinal: 0
2016-05-18 02:13:46,129 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.4.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 02:13:46,130 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.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic"]
2016-05-18 02:13:46,130 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AD6B7C3419BB46D4AE062AF3CAFD68CE, mem on start (mb), free: 127, total: 493, max: 672
2016-05-18 02:13:46,132 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AD6B7C3419BB46D4AE062AF3CAFD68CE, mem on close (mb), free: 127, total: 493, max: 672
2016-05-18 02:13:46,148 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic/_temporary
2016-05-18 02:13:46,149 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.120
2016-05-18 02:13:46,169 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic