Class cascading.BasicPipesPlatformTest

16

tests

0

failures

0

ignored

8.112s

duration

100%

successful

Tests

Test Duration Result
testCoGroup 0.418s passed
testCoGroupRelativeUnknown 0.515s passed
testCount 0.595s passed
testCount2 0.308s passed
testCount3 0.288s passed
testCount4 0.263s passed
testFilter 0.190s passed
testFilterAll 0.226s passed
testReplace 0.205s passed
testSimple 0.238s passed
testSimpleChain 3.142s passed
testSimpleRelative 0.321s passed
testSimpleRelativeUnknown 0.313s passed
testSimpleResult 0.528s passed
testSwap 0.284s passed
testUnGroup 0.278s passed

Standard output

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