2016-01-14 20:05:52,542 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 20:05:52,576 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.BasicPipesPlatformTest, with platform: hadoop2-mr1
2016-01-14 20:05:52,616 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-01-14 20:05:53,229 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:05:53,430 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 20:05:53,575 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:05:53,577 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:05:53,688 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: A526D5B6CA2A457B9727CC81BAF829C9
2016-01-14 20:05:53,917 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.171
2016-01-14 20:05:53,922 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-01-14 20:05:53,922 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:05:54,110 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 20:05:54,112 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:05:54,112 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:05:54,113 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/basicpipesplatform/testSimpleChain/simplechain"]
2016-01-14 20:05:54,113 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:05:54,115 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 2
2016-01-14 20:05:54,115 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:05:54,116 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/2)
2016-01-14 20:05:54,702 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1127056554/.staging/job_local1127056554_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:54,713 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1127056554/.staging/job_local1127056554_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:54,903 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_local1127056554_0001/job_local1127056554_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:54,907 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_local1127056554_0001/job_local1127056554_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:54,914 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local1127056554_0001
2016-01-14 20:05:54,914 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:05:55,022 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:05:55,156 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:05:55,156 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:05:55,168 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C720814AE9F54451853A396FADA4326A, ordinal: 0
2016-01-14 20:05:55,218 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:05:55,218 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-01-14 20:05:55,220 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C720814AE9F54451853A396FADA4326A, mem on start (mb), free: 85, total: 223, max: 672
2016-01-14 20:05:55,229 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C720814AE9F54451853A396FADA4326A, mem on close (mb), free: 85, total: 223, max: 672
2016-01-14 20:05:55,351 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:05:55,351 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:05:55,362 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F404E9A0C6FF44F9B48EE03FDA55CEBA, ordinal: 1
2016-01-14 20:05:55,366 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-01-14 20:05:55,366 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[[0, 'count']]"][6298687229/test/]
2016-01-14 20:05:55,366 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F404E9A0C6FF44F9B48EE03FDA55CEBA, mem on start (mb), free: 75, total: 223, max: 672
2016-01-14 20:05:55,392 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F404E9A0C6FF44F9B48EE03FDA55CEBA, mem on close (mb), free: 73, total: 223, max: 672
2016-01-14 20:05:55,418 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (2/2) ...stSimpleChain/simplechain
2016-01-14 20:05: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/teamcity2123655513/.staging/job_local2123655513_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:55,518 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity2123655513/.staging/job_local2123655513_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:55,632 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_local2123655513_0002/job_local2123655513_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:55,634 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_local2123655513_0002/job_local2123655513_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:55,635 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local2123655513_0002
2016-01-14 20:05:55,635 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:05:55,641 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/6298687229_test_4E4BE812E3AA48108403C3C5B649983A/part-00000
2016-01-14 20:05:55,753 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:05:55,753 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:05:55,763 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B8734F57DC4F4AA384C3A8D1689465CF, ordinal: 0
2016-01-14 20:05:55,763 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[[0, 'count']]"][6298687229/test/]
2016-01-14 20:05:55,764 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-01-14 20:05:55,764 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B8734F57DC4F4AA384C3A8D1689465CF, mem on start (mb), free: 102, total: 323, max: 672
2016-01-14 20:05:55,766 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B8734F57DC4F4AA384C3A8D1689465CF, mem on close (mb), free: 102, total: 323, max: 672
2016-01-14 20:05:55,788 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:05:55,789 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:05:55,800 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A7880829960C4471870A848E20B451DB, ordinal: 1
2016-01-14 20:05:55,801 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-01-14 20:05:55,802 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/basicpipesplatform/testSimpleChain/simplechain"]
2016-01-14 20:05:55,802 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A7880829960C4471870A848E20B451DB, mem on start (mb), free: 100, total: 323, max: 672
2016-01-14 20:05:55,814 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A7880829960C4471870A848E20B451DB, mem on close (mb), free: 99, total: 323, max: 672
2016-01-14 20:05:55,842 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/basicpipesplatform/testSimpleChain/simplechain/_temporary
2016-01-14 20:05:55,842 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:01.728
2016-01-14 20:05:55,881 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/basicpipesplatform/testSimpleChain/simplechain
2016-01-14 20:05:55,904 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:05:55,905 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:05:55,962 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.049
2016-01-14 20:05:55,963 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:05:55,964 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:05:55,985 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting
2016-01-14 20:05:55,985 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 20:05:55,986 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount/count"]
2016-01-14 20:05:55,986 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] parallel execution of steps is enabled: false
2016-01-14 20:05:55,986 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executing total steps: 1
2016-01-14 20:05:55,987 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] allocating management threads: 1
2016-01-14 20:05:55,988 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting step: (1/1) ...splatform/testCount/count
2016-01-14 20:05:56,101 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity840855981/.staging/job_local840855981_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:56,103 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity840855981/.staging/job_local840855981_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:56,153 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_local840855981_0003/job_local840855981_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:56,154 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_local840855981_0003/job_local840855981_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:56,155 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] submitted hadoop job: job_local840855981_0003
2016-01-14 20:05:56,156 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] tracking url: http://localhost:8080/
2016-01-14 20:05:56,164 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/ips.20.txt
2016-01-14 20:05:56,269 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:05:56,269 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:05:56,278 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C256914E6C1B46218687C36C5E8DE43E, ordinal: 0
2016-01-14 20:05:56,279 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 20:05:56,279 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-01-14 20:05:56,279 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C256914E6C1B46218687C36C5E8DE43E, mem on start (mb), free: 58, total: 424, max: 672
2016-01-14 20:05:56,283 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C256914E6C1B46218687C36C5E8DE43E, mem on close (mb), free: 58, total: 424, max: 672
2016-01-14 20:05:56,305 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:05:56,306 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:05:56,314 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D8183B2DD042483788424E23E4F8DA3D, ordinal: 1
2016-01-14 20:05:56,315 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-01-14 20:05:56,315 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount/count"]
2016-01-14 20:05:56,315 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D8183B2DD042483788424E23E4F8DA3D, mem on start (mb), free: 55, total: 424, max: 672
2016-01-14 20:05:56,352 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D8183B2DD042483788424E23E4F8DA3D, mem on close (mb), free: 173, total: 482, max: 672
2016-01-14 20:05:56,393 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/basicpipesplatform/testCount/count/_temporary
2016-01-14 20:05:56,394 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] completed in: 00:00.408
2016-01-14 20:05:56,451 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/basicpipesplatform/testCount/count
2016-01-14 20:05:56,471 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:05:56,472 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:05:56,523 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.044
2016-01-14 20:05:56,524 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:05:56,524 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:05:56,536 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:05:56,536 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:05:56,537 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/basicpipesplatform/testSwap/swap"]
2016-01-14 20:05:56,537 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:05:56,537 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:05:56,538 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:05:56,538 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...pesplatform/testSwap/swap
2016-01-14 20:05:56,604 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity228520250/.staging/job_local228520250_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:56,605 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity228520250/.staging/job_local228520250_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:56,660 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_local228520250_0004/job_local228520250_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:56,661 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_local228520250_0004/job_local228520250_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:56,663 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local228520250_0004
2016-01-14 20:05:56,663 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:05:56,673 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:05:56,682 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:05:56,682 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:05:56,689 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AB186CB3E12840B7B1A0611965AD1941, ordinal: 0
2016-01-14 20:05:56,690 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:05:56,690 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/basicpipesplatform/testSwap/swap"]
2016-01-14 20:05:56,691 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AB186CB3E12840B7B1A0611965AD1941, mem on start (mb), free: 123, total: 482, max: 672
2016-01-14 20:05:56,694 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AB186CB3E12840B7B1A0611965AD1941, mem on close (mb), free: 123, total: 482, max: 672
2016-01-14 20:05:56,718 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/basicpipesplatform/testSwap/swap/_temporary
2016-01-14 20:05:56,719 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.182
2016-01-14 20:05:56,753 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/basicpipesplatform/testSwap/swap
2016-01-14 20:05:56,773 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:05:56,774 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:05:56,833 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.052
2016-01-14 20:05:56,835 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:05:56,835 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:05:56,852 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:05:56,852 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 20:05:56,853 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/basicpipesplatform/testUnGroup/ungrouped"]
2016-01-14 20:05:56,853 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:05:56,853 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:05:56,854 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:05:56,855 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...orm/testUnGroup/ungrouped
2016-01-14 20:05:56,937 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1310077509/.staging/job_local1310077509_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:56,938 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1310077509/.staging/job_local1310077509_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:56,987 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_local1310077509_0005/job_local1310077509_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:56,989 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_local1310077509_0005/job_local1310077509_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:56,989 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local1310077509_0005
2016-01-14 20:05:56,991 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:05:56,998 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:05:57,006 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:05:57,006 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:05:57,014 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CA7F700D10B34F0489B7F902D2966E81, ordinal: 0
2016-01-14 20:05:57,015 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-01-14 20:05:57,015 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/basicpipesplatform/testUnGroup/ungrouped"]
2016-01-14 20:05:57,015 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CA7F700D10B34F0489B7F902D2966E81, mem on start (mb), free: 79, total: 482, max: 672
2016-01-14 20:05:57,017 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CA7F700D10B34F0489B7F902D2966E81, mem on close (mb), free: 79, total: 482, max: 672
2016-01-14 20:05:57,036 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/basicpipesplatform/testUnGroup/ungrouped/_temporary
2016-01-14 20:05:57,036 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.183
2016-01-14 20:05:57,067 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/basicpipesplatform/testUnGroup/ungrouped
2016-01-14 20:05:57,090 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:05:57,090 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:05:57,164 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.069
2016-01-14 20:05:57,166 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:05:57,166 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:05:57,205 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] starting
2016-01-14 20:05:57,206 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/upper.txt"]
2016-01-14 20:05:57,206 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-01-14 20:05:57,207 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown"]
2016-01-14 20:05:57,207 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] parallel execution of steps is enabled: false
2016-01-14 20:05:57,208 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executing total steps: 1
2016-01-14 20:05:57,208 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] allocating management threads: 1
2016-01-14 20:05:57,209 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] starting step: (1/1) ...lexcogrouprelativeunknown
2016-01-14 20:05:57,303 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity855227238/.staging/job_local855227238_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:57,304 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity855227238/.staging/job_local855227238_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:57,343 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_local855227238_0006/job_local855227238_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:57,344 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_local855227238_0006/job_local855227238_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:57,345 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] submitted hadoop job: job_local855227238_0006
2016-01-14 20:05:57,346 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] tracking url: http://localhost:8080/
2016-01-14 20:05:57,354 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:05:57,459 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:05:57,459 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:05:57,468 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B55945598A5A4B81A4B3B486B92EA70A, ordinal: 0
2016-01-14 20:05:57,469 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/upper.txt"]
2016-01-14 20:05:57,470 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:-2] upper:[{1}:-2]]
2016-01-14 20:05:57,470 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B55945598A5A4B81A4B3B486B92EA70A, mem on start (mb), free: 149, total: 583, max: 672
2016-01-14 20:05:57,472 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B55945598A5A4B81A4B3B486B92EA70A, mem on close (mb), free: 149, total: 583, max: 672
2016-01-14 20:05:57,481 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:05:57,583 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:05:57,583 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:05:57,592 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B55945598A5A4B81A4B3B486B92EA70A, ordinal: 0
2016-01-14 20:05:57,593 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.txt"]
2016-01-14 20:05:57,593 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:-2] upper:[{1}:-2]]
2016-01-14 20:05:57,593 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B55945598A5A4B81A4B3B486B92EA70A, mem on start (mb), free: 95, total: 630, max: 672
2016-01-14 20:05:57,596 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B55945598A5A4B81A4B3B486B92EA70A, mem on close (mb), free: 95, total: 630, max: 672
2016-01-14 20:05:57,617 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:05:57,617 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:05:57,623 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: CC110EDF49334F9FA3F88D066E3C85E4, ordinal: 1
2016-01-14 20:05:57,623 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:-2] upper:[{1}:-2]]
2016-01-14 20:05:57,624 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown"]
2016-01-14 20:05:57,624 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CC110EDF49334F9FA3F88D066E3C85E4, mem on start (mb), free: 91, total: 630, max: 672
2016-01-14 20:05:57,636 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 20:05:57,636 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 20:05:57,645 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CC110EDF49334F9FA3F88D066E3C85E4, mem on close (mb), free: 89, total: 630, max: 672
2016-01-14 20:05:57,676 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/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown/_temporary
2016-01-14 20:05:57,677 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] completed in: 00:00.471
2016-01-14 20:05:57,723 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/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown
2016-01-14 20:05:57,742 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:05:57,743 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:05:57,785 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.038
2016-01-14 20:05:57,786 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:05:57,786 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:05:57,807 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:05:57,807 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:05:57,807 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/basicpipesplatform/testSimpleRelative/simplerelative"]
2016-01-14 20:05:57,808 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:05:57,808 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:05:57,808 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:05:57,809 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...leRelative/simplerelative
2016-01-14 20:05:57,869 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity915082654/.staging/job_local915082654_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:57,870 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity915082654/.staging/job_local915082654_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:57,908 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_local915082654_0007/job_local915082654_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:57,909 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_local915082654_0007/job_local915082654_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:57,909 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local915082654_0007
2016-01-14 20:05:57,910 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:05:57,916 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:05:58,142 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:05:58,142 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:05:58,150 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FB6418FD993C4333AA47024B0CEB4C40, ordinal: 0
2016-01-14 20:05:58,150 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:05:58,151 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-01-14 20:05:58,151 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FB6418FD993C4333AA47024B0CEB4C40, mem on start (mb), free: 134, total: 243, max: 672
2016-01-14 20:05:58,153 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FB6418FD993C4333AA47024B0CEB4C40, mem on close (mb), free: 134, total: 243, max: 672
2016-01-14 20:05:58,169 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:05:58,170 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:05:58,177 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F5968BE7024D4235AB8918B9A7E9ECC0, ordinal: 1
2016-01-14 20:05:58,177 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-01-14 20:05:58,178 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/basicpipesplatform/testSimpleRelative/simplerelative"]
2016-01-14 20:05:58,178 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F5968BE7024D4235AB8918B9A7E9ECC0, mem on start (mb), free: 129, total: 243, max: 672
2016-01-14 20:05:58,186 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F5968BE7024D4235AB8918B9A7E9ECC0, mem on close (mb), free: 129, total: 243, max: 672
2016-01-14 20:05:58,210 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/basicpipesplatform/testSimpleRelative/simplerelative/_temporary
2016-01-14 20:05:58,211 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.403
2016-01-14 20:05:58,244 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/basicpipesplatform/testSimpleRelative/simplerelative
2016-01-14 20:05:58,422 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:05:58,423 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:05:58,483 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.056
2016-01-14 20:05:58,484 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:05:58,484 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:05:58,507 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:05:58,507 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-01-14 20:05:58,507 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleResult/simpleresult"]
2016-01-14 20:05:58,507 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:05:58,508 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:05:58,508 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:05:58,508 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...SimpleResult/simpleresult
2016-01-14 20:05:58,571 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity27321441/.staging/job_local27321441_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:58,572 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity27321441/.staging/job_local27321441_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:58,608 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_local27321441_0008/job_local27321441_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:58,609 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_local27321441_0008/job_local27321441_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:58,609 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local27321441_0008
2016-01-14 20:05:58,609 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:05:58,617 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:05:58,643 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:05:58,644 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:05:58,654 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A4016AF9C288478EA2BA19268841EF26, ordinal: 0
2016-01-14 20:05:58,655 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-01-14 20:05:58,656 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-01-14 20:05:58,656 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A4016AF9C288478EA2BA19268841EF26, mem on start (mb), free: 269, total: 423, max: 672
2016-01-14 20:05:58,736 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A4016AF9C288478EA2BA19268841EF26, mem on close (mb), free: 265, total: 423, max: 672
2016-01-14 20:05:58,753 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:05:58,754 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:05:58,763 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A89AD7FE8707449AAC471A6537003EBD, ordinal: 1
2016-01-14 20:05:58,764 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-01-14 20:05:58,764 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleResult/simpleresult"]
2016-01-14 20:05:58,764 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A89AD7FE8707449AAC471A6537003EBD, mem on start (mb), free: 259, total: 423, max: 672
2016-01-14 20:05:58,772 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A89AD7FE8707449AAC471A6537003EBD, mem on close (mb), free: 258, total: 423, max: 672
2016-01-14 20:05:58,789 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/basicpipesplatform/testSimpleResult/simpleresult/_temporary
2016-01-14 20:05:58,790 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.282
2016-01-14 20:05:58,817 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/basicpipesplatform/testSimpleResult/simpleresult
2016-01-14 20:05:58,838 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:05:58,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:05:58,875 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.031
2016-01-14 20:05:58,877 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:05:58,877 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:05:58,887 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:05:58,887 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:05:58,888 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/basicpipesplatform/testFilterAll/filterall"]
2016-01-14 20:05:58,888 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:05:58,889 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:05:58,889 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:05:58,890 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...m/testFilterAll/filterall
2016-01-14 20:05:58,958 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity860533462/.staging/job_local860533462_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:58,959 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity860533462/.staging/job_local860533462_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:59,002 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_local860533462_0009/job_local860533462_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:59,002 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_local860533462_0009/job_local860533462_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:59,003 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local860533462_0009
2016-01-14 20:05:59,003 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:05:59,009 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:05:59,016 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:05:59,016 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:05:59,021 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D70D452978334F7B9D15C978A896C810, ordinal: 0
2016-01-14 20:05:59,022 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:05:59,022 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/basicpipesplatform/testFilterAll/filterall"]
2016-01-14 20:05:59,022 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D70D452978334F7B9D15C978A896C810, mem on start (mb), free: 429, total: 472, max: 672
2016-01-14 20:05:59,023 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D70D452978334F7B9D15C978A896C810, mem on close (mb), free: 429, total: 472, max: 672
2016-01-14 20:05:59,037 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/basicpipesplatform/testFilterAll/filterall/_temporary
2016-01-14 20:05:59,038 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.150
2016-01-14 20:05:59,066 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/basicpipesplatform/testFilterAll/filterall
2016-01-14 20:05:59,081 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:05:59,081 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:05:59,122 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.037
2016-01-14 20:05:59,123 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:05:59,123 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:05:59,135 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:05:59,136 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.txt"]
2016-01-14 20:05:59,136 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/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown"]
2016-01-14 20:05:59,136 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:05:59,136 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:05:59,137 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:05:59,138 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...own/simplerelativeunknown
2016-01-14 20:05:59,194 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity900341039/.staging/job_local900341039_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:59,195 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity900341039/.staging/job_local900341039_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:59,229 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_local900341039_0010/job_local900341039_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:59,230 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_local900341039_0010/job_local900341039_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:59,230 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local900341039_0010
2016-01-14 20:05:59,231 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:05:59,237 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:05:59,272 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:05:59,273 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:05:59,279 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BF047727384A49BE876C5918EFE8F907, ordinal: 0
2016-01-14 20:05:59,279 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.txt"]
2016-01-14 20:05:59,279 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:-1]]
2016-01-14 20:05:59,280 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BF047727384A49BE876C5918EFE8F907, mem on start (mb), free: 275, total: 472, max: 672
2016-01-14 20:05:59,281 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BF047727384A49BE876C5918EFE8F907, mem on close (mb), free: 275, total: 472, max: 672
2016-01-14 20:05:59,302 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:05:59,302 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:05:59,308 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: EA757175185447389841EB629DDACDFF, ordinal: 1
2016-01-14 20:05:59,309 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:-1]]
2016-01-14 20:05:59,310 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/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown"]
2016-01-14 20:05:59,310 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: EA757175185447389841EB629DDACDFF, mem on start (mb), free: 268, total: 472, max: 672
2016-01-14 20:05:59,319 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: EA757175185447389841EB629DDACDFF, mem on close (mb), free: 266, total: 472, max: 672
2016-01-14 20:05:59,340 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/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown/_temporary
2016-01-14 20:05:59,342 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.205
2016-01-14 20:05:59,374 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/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown
2016-01-14 20:05:59,392 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:05:59,393 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:05:59,437 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.039
2016-01-14 20:05:59,437 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:05:59,438 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:05:59,463 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] starting
2016-01-14 20:05:59,463 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/upper.txt"]
2016-01-14 20:05:59,463 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-01-14 20:05:59,464 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroup/complexcogroup"]
2016-01-14 20:05:59,464 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] parallel execution of steps is enabled: false
2016-01-14 20:05:59,464 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executing total steps: 1
2016-01-14 20:05:59,465 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] allocating management threads: 1
2016-01-14 20:05:59,466 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] starting step: (1/1) ...estCoGroup/complexcogroup
2016-01-14 20:05:59,533 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity696144502/.staging/job_local696144502_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:59,534 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity696144502/.staging/job_local696144502_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:59,571 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_local696144502_0011/job_local696144502_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:59,572 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_local696144502_0011/job_local696144502_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:59,572 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] submitted hadoop job: job_local696144502_0011
2016-01-14 20:05:59,573 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] tracking url: http://localhost:8080/
2016-01-14 20:05:59,578 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:05:59,592 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:05:59,592 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:05:59,600 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F365A5EEFC824FBCB3C8EE7C6DB5EBF6, ordinal: 0
2016-01-14 20:05:59,601 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/upper.txt"]
2016-01-14 20:05:59,601 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:0] upper:[{1}:0]]
2016-01-14 20:05:59,601 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F365A5EEFC824FBCB3C8EE7C6DB5EBF6, mem on start (mb), free: 332, total: 475, max: 672
2016-01-14 20:05:59,603 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F365A5EEFC824FBCB3C8EE7C6DB5EBF6, mem on close (mb), free: 332, total: 475, max: 672
2016-01-14 20:05:59,610 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:05:59,628 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:05:59,629 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:05:59,635 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F365A5EEFC824FBCB3C8EE7C6DB5EBF6, ordinal: 0
2016-01-14 20:05:59,636 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-01-14 20:05:59,636 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:0] upper:[{1}:0]]
2016-01-14 20:05:59,636 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F365A5EEFC824FBCB3C8EE7C6DB5EBF6, mem on start (mb), free: 362, total: 475, max: 672
2016-01-14 20:05:59,638 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F365A5EEFC824FBCB3C8EE7C6DB5EBF6, mem on close (mb), free: 362, total: 475, max: 672
2016-01-14 20:05:59,655 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:05:59,655 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:05:59,661 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: FE508BE4F73C4D169D50530E73002E3C, ordinal: 1
2016-01-14 20:05:59,662 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:0] upper:[{1}:0]]
2016-01-14 20:05:59,662 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroup/complexcogroup"]
2016-01-14 20:05:59,663 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FE508BE4F73C4D169D50530E73002E3C, mem on start (mb), free: 355, total: 475, max: 672
2016-01-14 20:05:59,669 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 20:05:59,669 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 20:05:59,671 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FE508BE4F73C4D169D50530E73002E3C, mem on close (mb), free: 354, total: 475, max: 672
2016-01-14 20:05:59,693 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/basicpipesplatform/testCoGroup/complexcogroup/_temporary
2016-01-14 20:05:59,694 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] completed in: 00:00.230
2016-01-14 20:05:59,744 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/basicpipesplatform/testCoGroup/complexcogroup
2016-01-14 20:05:59,758 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:05:59,759 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:05:59,784 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-01-14 20:05:59,785 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:05:59,785 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:05:59,793 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:05:59,793 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:05:59,794 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/basicpipesplatform/testReplace/replace"]
2016-01-14 20:05:59,794 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:05:59,794 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:05:59,794 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:05:59,795 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...tform/testReplace/replace
2016-01-14 20:05:59,851 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity449761447/.staging/job_local449761447_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:59,852 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity449761447/.staging/job_local449761447_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:59,886 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_local449761447_0012/job_local449761447_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:05:59,886 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_local449761447_0012/job_local449761447_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:05:59,887 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local449761447_0012
2016-01-14 20:05:59,887 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:05:59,892 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:05:59,898 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:05:59,898 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:05:59,904 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DF6D53472A664B4B8187840738A1125B, ordinal: 0
2016-01-14 20:05:59,905 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:05:59,905 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/basicpipesplatform/testReplace/replace"]
2016-01-14 20:05:59,905 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DF6D53472A664B4B8187840738A1125B, mem on start (mb), free: 299, total: 475, max: 672
2016-01-14 20:05:59,908 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DF6D53472A664B4B8187840738A1125B, mem on close (mb), free: 299, total: 475, max: 672
2016-01-14 20:05:59,928 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/basicpipesplatform/testReplace/replace/_temporary
2016-01-14 20:05:59,929 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.134
2016-01-14 20:05:59,951 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/basicpipesplatform/testReplace/replace
2016-01-14 20:05:59,964 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:05:59,964 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:06:00,005 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.037
2016-01-14 20:06:00,006 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:06:00,006 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:06:00,023 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting
2016-01-14 20:06:00,024 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 20:06:00,024 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount2/count2"]
2016-01-14 20:06:00,024 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] parallel execution of steps is enabled: false
2016-01-14 20:06:00,025 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executing total steps: 1
2016-01-14 20:06:00,025 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] allocating management threads: 1
2016-01-14 20:06:00,027 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting step: (1/1) ...latform/testCount2/count2
2016-01-14 20:06:00,085 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity54139990/.staging/job_local54139990_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:06:00,086 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity54139990/.staging/job_local54139990_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:06:00,123 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_local54139990_0013/job_local54139990_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:06:00,123 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_local54139990_0013/job_local54139990_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:06:00,124 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] submitted hadoop job: job_local54139990_0013
2016-01-14 20:06:00,124 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] tracking url: http://localhost:8080/
2016-01-14 20:06:00,131 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/ips.20.txt
2016-01-14 20:06:00,150 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:06:00,150 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:06:00,155 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F15CB742AED04E719ECCCAD55302F89C, ordinal: 0
2016-01-14 20:06:00,156 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 20:06:00,156 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-01-14 20:06:00,156 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F15CB742AED04E719ECCCAD55302F89C, mem on start (mb), free: 367, total: 481, max: 672
2016-01-14 20:06:00,159 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F15CB742AED04E719ECCCAD55302F89C, mem on close (mb), free: 367, total: 481, max: 672
2016-01-14 20:06:00,177 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:06:00,177 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:06:00,182 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B3CB7FDAA51B456B8D5EB67796B8D08F, ordinal: 1
2016-01-14 20:06:00,182 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-01-14 20:06:00,183 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount2/count2"]
2016-01-14 20:06:00,183 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B3CB7FDAA51B456B8D5EB67796B8D08F, mem on start (mb), free: 360, total: 481, max: 672
2016-01-14 20:06:00,192 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B3CB7FDAA51B456B8D5EB67796B8D08F, mem on close (mb), free: 359, total: 481, max: 672
2016-01-14 20:06:00,215 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/basicpipesplatform/testCount2/count2/_temporary
2016-01-14 20:06:00,215 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] completed in: 00:00.192
2016-01-14 20:06:00,258 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/basicpipesplatform/testCount2/count2
2016-01-14 20:06:00,271 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:06:00,271 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:06:00,299 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.023
2016-01-14 20:06:00,299 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:06:00,299 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:06:00,312 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting
2016-01-14 20:06:00,312 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 20:06:00,312 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount3/count3"]
2016-01-14 20:06:00,312 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] parallel execution of steps is enabled: false
2016-01-14 20:06:00,313 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executing total steps: 1
2016-01-14 20:06:00,313 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] allocating management threads: 1
2016-01-14 20:06:00,314 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting step: (1/1) ...latform/testCount3/count3
2016-01-14 20:06:00,373 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity707860098/.staging/job_local707860098_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:06:00,374 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity707860098/.staging/job_local707860098_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:06:00,406 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_local707860098_0014/job_local707860098_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:06:00,407 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_local707860098_0014/job_local707860098_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:06:00,407 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] submitted hadoop job: job_local707860098_0014
2016-01-14 20:06:00,408 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] tracking url: http://localhost:8080/
2016-01-14 20:06:00,413 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/ips.20.txt
2016-01-14 20:06:00,433 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:06:00,433 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:06:00,437 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C8652DC29F3348E5918B4489BE0043F2, ordinal: 0
2016-01-14 20:06:00,438 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 20:06:00,438 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-01-14 20:06:00,438 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C8652DC29F3348E5918B4489BE0043F2, mem on start (mb), free: 368, total: 481, max: 672
2016-01-14 20:06:00,444 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C8652DC29F3348E5918B4489BE0043F2, mem on close (mb), free: 368, total: 481, max: 672
2016-01-14 20:06:00,460 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:06:00,461 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:06:00,466 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DD85AC54DCF5406B9A32CE640A5EB0E5, ordinal: 1
2016-01-14 20:06:00,466 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-01-14 20:06:00,466 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount3/count3"]
2016-01-14 20:06:00,467 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DD85AC54DCF5406B9A32CE640A5EB0E5, mem on start (mb), free: 362, total: 481, max: 672
2016-01-14 20:06:00,477 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DD85AC54DCF5406B9A32CE640A5EB0E5, mem on close (mb), free: 361, total: 481, max: 672
2016-01-14 20:06:00,495 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/basicpipesplatform/testCount3/count3/_temporary
2016-01-14 20:06:00,496 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] completed in: 00:00.183
2016-01-14 20:06:00,543 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/basicpipesplatform/testCount3/count3
2016-01-14 20:06:00,556 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:06:00,557 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:06:00,582 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-01-14 20:06:00,582 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:06:00,583 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 20:06:00,594 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting
2016-01-14 20:06:00,594 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 20:06:00,595 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount4/count4"]
2016-01-14 20:06:00,595 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] parallel execution of steps is enabled: false
2016-01-14 20:06:00,595 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] executing total steps: 1
2016-01-14 20:06:00,595 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] allocating management threads: 1
2016-01-14 20:06:00,596 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] starting step: (1/1) ...latform/testCount4/count4
2016-01-14 20:06:00,651 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity600076735/.staging/job_local600076735_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:06:00,652 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity600076735/.staging/job_local600076735_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:06:00,683 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_local600076735_0015/job_local600076735_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:06:00,684 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_local600076735_0015/job_local600076735_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:06:00,685 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] submitted hadoop job: job_local600076735_0015
2016-01-14 20:06:00,686 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] tracking url: http://localhost:8080/
2016-01-14 20:06:00,690 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/ips.20.txt
2016-01-14 20:06:00,708 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:06:00,709 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:06:00,713 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BE98A1EA79714D528A94217095439D85, ordinal: 0
2016-01-14 20:06:00,714 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-01-14 20:06:00,714 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-01-14 20:06:00,714 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BE98A1EA79714D528A94217095439D85, mem on start (mb), free: 368, total: 480, max: 672
2016-01-14 20:06:00,717 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BE98A1EA79714D528A94217095439D85, mem on close (mb), free: 368, total: 480, max: 672
2016-01-14 20:06:00,735 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:06:00,735 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:06:00,744 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DA7B6D16199D48D69697F131BC7292B4, ordinal: 1
2016-01-14 20:06:00,745 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-01-14 20:06:00,745 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount4/count4"]
2016-01-14 20:06:00,745 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DA7B6D16199D48D69697F131BC7292B4, mem on start (mb), free: 362, total: 480, max: 672
2016-01-14 20:06:00,755 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DA7B6D16199D48D69697F131BC7292B4, mem on close (mb), free: 360, total: 480, max: 672
2016-01-14 20:06:00,775 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/basicpipesplatform/testCount4/count4/_temporary
2016-01-14 20:06:00,776 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [count] completed in: 00:00.181
2016-01-14 20:06:00,820 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/basicpipesplatform/testCount4/count4
2016-01-14 20:06:00,832 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:06:00,833 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:06:00,855 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.019
2016-01-14 20:06:00,856 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 20:06:00,856 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:06:00,863 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:06:00,863 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:06:00,864 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/basicpipesplatform/testFilter/filter"]
2016-01-14 20:06:00,864 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:06:00,864 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:06:00,864 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:06:00,865 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...latform/testFilter/filter
2016-01-14 20:06:00,916 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1534367349/.staging/job_local1534367349_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:06:00,917 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1534367349/.staging/job_local1534367349_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:06:00,947 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_local1534367349_0016/job_local1534367349_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:06:00,948 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_local1534367349_0016/job_local1534367349_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:06:00,949 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local1534367349_0016
2016-01-14 20:06:00,950 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:06:00,953 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:06:00,959 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:06:00,959 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:06:00,964 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E341B78C94874A9AA7C2CC00C72F5016, ordinal: 0
2016-01-14 20:06:00,965 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:06:00,965 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/basicpipesplatform/testFilter/filter"]
2016-01-14 20:06:00,965 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E341B78C94874A9AA7C2CC00C72F5016, mem on start (mb), free: 307, total: 480, max: 672
2016-01-14 20:06:00,967 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E341B78C94874A9AA7C2CC00C72F5016, mem on close (mb), free: 307, total: 480, max: 672
2016-01-14 20:06:00,983 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/basicpipesplatform/testFilter/filter/_temporary
2016-01-14 20:06:00,983 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.119
2016-01-14 20:06:01,003 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/basicpipesplatform/testFilter/filter
2016-01-14 20:06:01,020 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 20:06:01,020 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:06:01,049 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.025
2016-01-14 20:06:01,050 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 20:06:01,050 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:06:01,067 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 20:06:01,067 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:06:01,067 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimple/simple"]
2016-01-14 20:06:01,068 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 20:06:01,068 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 20:06:01,068 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 20:06:01,071 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...latform/testSimple/simple
2016-01-14 20:06:01,131 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1675269084/.staging/job_local1675269084_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:06:01,131 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/tmp/cascading/staging/teamcity1675269084/.staging/job_local1675269084_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:06:01,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_local1675269084_0017/job_local1675269084_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-01-14 20:06:01,165 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_local1675269084_0017/job_local1675269084_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-01-14 20:06:01,165 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local1675269084_0017
2016-01-14 20:06:01,166 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 20:06:01,169 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:06:01,188 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 20:06:01,188 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 20:06:01,194 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BFC5812CB7684AF6A26831652CFF7F38, ordinal: 0
2016-01-14 20:06:01,195 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-01-14 20:06:01,195 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-01-14 20:06:01,195 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BFC5812CB7684AF6A26831652CFF7F38, mem on start (mb), free: 367, total: 481, max: 672
2016-01-14 20:06:01,198 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BFC5812CB7684AF6A26831652CFF7F38, mem on close (mb), free: 367, total: 481, max: 672
2016-01-14 20:06:01,212 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 20:06:01,212 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 20:06:01,218 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D50F4B23CDFA4BD7AA27DC43CB26B674, ordinal: 1
2016-01-14 20:06:01,218 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-01-14 20:06:01,219 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimple/simple"]
2016-01-14 20:06:01,219 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D50F4B23CDFA4BD7AA27DC43CB26B674, mem on start (mb), free: 362, total: 481, max: 672
2016-01-14 20:06:01,227 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D50F4B23CDFA4BD7AA27DC43CB26B674, mem on close (mb), free: 361, total: 481, max: 672
2016-01-14 20:06:01,242 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/basicpipesplatform/testSimple/simple/_temporary
2016-01-14 20:06:01,243 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:00.175
2016-01-14 20:06:01,265 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/basicpipesplatform/testSimple/simple