2016-05-18 01:48:54,840 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 01:48:54,869 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.BasicPipesPlatformTest, with platform: hadoop2-mr1
2016-05-18 01:48:54,903 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-05-18 01:48:55,464 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-05-18 01:48:55,661 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 01:48:55,808 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:48:55,811 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:48:55,924 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 4747FC3825FE4175A2C6FAA02E2D4F45
2016-05-18 01:48:56,152 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.165
2016-05-18 01:48:56,157 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 2, nodes: 4
2016-05-18 01:48:56,157 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:48:56,357 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 01:48:56,358 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:48:56,359 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:48:56,360 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleChain/simplechain"]
2016-05-18 01:48:56,360 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:48:56,362 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 2
2016-05-18 01:48:56,362 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:48:56,363 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/2)
2016-05-18 01:48:56,907 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity876384332/.staging/job_local876384332_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:48:56,919 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity876384332/.staging/job_local876384332_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:48:57,086 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local876384332_0001/job_local876384332_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:48:57,093 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local876384332_0001/job_local876384332_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:48:57,101 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local876384332_0001
2016-05-18 01:48:57,102 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:48:57,217 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt
2016-05-18 01:48:57,361 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:48:57,362 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:48:57,376 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BDAEBF69C3C7426D986002949E62F7D4, ordinal: 0
2016-05-18 01:48:57,409 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:48:57,409 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-05-18 01:48:57,410 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BDAEBF69C3C7426D986002949E62F7D4, mem on start (mb), free: 140, total: 281, max: 672
2016-05-18 01:48:57,419 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BDAEBF69C3C7426D986002949E62F7D4, mem on close (mb), free: 139, total: 281, max: 672
2016-05-18 01:48:57,533 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:48:57,533 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:48:57,545 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B2CFF018210B413EBF94171463A595B1, ordinal: 1
2016-05-18 01:48:57,550 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-05-18 01:48:57,550 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: TempHfs["SequenceFile[[0, 'count']]"][3277318275/test/]
2016-05-18 01:48:57,551 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B2CFF018210B413EBF94171463A595B1, mem on start (mb), free: 128, total: 281, max: 672
2016-05-18 01:48:57,580 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B2CFF018210B413EBF94171463A595B1, mem on close (mb), free: 127, total: 281, max: 672
2016-05-18 01:48:57,605 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (2/2) ...stSimpleChain/simplechain
2016-05-18 01:48:57,692 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity2107864324/.staging/job_local2107864324_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:48:57,693 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity2107864324/.staging/job_local2107864324_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:48:57,775 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2107864324_0002/job_local2107864324_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:48:57,778 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2107864324_0002/job_local2107864324_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:48:57,779 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local2107864324_0002
2016-05-18 01:48:57,779 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:48:57,785 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/3277318275_test_66F4F2C5AD7D441FB5AA07AF32888A73/part-00000
2016-05-18 01:48:57,890 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:48:57,891 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:48:57,900 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C9C6CC6961D949F086085BDE4B9C7F70, ordinal: 0
2016-05-18 01:48:57,901 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: TempHfs["SequenceFile[[0, 'count']]"][3277318275/test/]
2016-05-18 01:48:57,901 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-05-18 01:48:57,901 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C9C6CC6961D949F086085BDE4B9C7F70, mem on start (mb), free: 94, total: 382, max: 672
2016-05-18 01:48:57,903 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C9C6CC6961D949F086085BDE4B9C7F70, mem on close (mb), free: 94, total: 382, max: 672
2016-05-18 01:48:57,923 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:48:57,925 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:48:57,945 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D307FB8828904B72985CBDFEAE53B202, ordinal: 1
2016-05-18 01:48:57,947 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-05-18 01:48:57,948 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleChain/simplechain"]
2016-05-18 01:48:57,948 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D307FB8828904B72985CBDFEAE53B202, mem on start (mb), free: 90, total: 382, max: 672
2016-05-18 01:48:57,962 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D307FB8828904B72985CBDFEAE53B202, mem on close (mb), free: 89, total: 382, max: 672
2016-05-18 01:48:57,991 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleChain/simplechain/_temporary
2016-05-18 01:48:57,991 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:01.630
2016-05-18 01:48:58,042 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testSimpleChain/simplechain
2016-05-18 01:48:58,073 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:48:58,074 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:48:58,156 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.073
2016-05-18 01:48:58,159 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:48:58,160 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:48:58,180 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting
2016-05-18 01:48:58,181 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 01:48:58,181 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount/count"]
2016-05-18 01:48:58,182 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] parallel execution of steps is enabled: false
2016-05-18 01:48:58,182 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executing total steps: 1
2016-05-18 01:48:58,182 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] allocating management threads: 1
2016-05-18 01:48:58,183 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting step: (1/1) ...splatform/testCount/count
2016-05-18 01:48:58,314 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity856847636/.staging/job_local856847636_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:48:58,317 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity856847636/.staging/job_local856847636_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:48:58,419 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local856847636_0003/job_local856847636_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:48:58,420 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local856847636_0003/job_local856847636_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:48:58,421 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] submitted hadoop job: job_local856847636_0003
2016-05-18 01:48:58,421 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] tracking url: http://localhost:8080/
2016-05-18 01:48:58,429 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt
2016-05-18 01:48:58,457 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:48:58,457 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:48:58,465 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AD19B5C16D0D4434897E304122A247C7, ordinal: 0
2016-05-18 01:48:58,465 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 01:48:58,466 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-05-18 01:48:58,466 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AD19B5C16D0D4434897E304122A247C7, mem on start (mb), free: 58, total: 382, max: 672
2016-05-18 01:48:58,470 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AD19B5C16D0D4434897E304122A247C7, mem on close (mb), free: 58, total: 382, max: 672
2016-05-18 01:48:58,498 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:48:58,498 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:48:58,506 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: AB46EF96A57E4718AFC8FADB627A4BE0, ordinal: 1
2016-05-18 01:48:58,506 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-05-18 01:48:58,507 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount/count"]
2016-05-18 01:48:58,507 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AB46EF96A57E4718AFC8FADB627A4BE0, mem on start (mb), free: 53, total: 382, max: 672
2016-05-18 01:48:58,544 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AB46EF96A57E4718AFC8FADB627A4BE0, mem on close (mb), free: 288, total: 498, max: 672
2016-05-18 01:48:58,575 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount/count/_temporary
2016-05-18 01:48:58,575 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] completed in: 00:00.394
2016-05-18 01:48:58,638 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testCount/count
2016-05-18 01:48:58,657 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:48:58,658 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:48:58,705 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.037
2016-05-18 01:48:58,705 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 01:48:58,706 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:48:58,719 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:48:58,720 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:48:58,720 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSwap/swap"]
2016-05-18 01:48:58,720 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:48:58,720 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:48:58,720 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:48:58,721 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...pesplatform/testSwap/swap
2016-05-18 01:48:58,784 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1346081858/.staging/job_local1346081858_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:48:58,785 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1346081858/.staging/job_local1346081858_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:48:58,833 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1346081858_0004/job_local1346081858_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:48:58,834 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1346081858_0004/job_local1346081858_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:48:58,835 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1346081858_0004
2016-05-18 01:48:58,835 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:48:58,844 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt
2016-05-18 01:48:58,852 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:48:58,853 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:48:58,862 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F88471A8EA6E4FFFB7B62AC1B81E9D92, ordinal: 0
2016-05-18 01:48:58,862 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:48:58,863 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSwap/swap"]
2016-05-18 01:48:58,863 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F88471A8EA6E4FFFB7B62AC1B81E9D92, mem on start (mb), free: 222, total: 498, max: 672
2016-05-18 01:48:58,865 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F88471A8EA6E4FFFB7B62AC1B81E9D92, mem on close (mb), free: 222, total: 498, max: 672
2016-05-18 01:48:58,884 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSwap/swap/_temporary
2016-05-18 01:48:58,884 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.164
2016-05-18 01:48:58,923 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testSwap/swap
2016-05-18 01:48:58,947 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:48:58,948 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:48:59,007 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.052
2016-05-18 01:48:59,009 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 01:48:59,010 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:48:59,029 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:48:59,030 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 01:48:59,031 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testUnGroup/ungrouped"]
2016-05-18 01:48:59,031 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:48:59,031 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:48:59,031 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:48:59,032 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...orm/testUnGroup/ungrouped
2016-05-18 01:48:59,094 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity787435451/.staging/job_local787435451_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:48:59,095 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity787435451/.staging/job_local787435451_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:48:59,129 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local787435451_0005/job_local787435451_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:48:59,130 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local787435451_0005/job_local787435451_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:48:59,131 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local787435451_0005
2016-05-18 01:48:59,131 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:48:59,137 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower+upper.txt
2016-05-18 01:48:59,144 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:48:59,144 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:48:59,152 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F34DB3FEA7474F85B63CF0405CC22F88, ordinal: 0
2016-05-18 01:48:59,153 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 01:48:59,153 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testUnGroup/ungrouped"]
2016-05-18 01:48:59,153 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F34DB3FEA7474F85B63CF0405CC22F88, mem on start (mb), free: 168, total: 498, max: 672
2016-05-18 01:48:59,156 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F34DB3FEA7474F85B63CF0405CC22F88, mem on close (mb), free: 168, total: 498, max: 672
2016-05-18 01:48:59,177 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testUnGroup/ungrouped/_temporary
2016-05-18 01:48:59,178 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.148
2016-05-18 01:48:59,201 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testUnGroup/ungrouped
2016-05-18 01:48:59,221 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:48:59,221 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:48:59,282 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.056
2016-05-18 01:48:59,283 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:48:59,284 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:48:59,315 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting
2016-05-18 01:48:59,316 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/upper.txt"]
2016-05-18 01:48:59,317 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-05-18 01:48:59,317 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown"]
2016-05-18 01:48:59,318 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] parallel execution of steps is enabled: false
2016-05-18 01:48:59,318 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executing total steps: 1
2016-05-18 01:48:59,319 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] allocating management threads: 1
2016-05-18 01:48:59,320 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting step: (1/1) ...lexcogrouprelativeunknown
2016-05-18 01:48:59,393 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1803922869/.staging/job_local1803922869_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:48:59,395 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1803922869/.staging/job_local1803922869_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:48:59,446 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1803922869_0006/job_local1803922869_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:48:59,447 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1803922869_0006/job_local1803922869_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:48:59,448 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] submitted hadoop job: job_local1803922869_0006
2016-05-18 01:48:59,448 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] tracking url: http://localhost:8080/
2016-05-18 01:48:59,457 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/upper.txt
2016-05-18 01:48:59,492 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:48:59,493 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:48:59,502 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F91730E74A91484DBDB315847C7879AB, ordinal: 0
2016-05-18 01:48:59,504 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/upper.txt"]
2016-05-18 01:48:59,504 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:-2] upper:[{1}:-2]]
2016-05-18 01:48:59,504 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F91730E74A91484DBDB315847C7879AB, mem on start (mb), free: 184, total: 498, max: 672
2016-05-18 01:48:59,507 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F91730E74A91484DBDB315847C7879AB, mem on close (mb), free: 184, total: 498, max: 672
2016-05-18 01:48:59,516 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt
2016-05-18 01:48:59,568 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:48:59,568 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:48:59,576 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F91730E74A91484DBDB315847C7879AB, ordinal: 0
2016-05-18 01:48:59,576 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-05-18 01:48:59,576 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:-2] upper:[{1}:-2]]
2016-05-18 01:48:59,577 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F91730E74A91484DBDB315847C7879AB, mem on start (mb), free: 82, total: 498, max: 672
2016-05-18 01:48:59,578 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F91730E74A91484DBDB315847C7879AB, mem on close (mb), free: 82, total: 498, max: 672
2016-05-18 01:48:59,600 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:48:59,601 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:48:59,613 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E663C57BCBC9496E8F3421E0C78DB25A, ordinal: 1
2016-05-18 01:48:59,614 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:-2] upper:[{1}:-2]]
2016-05-18 01:48:59,614 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown"]
2016-05-18 01:48:59,615 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E663C57BCBC9496E8F3421E0C78DB25A, mem on start (mb), free: 74, total: 498, max: 672
2016-05-18 01:48:59,631 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 01:48:59,631 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 01:48:59,638 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E663C57BCBC9496E8F3421E0C78DB25A, mem on close (mb), free: 72, total: 498, max: 672
2016-05-18 01:48:59,660 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown/_temporary
2016-05-18 01:48:59,660 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] completed in: 00:00.344
2016-05-18 01:48:59,716 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testCoGroupRelativeUnknown/complexcogrouprelativeunknown
2016-05-18 01:48:59,738 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:48:59,739 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:48:59,799 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.035
2016-05-18 01:48:59,800 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:48:59,800 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:48:59,822 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:48:59,823 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:48:59,824 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleRelative/simplerelative"]
2016-05-18 01:48:59,824 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:48:59,825 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:48:59,826 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:48:59,827 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...leRelative/simplerelative
2016-05-18 01:48:59,883 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1781288346/.staging/job_local1781288346_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:48:59,884 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1781288346/.staging/job_local1781288346_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:48:59,919 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1781288346_0007/job_local1781288346_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:48:59,920 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1781288346_0007/job_local1781288346_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:48:59,921 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1781288346_0007
2016-05-18 01:48:59,921 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:48:59,928 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt
2016-05-18 01:48:59,942 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:48:59,943 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:48:59,949 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B1FC83853E50403DBAA157900BBB5811, ordinal: 0
2016-05-18 01:48:59,949 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:48:59,950 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-05-18 01:48:59,950 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B1FC83853E50403DBAA157900BBB5811, mem on start (mb), free: 142, total: 492, max: 672
2016-05-18 01:48:59,952 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B1FC83853E50403DBAA157900BBB5811, mem on close (mb), free: 142, total: 492, max: 672
2016-05-18 01:48:59,971 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:48:59,971 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:48:59,978 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: C81E64971D77445EBB8D4B59557D5BAA, ordinal: 1
2016-05-18 01:48:59,979 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-05-18 01:48:59,980 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleRelative/simplerelative"]
2016-05-18 01:48:59,980 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C81E64971D77445EBB8D4B59557D5BAA, mem on start (mb), free: 134, total: 492, max: 672
2016-05-18 01:48:59,989 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C81E64971D77445EBB8D4B59557D5BAA, mem on close (mb), free: 132, total: 492, max: 672
2016-05-18 01:49:00,012 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleRelative/simplerelative/_temporary
2016-05-18 01:49:00,013 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.190
2016-05-18 01:49:00,037 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testSimpleRelative/simplerelative
2016-05-18 01:49:00,175 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:49:00,176 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:49:00,228 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.048
2016-05-18 01:49:00,229 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:49:00,229 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:49:00,252 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:49:00,253 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-05-18 01:49:00,253 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleResult/simpleresult"]
2016-05-18 01:49:00,253 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:49:00,253 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:49:00,253 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:49:00,254 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...SimpleResult/simpleresult
2016-05-18 01:49:00,310 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity2110837395/.staging/job_local2110837395_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:00,312 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity2110837395/.staging/job_local2110837395_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:00,356 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2110837395_0008/job_local2110837395_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:00,357 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2110837395_0008/job_local2110837395_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:00,358 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local2110837395_0008
2016-05-18 01:49:00,358 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:49:00,366 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt
2016-05-18 01:49:00,394 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:49:00,394 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:49:00,403 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B102DD9450D34E799925A2DC26920144, ordinal: 0
2016-05-18 01:49:00,405 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-05-18 01:49:00,405 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-05-18 01:49:00,406 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B102DD9450D34E799925A2DC26920144, mem on start (mb), free: 174, total: 486, max: 672
2016-05-18 01:49:00,484 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B102DD9450D34E799925A2DC26920144, mem on close (mb), free: 169, total: 486, max: 672
2016-05-18 01:49:00,501 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:49:00,501 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:49:00,509 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A2C2858F65CA48D7912B0612F3FC4CA7, ordinal: 1
2016-05-18 01:49:00,510 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-05-18 01:49:00,510 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleResult/simpleresult"]
2016-05-18 01:49:00,510 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A2C2858F65CA48D7912B0612F3FC4CA7, mem on start (mb), free: 162, total: 486, max: 672
2016-05-18 01:49:00,519 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A2C2858F65CA48D7912B0612F3FC4CA7, mem on close (mb), free: 160, total: 486, max: 672
2016-05-18 01:49:00,543 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleResult/simpleresult/_temporary
2016-05-18 01:49:00,543 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.290
2016-05-18 01:49:00,566 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testSimpleResult/simpleresult
2016-05-18 01:49:00,585 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:49:00,585 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:49:00,612 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.023
2016-05-18 01:49:00,613 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 01:49:00,613 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:49:00,624 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:49:00,625 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:49:00,625 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testFilterAll/filterall"]
2016-05-18 01:49:00,625 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:49:00,625 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:49:00,625 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:49:00,626 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...m/testFilterAll/filterall
2016-05-18 01:49:00,683 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1076067967/.staging/job_local1076067967_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:00,683 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1076067967/.staging/job_local1076067967_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:00,723 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1076067967_0009/job_local1076067967_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:00,724 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1076067967_0009/job_local1076067967_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:00,725 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1076067967_0009
2016-05-18 01:49:00,725 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:49:00,730 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt
2016-05-18 01:49:00,736 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:49:00,736 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:49:00,744 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A0538792E7AC4519831CE484AA9411E0, ordinal: 0
2016-05-18 01:49:00,745 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:49:00,746 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testFilterAll/filterall"]
2016-05-18 01:49:00,746 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A0538792E7AC4519831CE484AA9411E0, mem on start (mb), free: 108, total: 486, max: 672
2016-05-18 01:49:00,748 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A0538792E7AC4519831CE484AA9411E0, mem on close (mb), free: 108, total: 486, max: 672
2016-05-18 01:49:00,768 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testFilterAll/filterall/_temporary
2016-05-18 01:49:00,769 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.144
2016-05-18 01:49:00,793 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testFilterAll/filterall
2016-05-18 01:49:00,808 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:49:00,808 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:49:00,854 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.040
2016-05-18 01:49:00,855 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:49:00,856 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:49:00,870 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:49:00,870 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-05-18 01:49:00,871 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown"]
2016-05-18 01:49:00,871 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:49:00,871 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:49:00,871 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:49:00,872 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...own/simplerelativeunknown
2016-05-18 01:49:00,926 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity392537886/.staging/job_local392537886_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:00,927 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity392537886/.staging/job_local392537886_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:00,986 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local392537886_0010/job_local392537886_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:00,988 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local392537886_0010/job_local392537886_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:00,989 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local392537886_0010
2016-05-18 01:49:00,989 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:49:00,996 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt
2016-05-18 01:49:01,018 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:49:01,018 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:49:01,024 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B7E945C35B5E440B8A8D5286706581D4, ordinal: 0
2016-05-18 01:49:01,025 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-05-18 01:49:01,025 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:-1]]
2016-05-18 01:49:01,025 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B7E945C35B5E440B8A8D5286706581D4, mem on start (mb), free: 180, total: 494, max: 672
2016-05-18 01:49:01,028 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B7E945C35B5E440B8A8D5286706581D4, mem on close (mb), free: 180, total: 494, max: 672
2016-05-18 01:49:01,044 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:49:01,044 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:49:01,050 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DB0D39D16C384702B2AB2C8F1C754E4B, ordinal: 1
2016-05-18 01:49:01,051 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:-1]]
2016-05-18 01:49:01,051 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown"]
2016-05-18 01:49:01,051 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DB0D39D16C384702B2AB2C8F1C754E4B, mem on start (mb), free: 173, total: 494, max: 672
2016-05-18 01:49:01,059 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DB0D39D16C384702B2AB2C8F1C754E4B, mem on close (mb), free: 171, total: 494, max: 672
2016-05-18 01:49:01,082 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown/_temporary
2016-05-18 01:49:01,083 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.211
2016-05-18 01:49:01,106 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testSimpleRelativeUnknown/simplerelativeunknown
2016-05-18 01:49:01,121 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:49:01,121 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:49:01,167 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.042
2016-05-18 01:49:01,168 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:49:01,168 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:49:01,192 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting
2016-05-18 01:49:01,192 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/upper.txt"]
2016-05-18 01:49:01,193 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-05-18 01:49:01,194 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroup/complexcogroup"]
2016-05-18 01:49:01,194 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] parallel execution of steps is enabled: false
2016-05-18 01:49:01,194 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executing total steps: 1
2016-05-18 01:49:01,195 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] allocating management threads: 1
2016-05-18 01:49:01,197 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting step: (1/1) ...estCoGroup/complexcogroup
2016-05-18 01:49:01,279 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1147519530/.staging/job_local1147519530_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:01,281 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1147519530/.staging/job_local1147519530_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:01,337 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1147519530_0011/job_local1147519530_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:01,339 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1147519530_0011/job_local1147519530_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:01,340 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] submitted hadoop job: job_local1147519530_0011
2016-05-18 01:49:01,341 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] tracking url: http://localhost:8080/
2016-05-18 01:49:01,348 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt
2016-05-18 01:49:01,370 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:49:01,371 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:49:01,382 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B1BC28A4FAF74139A24554591B6FFFE5, ordinal: 0
2016-05-18 01:49:01,383 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/lower.txt"]
2016-05-18 01:49:01,383 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:0] upper:[{1}:0]]
2016-05-18 01:49:01,383 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B1BC28A4FAF74139A24554591B6FFFE5, mem on start (mb), free: 171, total: 484, max: 672
2016-05-18 01:49:01,385 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B1BC28A4FAF74139A24554591B6FFFE5, mem on close (mb), free: 171, total: 484, max: 672
2016-05-18 01:49:01,394 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/upper.txt
2016-05-18 01:49:01,409 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:49:01,409 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:49:01,418 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B1BC28A4FAF74139A24554591B6FFFE5, ordinal: 0
2016-05-18 01:49:01,419 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/upper.txt"]
2016-05-18 01:49:01,420 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:0] upper:[{1}:0]]
2016-05-18 01:49:01,420 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B1BC28A4FAF74139A24554591B6FFFE5, mem on start (mb), free: 70, total: 484, max: 672
2016-05-18 01:49:01,421 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B1BC28A4FAF74139A24554591B6FFFE5, mem on close (mb), free: 70, total: 484, max: 672
2016-05-18 01:49:01,440 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:49:01,440 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:49:01,445 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F18F6363A7084255993BA917793D0BA7, ordinal: 1
2016-05-18 01:49:01,446 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:0] upper:[{1}:0]]
2016-05-18 01:49:01,446 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroup/complexcogroup"]
2016-05-18 01:49:01,446 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F18F6363A7084255993BA917793D0BA7, mem on start (mb), free: 63, total: 484, max: 672
2016-05-18 01:49:01,454 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 01:49:01,454 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 01:49:01,456 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F18F6363A7084255993BA917793D0BA7, mem on close (mb), free: 62, total: 484, max: 672
2016-05-18 01:49:01,473 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCoGroup/complexcogroup/_temporary
2016-05-18 01:49:01,473 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] completed in: 00:00.280
2016-05-18 01:49:01,524 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testCoGroup/complexcogroup
2016-05-18 01:49:01,542 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:49:01,542 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:49:01,565 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.019
2016-05-18 01:49:01,566 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 01:49:01,566 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:49:01,573 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:49:01,574 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:49:01,574 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testReplace/replace"]
2016-05-18 01:49:01,574 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:49:01,574 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:49:01,574 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:49:01,575 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...tform/testReplace/replace
2016-05-18 01:49:01,627 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1158740703/.staging/job_local1158740703_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:01,628 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1158740703/.staging/job_local1158740703_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:01,671 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1158740703_0012/job_local1158740703_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:01,672 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1158740703_0012/job_local1158740703_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:01,673 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1158740703_0012
2016-05-18 01:49:01,673 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:49:01,677 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt
2016-05-18 01:49:01,683 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:49:01,684 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:49:01,690 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FD2E1BD727984629A685E35449D20E8F, ordinal: 0
2016-05-18 01:49:01,691 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:49:01,691 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testReplace/replace"]
2016-05-18 01:49:01,692 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FD2E1BD727984629A685E35449D20E8F, mem on start (mb), free: 243, total: 493, max: 672
2016-05-18 01:49:01,694 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FD2E1BD727984629A685E35449D20E8F, mem on close (mb), free: 243, total: 493, max: 672
2016-05-18 01:49:01,708 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testReplace/replace/_temporary
2016-05-18 01:49:01,708 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.134
2016-05-18 01:49:01,730 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testReplace/replace
2016-05-18 01:49:01,747 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:49:01,748 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:49:01,788 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.035
2016-05-18 01:49:01,789 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:49:01,790 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:49:01,807 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting
2016-05-18 01:49:01,807 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 01:49:01,807 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount2/count2"]
2016-05-18 01:49:01,808 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] parallel execution of steps is enabled: false
2016-05-18 01:49:01,808 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executing total steps: 1
2016-05-18 01:49:01,808 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] allocating management threads: 1
2016-05-18 01:49:01,809 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting step: (1/1) ...latform/testCount2/count2
2016-05-18 01:49:01,860 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1992182505/.staging/job_local1992182505_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:01,860 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1992182505/.staging/job_local1992182505_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:01,897 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1992182505_0013/job_local1992182505_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:01,898 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1992182505_0013/job_local1992182505_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:01,898 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] submitted hadoop job: job_local1992182505_0013
2016-05-18 01:49:01,898 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] tracking url: http://localhost:8080/
2016-05-18 01:49:01,904 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt
2016-05-18 01:49:01,918 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:49:01,919 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:49:01,924 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E74E3DBFF900448684CD48B553EC7767, ordinal: 0
2016-05-18 01:49:01,924 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 01:49:01,924 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-05-18 01:49:01,925 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E74E3DBFF900448684CD48B553EC7767, mem on start (mb), free: 93, total: 493, max: 672
2016-05-18 01:49:01,927 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E74E3DBFF900448684CD48B553EC7767, mem on close (mb), free: 93, total: 493, max: 672
2016-05-18 01:49:01,943 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:49:01,943 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:49:01,951 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F61CB3FEB8EC4106882818EA2760B95C, ordinal: 1
2016-05-18 01:49:01,952 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-05-18 01:49:01,953 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount2/count2"]
2016-05-18 01:49:01,953 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F61CB3FEB8EC4106882818EA2760B95C, mem on start (mb), free: 86, total: 493, max: 672
2016-05-18 01:49:01,964 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F61CB3FEB8EC4106882818EA2760B95C, mem on close (mb), free: 84, total: 493, max: 672
2016-05-18 01:49:01,989 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount2/count2/_temporary
2016-05-18 01:49:01,989 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] completed in: 00:00.182
2016-05-18 01:49:02,037 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testCount2/count2
2016-05-18 01:49:02,051 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:49:02,052 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:49:02,085 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.030
2016-05-18 01:49:02,086 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:49:02,086 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:49:02,103 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting
2016-05-18 01:49:02,103 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 01:49:02,103 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount3/count3"]
2016-05-18 01:49:02,103 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] parallel execution of steps is enabled: false
2016-05-18 01:49:02,103 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executing total steps: 1
2016-05-18 01:49:02,103 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] allocating management threads: 1
2016-05-18 01:49:02,104 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting step: (1/1) ...latform/testCount3/count3
2016-05-18 01:49:02,165 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity589628497/.staging/job_local589628497_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:02,166 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity589628497/.staging/job_local589628497_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:02,201 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local589628497_0014/job_local589628497_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:02,202 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local589628497_0014/job_local589628497_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:02,203 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] submitted hadoop job: job_local589628497_0014
2016-05-18 01:49:02,203 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] tracking url: http://localhost:8080/
2016-05-18 01:49:02,209 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt
2016-05-18 01:49:02,223 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:49:02,223 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:49:02,228 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A74318FA3FF9410BAA9451DABC71F2D5, ordinal: 0
2016-05-18 01:49:02,228 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 01:49:02,228 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-05-18 01:49:02,228 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A74318FA3FF9410BAA9451DABC71F2D5, mem on start (mb), free: 150, total: 493, max: 672
2016-05-18 01:49:02,230 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A74318FA3FF9410BAA9451DABC71F2D5, mem on close (mb), free: 150, total: 493, max: 672
2016-05-18 01:49:02,245 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:49:02,245 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:49:02,250 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: FD77078C0294439F9940FD1BB52F62D9, ordinal: 1
2016-05-18 01:49:02,250 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-05-18 01:49:02,251 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount3/count3"]
2016-05-18 01:49:02,251 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FD77078C0294439F9940FD1BB52F62D9, mem on start (mb), free: 143, total: 493, max: 672
2016-05-18 01:49:02,260 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FD77078C0294439F9940FD1BB52F62D9, mem on close (mb), free: 141, total: 493, max: 672
2016-05-18 01:49:02,280 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount3/count3/_temporary
2016-05-18 01:49:02,282 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] completed in: 00:00.177
2016-05-18 01:49:02,326 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testCount3/count3
2016-05-18 01:49:02,339 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:49:02,339 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:49:02,365 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.022
2016-05-18 01:49:02,366 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:49:02,366 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:49:02,377 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting
2016-05-18 01:49:02,377 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 01:49:02,377 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount4/count4"]
2016-05-18 01:49:02,378 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] parallel execution of steps is enabled: false
2016-05-18 01:49:02,378 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] executing total steps: 1
2016-05-18 01:49:02,378 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] allocating management threads: 1
2016-05-18 01:49:02,379 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] starting step: (1/1) ...latform/testCount4/count4
2016-05-18 01:49:02,432 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity294871462/.staging/job_local294871462_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:02,433 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity294871462/.staging/job_local294871462_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:02,466 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local294871462_0015/job_local294871462_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:02,467 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local294871462_0015/job_local294871462_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:02,467 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] submitted hadoop job: job_local294871462_0015
2016-05-18 01:49:02,468 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] tracking url: http://localhost:8080/
2016-05-18 01:49:02,473 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt
2016-05-18 01:49:02,491 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:49:02,492 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:49:02,498 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D1A65D92FD434891AFC9882246DE5A6F, ordinal: 0
2016-05-18 01:49:02,498 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/ips.20.txt"]
2016-05-18 01:49:02,498 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(count)[by:[{1}:1]]
2016-05-18 01:49:02,499 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D1A65D92FD434891AFC9882246DE5A6F, mem on start (mb), free: 181, total: 493, max: 672
2016-05-18 01:49:02,501 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D1A65D92FD434891AFC9882246DE5A6F, mem on close (mb), free: 181, total: 493, max: 672
2016-05-18 01:49:02,518 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:49:02,518 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:49:02,522 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D3143532DA3A4F60BD9B70B04C487EDD, ordinal: 1
2016-05-18 01:49:02,523 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(count)[by:[{1}:1]]
2016-05-18 01:49:02,523 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount4/count4"]
2016-05-18 01:49:02,523 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D3143532DA3A4F60BD9B70B04C487EDD, mem on start (mb), free: 175, total: 493, max: 672
2016-05-18 01:49:02,532 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D3143532DA3A4F60BD9B70B04C487EDD, mem on close (mb), free: 173, total: 493, max: 672
2016-05-18 01:49:02,548 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testCount4/count4/_temporary
2016-05-18 01:49:02,548 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [count] completed in: 00:00.171
2016-05-18 01:49:02,589 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testCount4/count4
2016-05-18 01:49:02,601 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:49:02,602 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:49:02,623 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.018
2016-05-18 01:49:02,624 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-18 01:49:02,624 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:49:02,631 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:49:02,631 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:49:02,632 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testFilter/filter"]
2016-05-18 01:49:02,632 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:49:02,632 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:49:02,632 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:49:02,633 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...latform/testFilter/filter
2016-05-18 01:49:02,682 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity971959879/.staging/job_local971959879_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:02,683 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity971959879/.staging/job_local971959879_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:02,713 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local971959879_0016/job_local971959879_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:02,714 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local971959879_0016/job_local971959879_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:02,715 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local971959879_0016
2016-05-18 01:49:02,716 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:49:02,720 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt
2016-05-18 01:49:02,726 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:49:02,727 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:49:02,735 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DC224A329252428691ED173FAD21E0F5, ordinal: 0
2016-05-18 01:49:02,736 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:49:02,736 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testFilter/filter"]
2016-05-18 01:49:02,737 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DC224A329252428691ED173FAD21E0F5, mem on start (mb), free: 121, total: 493, max: 672
2016-05-18 01:49:02,740 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DC224A329252428691ED173FAD21E0F5, mem on close (mb), free: 121, total: 493, max: 672
2016-05-18 01:49:02,759 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testFilter/filter/_temporary
2016-05-18 01:49:02,760 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.128
2016-05-18 01:49:02,780 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testFilter/filter
2016-05-18 01:49:02,794 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:49:02,794 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 01:49:02,823 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.026
2016-05-18 01:49:02,824 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:49:02,824 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 01:49:02,835 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:49:02,835 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:49:02,835 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimple/simple"]
2016-05-18 01:49:02,836 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:49:02,837 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:49:02,837 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:49:02,838 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...latform/testSimple/simple
2016-05-18 01:49:02,887 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1589688389/.staging/job_local1589688389_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:02,887 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/tmp/cascading/staging/teamcity1589688389/.staging/job_local1589688389_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:02,918 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1589688389_0017/job_local1589688389_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2016-05-18 01:49:02,919 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1589688389_0017/job_local1589688389_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2016-05-18 01:49:02,919 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1589688389_0017
2016-05-18 01:49:02,920 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:49:02,925 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt
2016-05-18 01:49:02,943 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:49:02,944 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:49:02,949 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FDCF1E755F7441EEB7CFA087D4D1A590, ordinal: 0
2016-05-18 01:49:02,950 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[[0:1]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2016-05-18 01:49:02,950 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:0]]
2016-05-18 01:49:02,950 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FDCF1E755F7441EEB7CFA087D4D1A590, mem on start (mb), free: 180, total: 493, max: 672
2016-05-18 01:49:02,953 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FDCF1E755F7441EEB7CFA087D4D1A590, mem on close (mb), free: 180, total: 493, max: 672
2016-05-18 01:49:02,968 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:49:02,968 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:49:02,973 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F1126605CDF240E3817011428A0A10FD, ordinal: 1
2016-05-18 01:49:02,974 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:0]]
2016-05-18 01:49:02,974 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[[0]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimple/simple"]
2016-05-18 01:49:02,974 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F1126605CDF240E3817011428A0A10FD, mem on start (mb), free: 174, total: 493, max: 672
2016-05-18 01:49:02,982 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F1126605CDF240E3817011428A0A10FD, mem on close (mb), free: 172, total: 493, max: 672
2016-05-18 01:49:02,998 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output/hadoop2-mr1/basicpipesplatform/testSimple/simple/_temporary
2016-05-18 01:49:02,998 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.163
2016-05-18 01:49:03,018 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.4.x/build/test/output//hadoop2-mr1/basicpipesplatform/testSimple/simple