2016-01-14 20:30:50,955 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 20:30:50,976 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.RegressionPipesPlatformTest, with platform: hadoop2-mr1
2016-01-14 20:30:51,013 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-01-14 20:30:51,630 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-01-14 20:30:51,834 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 20:30:52,004 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:52,007 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:30:52,124 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 8B868DB7A8944B3C9A29DDBA772AD958
2016-01-14 20:30:52,270 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.092
2016-01-14 20:30:52,274 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:30:52,274 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:30:52,437 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 20:30:52,438 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:30:52,439 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lhs.txt"]
2016-01-14 20:30:52,439 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor"]
2016-01-14 20:30:52,440 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:30:52,441 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:30:52,441 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:30:52,442 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...regression/complexlogicor
2016-01-14 20:30:52,998 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity2122176067/.staging/job_local2122176067_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:53,011 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity2122176067/.staging/job_local2122176067_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:53,204 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2122176067_0001/job_local2122176067_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:53,212 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2122176067_0001/job_local2122176067_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:53,221 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local2122176067_0001
2016-01-14 20:30:53,221 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:30:53,310 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lhs.txt
2016-01-14 20:30:53,337 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:30:53,337 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:30:53,351 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D3E4E5893A0D45269808E9130412D5F9, ordinal: 0
2016-01-14 20:30:53,389 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lhs.txt"]
2016-01-14 20:30:53,389 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor"]
2016-01-14 20:30:53,390 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D3E4E5893A0D45269808E9130412D5F9, mem on start (mb), free: 188, total: 223, max: 672
2016-01-14 20:30:53,403 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D3E4E5893A0D45269808E9130412D5F9, mem on close (mb), free: 187, total: 223, max: 672
2016-01-14 20:30:53,443 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor/_temporary
2016-01-14 20:30:53,443 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:01.003
2016-01-14 20:30:53,483 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testComplexLogicOr/regression/complexlogicor
2016-01-14 20:30:53,516 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:53,516 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:30:53,581 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.053
2016-01-14 20:30:53,583 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:30:53,583 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:30:53,606 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] starting
2016-01-14 20:30:53,607 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-01-14 20:30:53,607 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-01-14 20:30:53,607 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] parallel execution of steps is enabled: false
2016-01-14 20:30:53,608 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] executing total steps: 1
2016-01-14 20:30:53,609 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] allocating management threads: 1
2016-01-14 20:30:53,611 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] starting step: (1/1) ...oupSplitPipe/intermediate
2016-01-14 20:30:53,690 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1816926964/.staging/job_local1816926964_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:53,691 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1816926964/.staging/job_local1816926964_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:53,774 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1816926964_0002/job_local1816926964_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:53,778 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1816926964_0002/job_local1816926964_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:53,780 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] submitted hadoop job: job_local1816926964_0002
2016-01-14 20:30:53,780 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] tracking url: http://localhost:8080/
2016-01-14 20:30:53,788 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower.txt
2016-01-14 20:30:53,801 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:30:53,801 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:30:53,814 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C233D563B73B45518491629E7F9DBA3D, ordinal: 0
2016-01-14 20:30:53,816 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-01-14 20:30:53,816 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-01-14 20:30:53,816 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C233D563B73B45518491629E7F9DBA3D, mem on start (mb), free: 205, total: 223, max: 672
2016-01-14 20:30:53,819 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C233D563B73B45518491629E7F9DBA3D, mem on close (mb), free: 204, total: 223, max: 672
2016-01-14 20:30:53,836 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate/_temporary
2016-01-14 20:30:53,836 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] completed in: 00:00.229
2016-01-14 20:30:53,864 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:53,865 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:30:53,977 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.103
2016-01-14 20:30:53,980 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:30:53,981 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:30:54,022 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] starting
2016-01-14 20:30:54,022 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-01-14 20:30:54,023 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit"]
2016-01-14 20:30:54,024 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] parallel execution of steps is enabled: false
2016-01-14 20:30:54,024 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] executing total steps: 1
2016-01-14 20:30:54,025 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] allocating management threads: 1
2016-01-14 20:30:54,026 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] starting step: (1/1) ...oupSplitPipe/cogroupsplit
2016-01-14 20:30:54,156 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1455581679/.staging/job_local1455581679_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:54,158 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1455581679/.staging/job_local1455581679_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:54,206 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1455581679_0003/job_local1455581679_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:54,208 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1455581679_0003/job_local1455581679_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:54,208 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] submitted hadoop job: job_local1455581679_0003
2016-01-14 20:30:54,209 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] tracking url: http://localhost:8080/
2016-01-14 20:30:54,216 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate/part-00000
2016-01-14 20:30:54,349 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:30:54,349 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:30:54,361 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F7D50EC74F0A48ABB708D0A018AE2030, ordinal: 0
2016-01-14 20:30:54,368 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate"]
2016-01-14 20:30:54,368 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lhs*rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num2']]
2016-01-14 20:30:54,369 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F7D50EC74F0A48ABB708D0A018AE2030, mem on start (mb), free: 64, total: 223, max: 672
2016-01-14 20:30:54,377 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F7D50EC74F0A48ABB708D0A018AE2030, mem on close (mb), free: 64, total: 223, max: 672
2016-01-14 20:30:54,482 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:30:54,482 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:30:54,515 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: EC605EA4B17840B986E5404BDF4C5CA9, ordinal: 1
2016-01-14 20:30:54,518 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lhs*rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num2']]
2016-01-14 20:30:54,519 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit"]
2016-01-14 20:30:54,519 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: EC605EA4B17840B986E5404BDF4C5CA9, mem on start (mb), free: 170, total: 281, max: 672
2016-01-14 20:30:54,540 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 20:30:54,541 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 20:30:54,553 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: EC605EA4B17840B986E5404BDF4C5CA9, mem on close (mb), free: 168, total: 281, max: 672
2016-01-14 20:30:54,585 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit/_temporary
2016-01-14 20:30:54,585 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs*rhs] completed in: 00:00.563
2016-01-14 20:30:54,659 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/cogroupsplit
2016-01-14 20:30:54,659 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testCoGroupSplitPipe/intermediate
2016-01-14 20:30:54,678 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:54,679 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:30:54,728 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.043
2016-01-14 20:30:54,730 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:30:54,730 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:30:54,751 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:30:54,751 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 20:30:54,751 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown"]
2016-01-14 20:30:54,752 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:30:54,752 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:30:54,752 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:30:54,753 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...eSortUnknown/none-unknown
2016-01-14 20:30:54,832 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1001229275/.staging/job_local1001229275_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:54,834 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1001229275/.staging/job_local1001229275_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:54,878 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1001229275_0004/job_local1001229275_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:54,880 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1001229275_0004/job_local1001229275_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:54,880 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local1001229275_0004
2016-01-14 20:30:54,880 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:30:54,889 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt
2016-01-14 20:30:54,994 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:30:54,995 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:30:55,002 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B8B9EAD60BC0462DA6A05DE9B774506A, ordinal: 0
2016-01-14 20:30:55,003 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 20:30:55,004 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{?}:NONE]]
2016-01-14 20:30:55,004 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B8B9EAD60BC0462DA6A05DE9B774506A, mem on start (mb), free: 120, total: 382, max: 672
2016-01-14 20:30:55,006 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B8B9EAD60BC0462DA6A05DE9B774506A, mem on close (mb), free: 120, total: 382, max: 672
2016-01-14 20:30:55,024 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:30:55,025 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:30:55,032 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: AD73E28FB0934823998C952BCED73FBF, ordinal: 1
2016-01-14 20:30:55,033 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{?}:NONE]]
2016-01-14 20:30:55,033 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown"]
2016-01-14 20:30:55,033 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AD73E28FB0934823998C952BCED73FBF, mem on start (mb), free: 116, total: 382, max: 672
2016-01-14 20:30:55,044 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AD73E28FB0934823998C952BCED73FBF, mem on close (mb), free: 115, total: 382, max: 672
2016-01-14 20:30:55,069 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown/_temporary
2016-01-14 20:30:55,069 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.317
2016-01-14 20:30:55,094 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testGroupNoneSortUnknown/none-unknown
2016-01-14 20:30:55,111 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:55,112 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:30:55,144 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.028
2016-01-14 20:30:55,145 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:30:55,145 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:30:55,167 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:30:55,167 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:30:55,168 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre"]
2016-01-14 20:30:55,168 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:30:55,168 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:30:55,169 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:30:55,169 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) .../testOOMEPreGroup/oomepre
2016-01-14 20:30:55,253 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity466249155/.staging/job_local466249155_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:55,255 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity466249155/.staging/job_local466249155_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:55,306 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local466249155_0005/job_local466249155_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:55,307 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local466249155_0005/job_local466249155_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:55,308 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local466249155_0005
2016-01-14 20:30:55,309 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:30:55,317 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt
2016-01-14 20:30:55,328 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:30:55,328 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:30:55,336 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E63F272D8DEA4EC6B8FB98127CD2B6D0, ordinal: 0
2016-01-14 20:30:55,337 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:30:55,337 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre"]
2016-01-14 20:30:55,337 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E63F272D8DEA4EC6B8FB98127CD2B6D0, mem on start (mb), free: 71, total: 382, max: 672
2016-01-14 20:30:55,340 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:74)
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-01-14 20:30:55,344 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E63F272D8DEA4EC6B8FB98127CD2B6D0, mem on close (mb), free: 71, total: 382, max: 672
2016-01-14 20:30:55,345 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local466249155_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:74)
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-01-14 20:30:55,352 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [test] hadoop job job_local466249155_0005 state at FAILED
2016-01-14 20:30:55,352 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [test] failure info: NA
2016-01-14 20:30:55,353 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [test] task completion events identify failed tasks
2016-01-14 20:30:55,353 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [test] task completion events count: 0
2016-01-14 20:30:55,354 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] stopping all jobs
2016-01-14 20:30:55,354 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] stopping: (1/1) .../testOOMEPreGroup/oomepre
2016-01-14 20:30:55,355 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] stopped all jobs
2016-01-14 20:30:55,355 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre/_temporary
2016-01-14 20:30:55,356 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.188
exception = cascading.flow.FlowException: local step failed: (1/1) .../testOOMEPreGroup/oomepre
2016-01-14 20:30:55,357 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testOOMEPreGroup/oomepre
2016-01-14 20:30:55,380 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:55,380 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:30:55,415 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.031
2016-01-14 20:30:55,416 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:30:55,416 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:30:55,427 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:30:55,427 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 20:30:55,427 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCopy/copy"]
2016-01-14 20:30:55,428 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:30:55,428 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:30:55,428 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:30:55,429 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...pesplatform/testCopy/copy
2016-01-14 20:30:55,516 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity769813592/.staging/job_local769813592_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:55,517 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity769813592/.staging/job_local769813592_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:55,552 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local769813592_0006/job_local769813592_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:55,553 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local769813592_0006/job_local769813592_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:55,554 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local769813592_0006
2016-01-14 20:30:55,554 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:30:55,561 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt
2016-01-14 20:30:55,569 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:30:55,569 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:30:55,575 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AC90C7BB6AEC472D8FB8C0C384EF2053, ordinal: 0
2016-01-14 20:30:55,575 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 20:30:55,575 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCopy/copy"]
2016-01-14 20:30:55,576 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AC90C7BB6AEC472D8FB8C0C384EF2053, mem on start (mb), free: 150, total: 382, max: 672
2016-01-14 20:30:55,577 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AC90C7BB6AEC472D8FB8C0C384EF2053, mem on close (mb), free: 150, total: 382, max: 672
2016-01-14 20:30:55,599 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testCopy/copy/_temporary
2016-01-14 20:30:55,599 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.171
2016-01-14 20:30:55,623 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testCopy/copy
2016-01-14 20:30:55,641 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:55,642 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:30:55,674 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.027
2016-01-14 20:30:55,675 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:30:55,675 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:30:55,689 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:30:55,689 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 20:30:55,690 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace"]
2016-01-14 20:30:55,690 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:30:55,690 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:30:55,690 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:30:55,691 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...wnReplace/unknown-replace
2016-01-14 20:30:55,752 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity940654632/.staging/job_local940654632_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:55,753 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity940654632/.staging/job_local940654632_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:55,789 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local940654632_0007/job_local940654632_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:55,790 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local940654632_0007/job_local940654632_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:55,790 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local940654632_0007
2016-01-14 20:30:55,790 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:30:55,798 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt
2016-01-14 20:30:55,805 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:30:55,805 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:30:55,812 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BAC2847C9E1B482497426757E1CB4586, ordinal: 0
2016-01-14 20:30:55,813 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 20:30:55,813 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace"]
2016-01-14 20:30:55,813 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BAC2847C9E1B482497426757E1CB4586, mem on start (mb), free: 107, total: 382, max: 672
2016-01-14 20:30:55,814 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BAC2847C9E1B482497426757E1CB4586, mem on close (mb), free: 107, total: 382, max: 672
2016-01-14 20:30:55,836 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace/_temporary
2016-01-14 20:30:55,837 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.147
2016-01-14 20:30:55,882 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testUnknownReplace/unknown-replace
2016-01-14 20:30:55,905 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:55,906 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:30:55,943 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.031
2016-01-14 20:30:55,943 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:30:55,944 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:30:55,956 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:30:55,956 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lhs.txt"]
2016-01-14 20:30:55,956 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand"]
2016-01-14 20:30:55,957 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:30:55,957 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:30:55,957 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:30:55,958 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...egression/complexlogicand
2016-01-14 20:30:56,015 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity767869404/.staging/job_local767869404_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:56,016 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity767869404/.staging/job_local767869404_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:56,054 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local767869404_0008/job_local767869404_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:56,055 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local767869404_0008/job_local767869404_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:56,056 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local767869404_0008
2016-01-14 20:30:56,057 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:30:56,061 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lhs.txt
2016-01-14 20:30:56,069 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:30:56,069 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:30:56,079 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E6A7B52A612348B695AC3F5A121A3B90, ordinal: 0
2016-01-14 20:30:56,080 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lhs.txt"]
2016-01-14 20:30:56,080 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand"]
2016-01-14 20:30:56,081 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E6A7B52A612348B695AC3F5A121A3B90, mem on start (mb), free: 59, total: 382, max: 672
2016-01-14 20:30:56,084 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E6A7B52A612348B695AC3F5A121A3B90, mem on close (mb), free: 59, total: 382, max: 672
2016-01-14 20:30:56,103 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand/_temporary
2016-01-14 20:30:56,103 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.146
2016-01-14 20:30:56,151 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testComplexLogicAnd/regression/complexlogicand
2016-01-14 20:30:56,168 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:56,169 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:30:56,206 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.033
2016-01-14 20:30:56,207 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:30:56,207 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:30:56,219 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:30:56,219 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lhs.txt"]
2016-01-14 20:30:56,220 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor"]
2016-01-14 20:30:56,221 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:30:56,221 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:30:56,222 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:30:56,223 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...egression/complexlogicxor
2016-01-14 20:30:56,280 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1584004464/.staging/job_local1584004464_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:56,280 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1584004464/.staging/job_local1584004464_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:56,327 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1584004464_0009/job_local1584004464_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:56,328 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1584004464_0009/job_local1584004464_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:56,329 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local1584004464_0009
2016-01-14 20:30:56,330 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:30:56,336 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lhs.txt
2016-01-14 20:30:56,343 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:30:56,343 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:30:56,350 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E58E5B2274D34230A5ED9198E1CCE125, ordinal: 0
2016-01-14 20:30:56,351 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lhs.txt"]
2016-01-14 20:30:56,352 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor"]
2016-01-14 20:30:56,352 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E58E5B2274D34230A5ED9198E1CCE125, mem on start (mb), free: 236, total: 497, max: 672
2016-01-14 20:30:56,355 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E58E5B2274D34230A5ED9198E1CCE125, mem on close (mb), free: 236, total: 497, max: 672
2016-01-14 20:30:56,376 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor/_temporary
2016-01-14 20:30:56,377 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.157
2016-01-14 20:30:56,399 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testComplexLogicXor/regression/complexlogicxor
2016-01-14 20:30:56,415 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:56,416 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:30:56,473 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.051
2016-01-14 20:30:56,474 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:30:56,474 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:30:56,505 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] starting
2016-01-14 20:30:56,505 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/upper.txt"]
2016-01-14 20:30:56,506 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-01-14 20:30:56,506 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost"]
2016-01-14 20:30:56,506 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] parallel execution of steps is enabled: false
2016-01-14 20:30:56,507 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executing total steps: 1
2016-01-14 20:30:56,507 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] allocating management threads: 1
2016-01-14 20:30:56,508 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] starting step: (1/1) ...estOOMEPostGroup/oomepost
2016-01-14 20:30:56,581 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1807223893/.staging/job_local1807223893_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:56,582 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1807223893/.staging/job_local1807223893_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:56,619 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1807223893_0010/job_local1807223893_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:56,619 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1807223893_0010/job_local1807223893_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:56,620 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] submitted hadoop job: job_local1807223893_0010
2016-01-14 20:30:56,621 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] tracking url: http://localhost:8080/
2016-01-14 20:30:56,627 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/upper.txt
2016-01-14 20:30:56,708 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:30:56,708 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:30:56,717 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D6E636B602D0401C917FD0E87D1C3B89, ordinal: 0
2016-01-14 20:30:56,717 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/upper.txt"]
2016-01-14 20:30:56,718 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-01-14 20:30:56,718 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D6E636B602D0401C917FD0E87D1C3B89, mem on start (mb), free: 80, total: 497, max: 672
2016-01-14 20:30:56,719 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D6E636B602D0401C917FD0E87D1C3B89, mem on close (mb), free: 80, total: 497, max: 672
2016-01-14 20:30:56,727 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower.txt
2016-01-14 20:30:56,759 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:30:56,759 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:30:56,767 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D6E636B602D0401C917FD0E87D1C3B89, ordinal: 0
2016-01-14 20:30:56,768 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-01-14 20:30:56,768 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-01-14 20:30:56,768 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D6E636B602D0401C917FD0E87D1C3B89, mem on start (mb), free: 177, total: 490, max: 672
2016-01-14 20:30:56,770 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D6E636B602D0401C917FD0E87D1C3B89, mem on close (mb), free: 177, total: 490, max: 672
2016-01-14 20:30:56,788 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:30:56,788 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:30:56,795 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: BCEF31027BC0497588D60AE27408F1D3, ordinal: 1
2016-01-14 20:30:56,795 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-01-14 20:30:56,795 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost"]
2016-01-14 20:30:56,796 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BCEF31027BC0497588D60AE27408F1D3, mem on start (mb), free: 170, total: 490, max: 672
2016-01-14 20:30:56,803 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 20:30:56,803 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 20:30:56,804 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:74)
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:141)
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-01-14 20:30:56,805 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BCEF31027BC0497588D60AE27408F1D3, mem on close (mb), free: 168, total: 490, max: 672
2016-01-14 20:30:56,807 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local1807223893_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:74)
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:141)
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-01-14 20:30:56,809 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [lower*upper] hadoop job job_local1807223893_0010 state at FAILED
2016-01-14 20:30:56,810 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [lower*upper] failure info: NA
2016-01-14 20:30:56,810 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [lower*upper] task completion events identify failed tasks
2016-01-14 20:30:56,810 WARN flow.Flow (BaseFlow.java:logWarn(1445)) - [lower*upper] task completion events count: 0
2016-01-14 20:30:56,819 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] stopping all jobs
2016-01-14 20:30:56,820 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] stopping: (1/1) ...estOOMEPostGroup/oomepost
2016-01-14 20:30:56,821 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] stopped all jobs
2016-01-14 20:30:56,822 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost/_temporary
2016-01-14 20:30:56,822 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] completed in: 00:00.316
exception = cascading.flow.FlowException: local step failed: (1/1) ...estOOMEPostGroup/oomepost
2016-01-14 20:30:56,823 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testOOMEPostGroup/oomepost
2016-01-14 20:30:56,839 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:56,839 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:30:56,868 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-01-14 20:30:56,869 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:30:56,869 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:30:56,882 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:30:56,882 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:30:56,883 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified"]
2016-01-14 20:30:56,883 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:30:56,883 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:30:56,883 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:30:56,884 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...Modified/lasteachmodified
2016-01-14 20:30:56,942 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1742131837/.staging/job_local1742131837_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:56,944 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1742131837/.staging/job_local1742131837_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:56,981 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1742131837_0011/job_local1742131837_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:56,984 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1742131837_0011/job_local1742131837_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:56,986 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local1742131837_0011
2016-01-14 20:30:56,986 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:30:56,991 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt
2016-01-14 20:30:57,017 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:30:57,018 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:30:57,024 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B39B702205EE4A49BB11202F7B25B6AE, ordinal: 0
2016-01-14 20:30:57,028 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:30:57,028 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'insert']]
2016-01-14 20:30:57,029 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B39B702205EE4A49BB11202F7B25B6AE, mem on start (mb), free: 183, total: 494, max: 672
2016-01-14 20:30:57,032 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B39B702205EE4A49BB11202F7B25B6AE, mem on close (mb), free: 183, total: 494, max: 672
2016-01-14 20:30:57,048 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:30:57,049 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:30:57,055 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D52F8D111ED1472AAE227143FD7CF751, ordinal: 1
2016-01-14 20:30:57,055 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'insert']]
2016-01-14 20:30:57,055 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified"]
2016-01-14 20:30:57,056 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D52F8D111ED1472AAE227143FD7CF751, mem on start (mb), free: 176, total: 494, max: 672
2016-01-14 20:30:57,064 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D52F8D111ED1472AAE227143FD7CF751, mem on close (mb), free: 175, total: 494, max: 672
2016-01-14 20:30:57,085 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified/_temporary
2016-01-14 20:30:57,085 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.202
2016-01-14 20:30:57,115 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testLastEachNotModified/lasteachmodified
2016-01-14 20:30:57,131 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:57,132 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:30:57,169 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.033
2016-01-14 20:30:57,169 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:30:57,170 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:30:57,179 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:30:57,179 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 20:30:57,179 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknown/unknown"]
2016-01-14 20:30:57,179 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:30:57,180 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:30:57,180 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:30:57,180 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...tform/testUnknown/unknown
2016-01-14 20:30:57,236 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity113187322/.staging/job_local113187322_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:57,237 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity113187322/.staging/job_local113187322_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:57,269 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local113187322_0012/job_local113187322_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:57,270 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local113187322_0012/job_local113187322_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:57,271 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local113187322_0012
2016-01-14 20:30:57,271 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:30:57,277 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt
2016-01-14 20:30:57,283 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:30:57,283 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:30:57,290 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BC814BB489224665B383D18BA79DBD38, ordinal: 0
2016-01-14 20:30:57,291 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 20:30:57,291 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknown/unknown"]
2016-01-14 20:30:57,291 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BC814BB489224665B383D18BA79DBD38, mem on start (mb), free: 126, total: 494, max: 672
2016-01-14 20:30:57,293 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BC814BB489224665B383D18BA79DBD38, mem on close (mb), free: 126, total: 494, max: 672
2016-01-14 20:30:57,306 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnknown/unknown/_temporary
2016-01-14 20:30:57,307 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.127
2016-01-14 20:30:57,330 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testUnknown/unknown
2016-01-14 20:30:57,346 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:57,346 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:30:57,374 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-01-14 20:30:57,375 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:30:57,375 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:30:57,385 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:30:57,385 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/critics.txt"]
2016-01-14 20:30:57,386 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth"]
2016-01-14 20:30:57,386 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:30:57,386 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:30:57,386 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:30:57,387 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...orm/testVarWidth/varwidth
2016-01-14 20:30:57,440 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity337922063/.staging/job_local337922063_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:57,441 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity337922063/.staging/job_local337922063_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:57,472 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local337922063_0013/job_local337922063_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:30:57,473 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local337922063_0013/job_local337922063_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:30:57,474 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local337922063_0013
2016-01-14 20:30:57,474 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:30:57,478 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/critics.txt
2016-01-14 20:30:57,484 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:30:57,485 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:30:57,491 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C444443F1C88498B9B86AE7A3DF79628, ordinal: 0
2016-01-14 20:30:57,492 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/critics.txt"]
2016-01-14 20:30:57,492 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth"]
2016-01-14 20:30:57,492 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C444443F1C88498B9B86AE7A3DF79628, mem on start (mb), free: 78, total: 494, max: 672
2016-01-14 20:30:57,495 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C444443F1C88498B9B86AE7A3DF79628, mem on close (mb), free: 78, total: 494, max: 672
2016-01-14 20:30:57,522 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth/_temporary
2016-01-14 20:30:57,522 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.137
2016-01-14 20:30:57,549 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testVarWidth/varwidth
2016-01-14 20:30:57,568 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:57,569 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:30:57,572 WARN planner.FlowPlanner (FlowPlanner.java:verifyPipeAssemblyEndPoints(463)) - duplicate head name found, not an error but heads should have unique names: 'test'
2016-01-14 20:30:57,575 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testDupeHeadNames/unknown
2016-01-14 20:30:57,608 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:57,609 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:30:57,614 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testDupeTailNames/unknown
2016-01-14 20:30:57,977 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:30:57,978 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:31:00,074 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pipeline] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:02.076
2016-01-14 20:31:00,080 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pipeline] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:31:00,080 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pipeline] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:31:00,273 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pipeline] starting
2016-01-14 20:31:00,273 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pipeline] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.200.txt"]
2016-01-14 20:31:00,274 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pipeline] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline"]
2016-01-14 20:31:00,274 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pipeline] parallel execution of steps is enabled: false
2016-01-14 20:31:00,274 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pipeline] executing total steps: 1
2016-01-14 20:31:00,274 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pipeline] allocating management threads: 1
2016-01-14 20:31:00,274 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pipeline] starting step: (1/1) ...tDeepPipeline/deeppipline
2016-01-14 20:31:00,328 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity859402165/.staging/job_local859402165_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:31:00,329 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity859402165/.staging/job_local859402165_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:31:00,361 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local859402165_0014/job_local859402165_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:31:00,363 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local859402165_0014/job_local859402165_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:31:00,364 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pipeline] submitted hadoop job: job_local859402165_0014
2016-01-14 20:31:00,364 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pipeline] tracking url: http://localhost:8080/
2016-01-14 20:31:00,369 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.200.txt
2016-01-14 20:31:00,392 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:31:00,392 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:31:00,508 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: ECC36010694C4151B0D572FE05B98F25, ordinal: 0
2016-01-14 20:31:00,533 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.200.txt"]
2016-01-14 20:31:00,534 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(pipeline)[by:[{1}:'hash']]
2016-01-14 20:31:00,534 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: ECC36010694C4151B0D572FE05B98F25, mem on start (mb), free: 178, total: 495, max: 672
2016-01-14 20:31:00,739 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: ECC36010694C4151B0D572FE05B98F25, mem on close (mb), free: 171, total: 495, max: 672
2016-01-14 20:31:00,774 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:31:00,774 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:31:00,867 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DD364D1395E647E3B9092320EAA99450, ordinal: 1
2016-01-14 20:31:00,886 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(pipeline)[by:[{1}:'hash']]
2016-01-14 20:31:00,886 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline"]
2016-01-14 20:31:00,887 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DD364D1395E647E3B9092320EAA99450, mem on start (mb), free: 162, total: 495, max: 672
2016-01-14 20:31:01,265 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DD364D1395E647E3B9092320EAA99450, mem on close (mb), free: 153, total: 495, max: 672
2016-01-14 20:31:01,291 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline/_temporary
2016-01-14 20:31:01,293 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [pipeline] completed in: 00:01.018
2016-01-14 20:31:01,332 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testDeepPipeline/deeppipline
2016-01-14 20:31:01,349 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:31:01,350 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:31:01,380 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.024
2016-01-14 20:31:01,380 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:31:01,381 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:31:01,390 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] starting
2016-01-14 20:31:01,390 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-01-14 20:31:01,391 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-01-14 20:31:01,391 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] parallel execution of steps is enabled: false
2016-01-14 20:31:01,391 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] executing total steps: 1
2016-01-14 20:31:01,391 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] allocating management threads: 1
2016-01-14 20:31:01,392 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] starting step: (1/1) ...litPipe/splitintermediate
2016-01-14 20:31:01,448 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1973208846/.staging/job_local1973208846_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:31:01,449 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1973208846/.staging/job_local1973208846_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:31:01,480 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1973208846_0015/job_local1973208846_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:31:01,481 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1973208846_0015/job_local1973208846_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:31:01,481 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] submitted hadoop job: job_local1973208846_0015
2016-01-14 20:31:01,481 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] tracking url: http://localhost:8080/
2016-01-14 20:31:01,487 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower.txt
2016-01-14 20:31:01,493 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:31:01,493 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:31:01,497 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BC75AFEB934B4333ACBB3C01B18E419B, ordinal: 0
2016-01-14 20:31:01,497 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-01-14 20:31:01,497 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-01-14 20:31:01,498 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BC75AFEB934B4333ACBB3C01B18E419B, mem on start (mb), free: 104, total: 495, max: 672
2016-01-14 20:31:01,499 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BC75AFEB934B4333ACBB3C01B18E419B, mem on close (mb), free: 104, total: 495, max: 672
2016-01-14 20:31:01,515 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate/_temporary
2016-01-14 20:31:01,516 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [split] completed in: 00:00.125
2016-01-14 20:31:01,530 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:31:01,530 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:31:01,551 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs+rhs] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.017
2016-01-14 20:31:01,552 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs+rhs] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:31:01,552 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs+rhs] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:31:01,560 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs+rhs] starting
2016-01-14 20:31:01,560 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs+rhs] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-01-14 20:31:01,560 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs+rhs] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit"]
2016-01-14 20:31:01,560 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs+rhs] parallel execution of steps is enabled: false
2016-01-14 20:31:01,561 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs+rhs] executing total steps: 1
2016-01-14 20:31:01,561 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs+rhs] allocating management threads: 1
2016-01-14 20:31:01,562 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs+rhs] starting step: (1/1) ...pBySplitPipe/groupbysplit
2016-01-14 20:31:01,633 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity2017963360/.staging/job_local2017963360_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:31:01,634 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity2017963360/.staging/job_local2017963360_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:31:01,669 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2017963360_0016/job_local2017963360_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:31:01,670 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2017963360_0016/job_local2017963360_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:31:01,670 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs+rhs] submitted hadoop job: job_local2017963360_0016
2016-01-14 20:31:01,671 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs+rhs] tracking url: http://localhost:8080/
2016-01-14 20:31:01,676 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate/part-00000
2016-01-14 20:31:01,695 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:31:01,696 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:31:01,700 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BC37722064364DDB96291A6C76C16D27, ordinal: 0
2016-01-14 20:31:01,701 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate"]
2016-01-14 20:31:01,701 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2016-01-14 20:31:01,701 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BC37722064364DDB96291A6C76C16D27, mem on start (mb), free: 181, total: 495, max: 672
2016-01-14 20:31:01,702 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BC37722064364DDB96291A6C76C16D27, mem on close (mb), free: 181, total: 495, max: 672
2016-01-14 20:31:01,715 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:31:01,715 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:31:01,718 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: ADEA4F1080F54AFEB858140C128F0BAD, ordinal: 1
2016-01-14 20:31:01,718 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2016-01-14 20:31:01,718 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit"]
2016-01-14 20:31:01,719 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: ADEA4F1080F54AFEB858140C128F0BAD, mem on start (mb), free: 176, total: 495, max: 672
2016-01-14 20:31:01,725 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: ADEA4F1080F54AFEB858140C128F0BAD, mem on close (mb), free: 175, total: 495, max: 672
2016-01-14 20:31:01,740 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit/_temporary
2016-01-14 20:31:01,740 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lhs+rhs] completed in: 00:00.179
2016-01-14 20:31:01,789 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/splitintermediate
2016-01-14 20:31:01,790 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testGroupBySplitPipe/groupbysplit
2016-01-14 20:31:01,802 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:31:01,803 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:31:01,863 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.055
2016-01-14 20:31:01,865 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 20:31:01,866 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:31:01,889 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] starting
2016-01-14 20:31:01,890 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 20:31:01,891 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars"]
2016-01-14 20:31:01,891 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] parallel execution of steps is enabled: false
2016-01-14 20:31:01,892 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] executing total steps: 2
2016-01-14 20:31:01,892 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] allocating management threads: 1
2016-01-14 20:31:01,893 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] starting step: (1/2)
2016-01-14 20:31:01,951 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity307340393/.staging/job_local307340393_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:31:01,952 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity307340393/.staging/job_local307340393_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:31:01,982 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local307340393_0017/job_local307340393_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:31:01,983 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local307340393_0017/job_local307340393_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:31:01,984 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] submitted hadoop job: job_local307340393_0017
2016-01-14 20:31:01,984 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] tracking url: http://localhost:8080/
2016-01-14 20:31:01,988 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt
2016-01-14 20:31:02,008 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:31:02,008 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:31:02,012 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E0014EF19D894E8E8EA6354D7544FAE2, ordinal: 0
2016-01-14 20:31:02,013 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 20:31:02,013 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-01-14 20:31:02,014 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E0014EF19D894E8E8EA6354D7544FAE2, mem on start (mb), free: 182, total: 495, max: 672
2016-01-14 20:31:02,015 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E0014EF19D894E8E8EA6354D7544FAE2, mem on close (mb), free: 182, total: 495, max: 672
2016-01-14 20:31:02,028 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:31:02,028 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:31:02,032 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E0924C0B5EDF43E09A3739D37523F87D, ordinal: 1
2016-01-14 20:31:02,032 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-01-14 20:31:02,033 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[[UNKNOWN]->[ALL]]"][5928406061/__&%&%bar:bar@foo:_blah_/]
2016-01-14 20:31:02,033 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E0924C0B5EDF43E09A3739D37523F87D, mem on start (mb), free: 177, total: 495, max: 672
2016-01-14 20:31:02,051 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E0924C0B5EDF43E09A3739D37523F87D, mem on close (mb), free: 175, total: 495, max: 672
2016-01-14 20:31:02,071 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] starting step: (2/2) ...sInTempFiles/illegalchars
2016-01-14 20:31:02,132 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1663937320/.staging/job_local1663937320_0018/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:31:02,132 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1663937320/.staging/job_local1663937320_0018/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:31:02,162 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1663937320_0018/job_local1663937320_0018.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:31:02,163 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1663937320_0018/job_local1663937320_0018.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:31:02,163 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] submitted hadoop job: job_local1663937320_0018
2016-01-14 20:31:02,164 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] tracking url: http://localhost:8080/
2016-01-14 20:31:02,167 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/5928406061____bar_bar_foo__blah__E04F045EE1BC446284A22C56C34930CA/part-00000
2016-01-14 20:31:02,194 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:31:02,194 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:31:02,198 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C0C9C4DD264E4ECFA70D96F4E554ED49, ordinal: 0
2016-01-14 20:31:02,199 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[[UNKNOWN]->[ALL]]"][5928406061/__&%&%bar:bar@foo:_blah_/]
2016-01-14 20:31:02,199 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-01-14 20:31:02,199 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C0C9C4DD264E4ECFA70D96F4E554ED49, mem on start (mb), free: 171, total: 484, max: 672
2016-01-14 20:31:02,201 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C0C9C4DD264E4ECFA70D96F4E554ED49, mem on close (mb), free: 171, total: 484, max: 672
2016-01-14 20:31:02,214 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:31:02,214 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:31:02,218 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DAC557EAD81544D48E26DED7D2435769, ordinal: 1
2016-01-14 20:31:02,218 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2016-01-14 20:31:02,219 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars"]
2016-01-14 20:31:02,219 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DAC557EAD81544D48E26DED7D2435769, mem on start (mb), free: 165, total: 484, max: 672
2016-01-14 20:31:02,226 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DAC557EAD81544D48E26DED7D2435769, mem on close (mb), free: 163, total: 484, max: 672
2016-01-14 20:31:02,239 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars/_temporary
2016-01-14 20:31:02,240 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [**&%&%bar:bar@foo://bl...] completed in: 00:00.350
2016-01-14 20:31:02,261 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testIllegalCharsInTempFiles/illegalchars
2016-01-14 20:31:02,274 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:31:02,274 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-14 20:31:02,292 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.014
2016-01-14 20:31:02,293 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:31:02,293 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:31:02,300 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:31:02,300 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 20:31:02,300 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic"]
2016-01-14 20:31:02,300 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:31:02,300 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:31:02,300 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:31:02,301 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...-unknown-nondeterministic
2016-01-14 20:31:02,355 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity869191972/.staging/job_local869191972_0019/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:31:02,356 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity869191972/.staging/job_local869191972_0019/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:31:02,387 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local869191972_0019/job_local869191972_0019.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:31:02,389 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local869191972_0019/job_local869191972_0019.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:31:02,390 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local869191972_0019
2016-01-14 20:31:02,390 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:31:02,395 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt
2016-01-14 20:31:02,400 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:31:02,400 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:31:02,404 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CF634F8593D74129A893B8BF0599F3D4, ordinal: 0
2016-01-14 20:31:02,404 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 20:31:02,404 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic"]
2016-01-14 20:31:02,405 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CF634F8593D74129A893B8BF0599F3D4, mem on start (mb), free: 115, total: 484, max: 672
2016-01-14 20:31:02,406 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CF634F8593D74129A893B8BF0599F3D4, mem on close (mb), free: 115, total: 484, max: 672
2016-01-14 20:31:02,426 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic/_temporary
2016-01-14 20:31:02,426 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.126
2016-01-14 20:31:02,450 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/testUnGroupUnknown/ungrouped-unknown-nondeterministic