Class cascading.pipe.assembly.AssemblyHelpersPlatformTest

all > cascading.pipe.assembly > AssemblyHelpersPlatformTest
35

tests
0

failures
19.100s

duration
100%

successful

Tests

Test Duration Result
testAverageBy 0.339s passed
testAverageByNull 0.331s passed
testAverageMerge 1.246s passed
testCoerce 0.224s passed
testCoerceFields 0.308s passed
testCount 0.382s passed
testCountAll 0.331s passed
testCountCount 0.945s passed
testCountMerge 1.016s passed
testCountNullNotNull 0.306s passed
testDiscardNarrow 0.254s passed
testFirstBy 0.398s passed
testFirstByWithoutComparator 0.290s passed
testMaxBy 0.402s passed
testMaxByNullSafety 0.328s passed
testMaxByString 0.408s passed
testMinBy 0.372s passed
testMinByNullSafety 0.514s passed
testMinByString 0.683s passed
testParallelAggregates 0.354s passed
testParallelAggregatesMerge 3.667s passed
testParallelAggregatesMergeLegacyHash 0.382s passed
testParallelAggregatesPriorMerge 0.438s passed
testParallelAggregatesPriorMergeLegacyHash 0.443s passed
testRenameAll 0.334s passed
testRenameNamed 0.227s passed
testRenameNarrow 0.236s passed
testRetainNarrow 0.224s passed
testSameSourceMerge 0.588s passed
testSameSourceMergeThreeWay 1.374s passed
testSumBy 0.353s passed
testSumByNulls 0.342s passed
testSumMerge 0.448s passed
testUnique 0.279s passed
testUniqueMerge 0.334s passed

Standard output

2015-08-14 09:55:53,541 INFO  platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2015-08-14 09:55:53,607 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop2-mr1
2015-08-14 09:55:53,608 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.pipe.assembly.AssemblyHelpersPlatformTest
2015-08-14 09:55:53,664 INFO  hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(105)) - not using cluster
2015-08-14 09:55:54,505 WARN  util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2015-08-14 09:55:54,664 INFO  platform.TestPlatform (TestPlatform.java:getGlobalProperties(72)) - platform property overrides: 
2015-08-14 09:55:55,136 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:55:55,138 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:55:55,151 INFO  property.AppProps (AppProps.java:getAppID(169)) - using app.id: 0DDEAB330BBE4FBDBC69DED93172AA51
2015-08-14 09:55:55,448 INFO  util.Version (Version.java:printBanner(85)) - Concurrent, Inc - Cascading 2.7.1
2015-08-14 09:55:55,450 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-14 09:55:55,451 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:55:55,451 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:55:55,451 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/multimerge+false653"]
2015-08-14 09:55:55,452 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-14 09:55:55,452 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-14 09:55:55,454 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-14 09:55:55,455 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...tform/multimerge+false653
2015-08-14 09:55:56,249 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local1154557997_0001
2015-08-14 09:55:56,250 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-14 09:55:56,352 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:55:56,547 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:55:56,547 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:55:56,612 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:55:56,613 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-14 09:55:56,633 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:55:56,633 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 70, total: 200, max: 672
2015-08-14 09:55:56,633 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 29% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:56,635 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:55:56,635 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 70, total: 200, max: 672
2015-08-14 09:55:56,635 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 29% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:56,636 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:55:56,636 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 70, total: 200, max: 672
2015-08-14 09:55:56,637 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 29% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:56,637 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:55:56,638 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 70, total: 200, max: 672
2015-08-14 09:55:56,638 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 29% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:56,668 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt
2015-08-14 09:55:56,815 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:55:56,815 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:55:56,841 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:55:56,842 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-14 09:55:56,946 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:55:56,947 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 92, total: 300, max: 672
2015-08-14 09:55:56,947 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 44% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:56,949 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:55:56,949 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 92, total: 300, max: 672
2015-08-14 09:55:56,949 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 44% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:56,950 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:55:56,951 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 92, total: 300, max: 672
2015-08-14 09:55:56,951 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 44% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:56,952 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:55:56,952 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 92, total: 300, max: 672
2015-08-14 09:55:56,952 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 44% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:57,098 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:55:57,098 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:55:57,126 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-14 09:55:57,126 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/multimerge+false653"]
2015-08-14 09:55:57,216 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/multimerge+false653/_temporary
2015-08-14 09:55:57,309 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/multimerge+false653
2015-08-14 09:55:57,370 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:55:57,371 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:55:57,411 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-14 09:55:57,412 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:55:57,412 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['num', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/minbystring"]
2015-08-14 09:55:57,413 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-14 09:55:57,413 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-14 09:55:57,413 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-14 09:55:57,414 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...lpersplatform/minbystring
2015-08-14 09:55:57,634 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local945452338_0002
2015-08-14 09:55:57,635 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-14 09:55:57,643 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:55:57,791 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:55:57,791 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:55:57,805 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:55:57,806 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'num']]
2015-08-14 09:55:57,809 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:55:57,809 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 79, total: 421, max: 672
2015-08-14 09:55:57,809 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 62% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:57,811 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:55:57,811 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 79, total: 421, max: 672
2015-08-14 09:55:57,811 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 62% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:57,838 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:55:57,838 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:55:57,851 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'num']]
2015-08-14 09:55:57,851 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/minbystring"]
2015-08-14 09:55:57,905 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/minbystring/_temporary
2015-08-14 09:55:58,014 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/minbystring
2015-08-14 09:55:58,057 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:55:58,058 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:55:58,105 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs] starting
2015-08-14 09:55:58,106 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:55:58,106 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:55:58,106 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  sink: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/mergeaverage"]
2015-08-14 09:55:58,107 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  parallel execution is enabled: false
2015-08-14 09:55:58,107 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  starting jobs: 1
2015-08-14 09:55:58,107 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  allocating threads: 1
2015-08-14 09:55:58,108 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average-lhs+average-rhs] starting step: (1/1) ...persplatform/mergeaverage
2015-08-14 09:55:58,390 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average-lhs+average-rhs] submitted hadoop job: job_local1736132535_0003
2015-08-14 09:55:58,391 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average-lhs+average-rhs] tracking url: http://localhost:8080/
2015-08-14 09:55:58,402 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:55:58,558 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:55:58,559 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:55:58,576 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:55:58,577 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(average-lhs+average-rhs)[by: average-lhs:[{1}:'char'] average-rhs:[{1}:'char']]
2015-08-14 09:55:58,579 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:55:58,580 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 71, total: 523, max: 672
2015-08-14 09:55:58,580 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:58,581 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:55:58,581 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 71, total: 523, max: 672
2015-08-14 09:55:58,581 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:58,582 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:55:58,582 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 71, total: 523, max: 672
2015-08-14 09:55:58,582 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:58,583 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:55:58,583 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 71, total: 523, max: 672
2015-08-14 09:55:58,583 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:58,597 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt
2015-08-14 09:55:58,751 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:55:58,752 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:55:58,768 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:55:58,768 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(average-lhs+average-rhs)[by: average-lhs:[{1}:'char'] average-rhs:[{1}:'char']]
2015-08-14 09:55:59,068 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:55:59,068 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 111, total: 217, max: 672
2015-08-14 09:55:59,069 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 32% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:59,070 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:55:59,071 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 111, total: 217, max: 672
2015-08-14 09:55:59,071 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 32% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:59,072 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:55:59,072 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 111, total: 217, max: 672
2015-08-14 09:55:59,073 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 32% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:59,073 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:55:59,074 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 111, total: 217, max: 672
2015-08-14 09:55:59,074 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 32% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:59,109 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:55:59,109 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:55:59,127 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(average-lhs+average-rhs)[by: average-lhs:[{1}:'char'] average-rhs:[{1}:'char']]
2015-08-14 09:55:59,127 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/mergeaverage"]
2015-08-14 09:55:59,178 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/mergeaverage/_temporary
2015-08-14 09:55:59,262 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/mergeaverage
2015-08-14 09:55:59,292 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:55:59,293 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:55:59,319 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-14 09:55:59,320 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt"]
2015-08-14 09:55:59,320 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/renameall"]
2015-08-14 09:55:59,321 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-14 09:55:59,322 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-14 09:55:59,322 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-14 09:55:59,323 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...helpersplatform/renameall
2015-08-14 09:55:59,500 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local2138423142_0004
2015-08-14 09:55:59,501 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-14 09:55:59,510 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt
2015-08-14 09:55:59,520 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:55:59,520 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:55:59,528 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt"]
2015-08-14 09:55:59,528 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/renameall"]
2015-08-14 09:55:59,557 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/renameall/_temporary
2015-08-14 09:55:59,596 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/renameall
2015-08-14 09:55:59,631 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:55:59,631 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:55:59,691 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-14 09:55:59,691 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:55:59,691 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['count', 'count2']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/countcount"]
2015-08-14 09:55:59,692 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-14 09:55:59,692 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 2
2015-08-14 09:55:59,693 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-14 09:55:59,694 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/2)
2015-08-14 09:55:59,856 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local2022654824_0005
2015-08-14 09:55:59,856 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-14 09:55:59,864 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:55:59,935 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:55:59,936 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:55:59,948 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:55:59,948 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{1}:'char']]
2015-08-14 09:55:59,950 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:55:59,950 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 71, total: 331, max: 672
2015-08-14 09:55:59,950 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 49% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:59,951 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:55:59,952 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 71, total: 331, max: 672
2015-08-14 09:55:59,952 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 49% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:59,952 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:55:59,953 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 70, total: 331, max: 672
2015-08-14 09:55:59,953 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 49% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:59,953 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:55:59,953 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 70, total: 331, max: 672
2015-08-14 09:55:59,954 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 49% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:55:59,976 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:55:59,976 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:55:59,988 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{1}:'char']]
2015-08-14 09:55:59,988 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['count', 'count2']]"][315368348/count/]
2015-08-14 09:56:00,015 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:00,015 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 331, max: 672
2015-08-14 09:56:00,015 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 49% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:00,041 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (2/2) ...elpersplatform/countcount
2015-08-14 09:56:00,213 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local1207245938_0006
2015-08-14 09:56:00,214 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-14 09:56:00,221 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/315368348_count_E3439E8FA26E41F59C8912028C7F9BBE/part-00000
2015-08-14 09:56:00,381 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:00,381 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:00,393 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['count', 'count2']]"][315368348/count/]
2015-08-14 09:56:00,394 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{1}:'count']]
2015-08-14 09:56:00,416 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:00,416 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:00,427 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{1}:'count']]
2015-08-14 09:56:00,428 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['count', 'count2']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/countcount"]
2015-08-14 09:56:00,467 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/countcount/_temporary
2015-08-14 09:56:00,542 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/countcount
2015-08-14 09:56:00,572 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:00,572 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:00,606 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs] starting
2015-08-14 09:56:00,607 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:56:00,607 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:00,607 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  sink: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/mergecount"]
2015-08-14 09:56:00,607 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  parallel execution is enabled: false
2015-08-14 09:56:00,608 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  starting jobs: 1
2015-08-14 09:56:00,608 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  allocating threads: 1
2015-08-14 09:56:00,608 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs+count-rhs] starting step: (1/1) ...elpersplatform/mergecount
2015-08-14 09:56:00,799 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs+count-rhs] submitted hadoop job: job_local540458491_0007
2015-08-14 09:56:00,799 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs+count-rhs] tracking url: http://localhost:8080/
2015-08-14 09:56:00,806 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:00,960 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:00,960 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:00,974 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:00,974 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count-lhs+count-rhs)[by: count-lhs:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-14 09:56:00,976 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:00,976 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 148, total: 559, max: 672
2015-08-14 09:56:00,977 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:00,978 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 148, total: 559, max: 672
2015-08-14 09:56:00,978 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:00,978 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 148, total: 559, max: 672
2015-08-14 09:56:00,979 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:00,979 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 148, total: 559, max: 672
2015-08-14 09:56:00,991 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt
2015-08-14 09:56:01,301 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:01,302 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:01,317 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:56:01,317 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count-lhs+count-rhs)[by: count-lhs:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-14 09:56:01,322 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:01,322 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 87, total: 193, max: 672
2015-08-14 09:56:01,323 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 28% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:01,324 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:01,324 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 87, total: 193, max: 672
2015-08-14 09:56:01,324 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 28% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:01,325 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:01,325 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 87, total: 193, max: 672
2015-08-14 09:56:01,326 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 28% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:01,326 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:01,326 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 87, total: 193, max: 672
2015-08-14 09:56:01,327 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 28% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:01,353 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:01,353 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:01,367 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count-lhs+count-rhs)[by: count-lhs:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-14 09:56:01,367 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/mergecount"]
2015-08-14 09:56:01,409 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/mergecount/_temporary
2015-08-14 09:56:01,558 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/mergecount
2015-08-14 09:56:01,591 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:01,593 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:01,622 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min] starting
2015-08-14 09:56:01,622 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:01,622 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  sink: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/minbynullsafety"]
2015-08-14 09:56:01,622 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  parallel execution is enabled: false
2015-08-14 09:56:01,623 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  starting jobs: 1
2015-08-14 09:56:01,623 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  allocating threads: 1
2015-08-14 09:56:01,623 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] starting step: (1/1) ...splatform/minbynullsafety
2015-08-14 09:56:01,762 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] submitted hadoop job: job_local762235585_0008
2015-08-14 09:56:01,762 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] tracking url: http://localhost:8080/
2015-08-14 09:56:01,769 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:01,915 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:01,915 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:01,927 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:01,927 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(min)[by:[{1}:'char']]
2015-08-14 09:56:01,929 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:01,930 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 134, total: 393, max: 672
2015-08-14 09:56:01,930 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 58% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:01,931 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:01,931 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 134, total: 393, max: 672
2015-08-14 09:56:01,931 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 58% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:01,932 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:01,932 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 134, total: 393, max: 672
2015-08-14 09:56:01,932 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 58% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:01,933 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:01,933 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 134, total: 393, max: 672
2015-08-14 09:56:01,933 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 58% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:01,953 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:01,953 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:01,964 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(min)[by:[{1}:'char']]
2015-08-14 09:56:01,965 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/minbynullsafety"]
2015-08-14 09:56:02,003 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/minbynullsafety/_temporary
2015-08-14 09:56:02,074 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/minbynullsafety
2015-08-14 09:56:02,103 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:02,104 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:02,130 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-14 09:56:02,130 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:02,130 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['num', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/maxbystring"]
2015-08-14 09:56:02,130 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-14 09:56:02,131 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-14 09:56:02,131 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-14 09:56:02,132 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...lpersplatform/maxbystring
2015-08-14 09:56:02,289 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local500483023_0009
2015-08-14 09:56:02,289 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-14 09:56:02,295 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:02,316 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:02,316 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:02,327 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:02,327 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'num']]
2015-08-14 09:56:02,330 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:02,330 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 138, total: 449, max: 672
2015-08-14 09:56:02,330 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 66% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:02,331 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:02,331 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 138, total: 449, max: 672
2015-08-14 09:56:02,331 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 66% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:02,351 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:02,352 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:02,361 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'num']]
2015-08-14 09:56:02,361 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/maxbystring"]
2015-08-14 09:56:02,400 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/maxbystring/_temporary
2015-08-14 09:56:02,482 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/maxbystring
2015-08-14 09:56:02,518 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:02,518 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:02,551 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first] starting
2015-08-14 09:56:02,552 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  source: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs+rhs-cross.txt"]
2015-08-14 09:56:02,552 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  sink: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/firstnfields"]
2015-08-14 09:56:02,552 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  parallel execution is enabled: false
2015-08-14 09:56:02,552 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  starting jobs: 1
2015-08-14 09:56:02,552 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  allocating threads: 1
2015-08-14 09:56:02,553 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] starting step: (1/1) ...persplatform/firstnfields
2015-08-14 09:56:02,719 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] submitted hadoop job: job_local2097174463_0010
2015-08-14 09:56:02,720 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] tracking url: http://localhost:8080/
2015-08-14 09:56:02,726 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs+rhs-cross.txt
2015-08-14 09:56:02,751 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:02,751 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:02,763 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs+rhs-cross.txt"]
2015-08-14 09:56:02,763 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(first)[by:[{1}:'num']]
2015-08-14 09:56:02,767 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:02,767 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 136, total: 451, max: 672
2015-08-14 09:56:02,767 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 67% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:02,768 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:02,769 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 135, total: 451, max: 672
2015-08-14 09:56:02,769 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 67% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:02,790 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:02,790 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:02,800 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(first)[by:[{1}:'num']]
2015-08-14 09:56:02,800 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/firstnfields"]
2015-08-14 09:56:02,840 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/firstnfields/_temporary
2015-08-14 09:56:02,881 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/firstnfields
2015-08-14 09:56:02,915 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:02,915 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:02,938 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce] starting
2015-08-14 09:56:02,938 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt"]
2015-08-14 09:56:02,940 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  sink: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/coercefields"]
2015-08-14 09:56:02,940 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  parallel execution is enabled: false
2015-08-14 09:56:02,940 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  starting jobs: 1
2015-08-14 09:56:02,940 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  allocating threads: 1
2015-08-14 09:56:02,942 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] starting step: (1/1) ...persplatform/coercefields
2015-08-14 09:56:03,093 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] submitted hadoop job: job_local1809037600_0011
2015-08-14 09:56:03,098 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] tracking url: http://localhost:8080/
2015-08-14 09:56:03,105 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt
2015-08-14 09:56:03,112 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:03,113 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:03,122 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt"]
2015-08-14 09:56:03,122 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/coercefields"]
2015-08-14 09:56:03,153 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/coercefields/_temporary
2015-08-14 09:56:03,188 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/coercefields
2015-08-14 09:56:03,213 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:03,213 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:03,232 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-14 09:56:03,232 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:03,233 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/count"]
2015-08-14 09:56:03,233 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-14 09:56:03,233 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 1
2015-08-14 09:56:03,233 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-14 09:56:03,234 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/1) ...mblyhelpersplatform/count
2015-08-14 09:56:03,369 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local370694598_0012
2015-08-14 09:56:03,369 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-14 09:56:03,376 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:03,408 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:03,408 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:03,419 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:03,419 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{1}:'char']]
2015-08-14 09:56:03,421 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:03,421 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 143, total: 520, max: 672
2015-08-14 09:56:03,421 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:03,422 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:03,422 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 143, total: 520, max: 672
2015-08-14 09:56:03,422 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:03,423 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:03,423 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 143, total: 520, max: 672
2015-08-14 09:56:03,423 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:03,424 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:03,424 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 143, total: 520, max: 672
2015-08-14 09:56:03,424 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:03,443 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:03,443 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:03,454 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{1}:'char']]
2015-08-14 09:56:03,455 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/count"]
2015-08-14 09:56:03,490 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/count/_temporary
2015-08-14 09:56:03,570 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/count
2015-08-14 09:56:03,603 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:03,604 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:03,627 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-14 09:56:03,627 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:03,627 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/maxby"]
2015-08-14 09:56:03,627 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-14 09:56:03,628 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-14 09:56:03,628 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-14 09:56:03,628 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...mblyhelpersplatform/maxby
2015-08-14 09:56:03,791 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local1499415210_0013
2015-08-14 09:56:03,792 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-14 09:56:03,799 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:03,821 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:03,821 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:03,831 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:03,832 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'char']]
2015-08-14 09:56:03,833 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:03,834 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 204, total: 520, max: 672
2015-08-14 09:56:03,834 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:03,835 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:03,835 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 204, total: 520, max: 672
2015-08-14 09:56:03,835 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:03,836 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:03,836 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 204, total: 520, max: 672
2015-08-14 09:56:03,836 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:03,837 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:03,837 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 204, total: 520, max: 672
2015-08-14 09:56:03,837 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:03,856 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:03,856 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:03,866 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'char']]
2015-08-14 09:56:03,867 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/maxby"]
2015-08-14 09:56:03,903 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/maxby/_temporary
2015-08-14 09:56:03,972 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/maxby
2015-08-14 09:56:03,995 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:03,996 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:04,013 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min] starting
2015-08-14 09:56:04,013 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:04,014 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  sink: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/minby"]
2015-08-14 09:56:04,014 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  parallel execution is enabled: false
2015-08-14 09:56:04,014 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  starting jobs: 1
2015-08-14 09:56:04,014 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  allocating threads: 1
2015-08-14 09:56:04,015 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] starting step: (1/1) ...mblyhelpersplatform/minby
2015-08-14 09:56:04,166 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] submitted hadoop job: job_local745229768_0014
2015-08-14 09:56:04,167 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] tracking url: http://localhost:8080/
2015-08-14 09:56:04,173 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:04,197 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:04,198 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:04,209 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:04,209 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(min)[by:[{1}:'char']]
2015-08-14 09:56:04,211 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:04,211 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 213, total: 520, max: 672
2015-08-14 09:56:04,211 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:04,212 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:04,212 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 213, total: 520, max: 672
2015-08-14 09:56:04,212 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:04,213 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:04,213 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 213, total: 520, max: 672
2015-08-14 09:56:04,213 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:04,214 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:04,214 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 213, total: 520, max: 672
2015-08-14 09:56:04,214 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:04,233 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:04,233 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:04,242 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(min)[by:[{1}:'char']]
2015-08-14 09:56:04,242 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/minby"]
2015-08-14 09:56:04,278 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/minby/_temporary
2015-08-14 09:56:04,344 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/minby
2015-08-14 09:56:04,367 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:04,367 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:04,386 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum] starting
2015-08-14 09:56:04,386 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:04,387 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  sink: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/sum"]
2015-08-14 09:56:04,387 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  parallel execution is enabled: false
2015-08-14 09:56:04,387 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  starting jobs: 1
2015-08-14 09:56:04,387 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  allocating threads: 1
2015-08-14 09:56:04,388 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] starting step: (1/1) ...semblyhelpersplatform/sum
2015-08-14 09:56:04,518 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] submitted hadoop job: job_local1636120658_0015
2015-08-14 09:56:04,519 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] tracking url: http://localhost:8080/
2015-08-14 09:56:04,523 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:04,549 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:04,549 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:04,559 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:04,559 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(sum)[by:[{1}:'char']]
2015-08-14 09:56:04,561 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:04,562 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 213, total: 521, max: 672
2015-08-14 09:56:04,562 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:04,563 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:04,563 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 213, total: 521, max: 672
2015-08-14 09:56:04,563 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:04,564 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:04,564 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 212, total: 521, max: 672
2015-08-14 09:56:04,564 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:04,564 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:04,565 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 212, total: 521, max: 672
2015-08-14 09:56:04,565 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:04,582 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:04,583 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:04,592 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(sum)[by:[{1}:'char']]
2015-08-14 09:56:04,592 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/sum"]
2015-08-14 09:56:04,629 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/sum/_temporary
2015-08-14 09:56:04,698 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/sum
2015-08-14 09:56:04,723 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:04,724 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:04,749 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs] starting
2015-08-14 09:56:04,749 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:56:04,750 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:04,750 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  sink: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/mergesum"]
2015-08-14 09:56:04,750 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  parallel execution is enabled: false
2015-08-14 09:56:04,750 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  starting jobs: 1
2015-08-14 09:56:04,750 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  allocating threads: 1
2015-08-14 09:56:04,751 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum-lhs+sum-rhs] starting step: (1/1) ...yhelpersplatform/mergesum
2015-08-14 09:56:04,890 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum-lhs+sum-rhs] submitted hadoop job: job_local1780201781_0016
2015-08-14 09:56:04,890 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum-lhs+sum-rhs] tracking url: http://localhost:8080/
2015-08-14 09:56:04,896 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:04,920 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:04,921 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:04,932 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:04,933 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(sum-lhs+sum-rhs)[by: sum-lhs:[{1}:'char'] sum-rhs:[{1}:'char']]
2015-08-14 09:56:04,934 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:04,935 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 212, total: 521, max: 672
2015-08-14 09:56:04,935 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:04,936 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:04,936 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 212, total: 521, max: 672
2015-08-14 09:56:04,936 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:04,937 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:04,937 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 212, total: 521, max: 672
2015-08-14 09:56:04,937 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:04,937 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:04,937 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 212, total: 521, max: 672
2015-08-14 09:56:04,938 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:04,947 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt
2015-08-14 09:56:04,977 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:04,977 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:04,988 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:56:04,988 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(sum-lhs+sum-rhs)[by: sum-lhs:[{1}:'char'] sum-rhs:[{1}:'char']]
2015-08-14 09:56:04,993 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:04,993 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 110, total: 521, max: 672
2015-08-14 09:56:04,993 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:04,994 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:04,994 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 110, total: 521, max: 672
2015-08-14 09:56:04,994 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:04,995 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:04,995 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 110, total: 521, max: 672
2015-08-14 09:56:04,995 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:04,996 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:04,996 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 110, total: 521, max: 672
2015-08-14 09:56:04,996 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:05,016 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:05,016 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:05,027 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(sum-lhs+sum-rhs)[by: sum-lhs:[{1}:'char'] sum-rhs:[{1}:'char']]
2015-08-14 09:56:05,027 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/mergesum"]
2015-08-14 09:56:05,064 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/mergesum/_temporary
2015-08-14 09:56:05,145 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/mergesum
2015-08-14 09:56:05,169 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:05,169 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:05,185 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-14 09:56:05,185 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt"]
2015-08-14 09:56:05,186 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/discardnarrow"]
2015-08-14 09:56:05,186 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-14 09:56:05,186 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-14 09:56:05,186 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-14 09:56:05,188 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...ersplatform/discardnarrow
2015-08-14 09:56:05,321 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local153624672_0017
2015-08-14 09:56:05,322 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-14 09:56:05,327 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt
2015-08-14 09:56:05,334 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:05,335 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:05,341 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt"]
2015-08-14 09:56:05,341 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/discardnarrow"]
2015-08-14 09:56:05,366 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/discardnarrow/_temporary
2015-08-14 09:56:05,401 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/discardnarrow
2015-08-14 09:56:05,430 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:05,431 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:05,460 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-14 09:56:05,461 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:56:05,461 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:05,461 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/multimerge+true654"]
2015-08-14 09:56:05,461 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-14 09:56:05,462 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-14 09:56:05,462 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-14 09:56:05,462 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...atform/multimerge+true654
2015-08-14 09:56:05,594 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local1688471030_0018
2015-08-14 09:56:05,595 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-14 09:56:05,602 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:05,623 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:05,623 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:05,636 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:05,636 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-14 09:56:05,638 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:05,638 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 114, total: 521, max: 672
2015-08-14 09:56:05,639 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:05,640 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:05,640 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 114, total: 521, max: 672
2015-08-14 09:56:05,640 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:05,641 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:05,641 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 114, total: 521, max: 672
2015-08-14 09:56:05,641 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:05,642 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:05,642 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 114, total: 521, max: 672
2015-08-14 09:56:05,642 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:05,651 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt
2015-08-14 09:56:05,687 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:05,687 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:05,700 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:56:05,700 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-14 09:56:05,705 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:05,705 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 521, max: 672
2015-08-14 09:56:05,706 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:05,707 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:05,707 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 521, max: 672
2015-08-14 09:56:05,708 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:05,709 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:05,709 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 521, max: 672
2015-08-14 09:56:05,709 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:05,710 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:05,710 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 521, max: 672
2015-08-14 09:56:05,710 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:05,733 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:05,733 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:05,745 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by:[{1}:'char']]
2015-08-14 09:56:05,745 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/multimerge+true654"]
2015-08-14 09:56:05,778 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/multimerge+true654/_temporary
2015-08-14 09:56:05,844 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/multimerge+true654
2015-08-14 09:56:05,865 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:05,866 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:05,877 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-14 09:56:05,877 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt"]
2015-08-14 09:56:05,877 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/rename"]
2015-08-14 09:56:05,877 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-14 09:56:05,877 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-14 09:56:05,877 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-14 09:56:05,878 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...blyhelpersplatform/rename
2015-08-14 09:56:06,003 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local291301060_0019
2015-08-14 09:56:06,004 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-14 09:56:06,008 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt
2015-08-14 09:56:06,015 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:06,016 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:06,021 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt"]
2015-08-14 09:56:06,021 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/rename"]
2015-08-14 09:56:06,038 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/rename/_temporary
2015-08-14 09:56:06,072 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/rename
2015-08-14 09:56:06,098 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:06,099 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:06,121 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-14 09:56:06,122 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:56:06,122 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:06,122 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/multimerge+true653"]
2015-08-14 09:56:06,122 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-14 09:56:06,122 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-14 09:56:06,122 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-14 09:56:06,124 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...atform/multimerge+true653
2015-08-14 09:56:06,268 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local454328466_0020
2015-08-14 09:56:06,268 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-14 09:56:06,274 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:06,298 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:06,299 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:06,310 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:06,310 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-14 09:56:06,312 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:06,312 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 521, max: 672
2015-08-14 09:56:06,313 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:06,314 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:06,314 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 521, max: 672
2015-08-14 09:56:06,314 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:06,315 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:06,315 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 521, max: 672
2015-08-14 09:56:06,315 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:06,316 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:06,316 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 521, max: 672
2015-08-14 09:56:06,316 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:06,327 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt
2015-08-14 09:56:06,349 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:06,349 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:06,361 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:56:06,361 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-14 09:56:06,366 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:06,366 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 109, total: 521, max: 672
2015-08-14 09:56:06,367 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:06,368 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:06,368 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 109, total: 521, max: 672
2015-08-14 09:56:06,368 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:06,369 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:06,369 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 109, total: 521, max: 672
2015-08-14 09:56:06,370 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:06,370 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:06,370 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 109, total: 521, max: 672
2015-08-14 09:56:06,371 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:06,392 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:06,393 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:06,404 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by:[{1}:'char']]
2015-08-14 09:56:06,404 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/multimerge+true653"]
2015-08-14 09:56:06,440 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/multimerge+true653/_temporary
2015-08-14 09:56:06,510 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/multimerge+true653
2015-08-14 09:56:06,536 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:06,536 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:06,569 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second] starting
2015-08-14 09:56:06,570 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:06,570 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  sink: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/samesourcemergecount"]
2015-08-14 09:56:06,570 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  parallel execution is enabled: false
2015-08-14 09:56:06,570 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  starting jobs: 2
2015-08-14 09:56:06,570 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  allocating threads: 1
2015-08-14 09:56:06,571 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] starting step: (1/2)
2015-08-14 09:56:06,703 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] submitted hadoop job: job_local998945166_0021
2015-08-14 09:56:06,704 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] tracking url: http://localhost:8080/
2015-08-14 09:56:06,709 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:06,729 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:06,729 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:06,738 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:06,738 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(first)[by:[{1}:'char']]
2015-08-14 09:56:06,742 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:06,743 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 174, total: 521, max: 672
2015-08-14 09:56:06,743 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:06,744 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:06,744 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 174, total: 521, max: 672
2015-08-14 09:56:06,744 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:06,745 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:06,745 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 174, total: 521, max: 672
2015-08-14 09:56:06,745 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:06,746 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:06,746 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 174, total: 521, max: 672
2015-08-14 09:56:06,746 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:06,762 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:06,762 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:06,769 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(first)[by:[{1}:'char']]
2015-08-14 09:56:06,770 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][6549948916/first/]
2015-08-14 09:56:06,794 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] starting step: (2/2) ...form/samesourcemergecount
2015-08-14 09:56:06,934 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] submitted hadoop job: job_local572417796_0022
2015-08-14 09:56:06,935 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] tracking url: http://localhost:8080/
2015-08-14 09:56:06,939 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/6549948916_first_35ED5667D0114B8E82E6EB0E25CDD059/part-00000
2015-08-14 09:56:06,964 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:06,964 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:06,974 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][6549948916/first/]
2015-08-14 09:56:06,974 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(second)[by:[{1}:'char']]
2015-08-14 09:56:06,976 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:06,976 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 209, total: 522, max: 672
2015-08-14 09:56:06,977 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:06,977 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:06,977 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 209, total: 522, max: 672
2015-08-14 09:56:06,977 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:06,994 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:06,994 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:07,002 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(second)[by:[{1}:'char']]
2015-08-14 09:56:07,002 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/samesourcemergecount"]
2015-08-14 09:56:07,033 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/samesourcemergecount/_temporary
2015-08-14 09:56:07,099 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/samesourcemergecount
2015-08-14 09:56:07,125 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:07,125 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:07,137 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average] starting
2015-08-14 09:56:07,138 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:07,138 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  sink: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/average"]
2015-08-14 09:56:07,138 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  parallel execution is enabled: false
2015-08-14 09:56:07,138 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  starting jobs: 1
2015-08-14 09:56:07,139 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  allocating threads: 1
2015-08-14 09:56:07,141 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] starting step: (1/1) ...lyhelpersplatform/average
2015-08-14 09:56:07,269 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] submitted hadoop job: job_local646597439_0023
2015-08-14 09:56:07,270 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] tracking url: http://localhost:8080/
2015-08-14 09:56:07,276 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:07,301 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:07,301 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:07,308 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:07,309 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(average)[by:[{1}:'char']]
2015-08-14 09:56:07,311 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:07,311 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 210, total: 522, max: 672
2015-08-14 09:56:07,311 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:07,312 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:07,313 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 210, total: 522, max: 672
2015-08-14 09:56:07,313 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:07,314 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:07,314 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 210, total: 522, max: 672
2015-08-14 09:56:07,314 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:07,315 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:07,315 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 210, total: 522, max: 672
2015-08-14 09:56:07,316 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:07,333 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:07,333 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:07,340 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(average)[by:[{1}:'char']]
2015-08-14 09:56:07,340 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/average"]
2015-08-14 09:56:07,370 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/average/_temporary
2015-08-14 09:56:07,437 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/average
2015-08-14 09:56:07,459 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:07,460 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:07,472 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-14 09:56:07,472 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:07,472 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/maxbynullsafety"]
2015-08-14 09:56:07,473 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-14 09:56:07,473 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-14 09:56:07,473 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-14 09:56:07,474 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...splatform/maxbynullsafety
2015-08-14 09:56:07,600 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local1745065929_0024
2015-08-14 09:56:07,601 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-14 09:56:07,606 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:07,630 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:07,630 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:07,637 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:07,637 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'char']]
2015-08-14 09:56:07,639 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:07,639 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 522, max: 672
2015-08-14 09:56:07,639 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:07,640 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:07,641 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 522, max: 672
2015-08-14 09:56:07,641 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:07,641 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:07,642 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 522, max: 672
2015-08-14 09:56:07,643 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:07,643 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:07,644 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 522, max: 672
2015-08-14 09:56:07,644 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:07,664 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:07,664 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:07,671 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'char']]
2015-08-14 09:56:07,671 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/maxbynullsafety"]
2015-08-14 09:56:07,699 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/maxbynullsafety/_temporary
2015-08-14 09:56:07,765 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/maxbynullsafety
2015-08-14 09:56:07,788 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:07,789 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:07,803 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum] starting
2015-08-14 09:56:07,803 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:07,803 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  sink: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/sumnulls"]
2015-08-14 09:56:07,803 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  parallel execution is enabled: false
2015-08-14 09:56:07,803 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  starting jobs: 1
2015-08-14 09:56:07,803 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  allocating threads: 1
2015-08-14 09:56:07,804 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] starting step: (1/1) ...yhelpersplatform/sumnulls
2015-08-14 09:56:07,934 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] submitted hadoop job: job_local159862620_0025
2015-08-14 09:56:07,935 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] tracking url: http://localhost:8080/
2015-08-14 09:56:07,940 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:07,964 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:07,965 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:07,971 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:07,972 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(sum)[by:[{1}:'char']]
2015-08-14 09:56:07,981 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:07,981 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 522, max: 672
2015-08-14 09:56:07,981 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:07,982 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:07,983 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 522, max: 672
2015-08-14 09:56:07,983 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:07,984 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:07,984 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 522, max: 672
2015-08-14 09:56:07,985 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:07,985 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:07,986 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 522, max: 672
2015-08-14 09:56:07,986 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:08,002 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:08,003 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:08,009 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(sum)[by:[{1}:'char']]
2015-08-14 09:56:08,009 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/sumnulls"]
2015-08-14 09:56:08,043 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/sumnulls/_temporary
2015-08-14 09:56:08,108 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/sumnulls
2015-08-14 09:56:08,130 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:08,130 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:08,142 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-14 09:56:08,142 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:08,143 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/countall"]
2015-08-14 09:56:08,143 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-14 09:56:08,143 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 1
2015-08-14 09:56:08,143 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-14 09:56:08,146 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/1) ...yhelpersplatform/countall
2015-08-14 09:56:08,275 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local172351398_0026
2015-08-14 09:56:08,276 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-14 09:56:08,280 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:08,305 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:08,306 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:08,313 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:08,313 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{?}:NONE]]
2015-08-14 09:56:08,332 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:08,332 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:08,346 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{?}:NONE]]
2015-08-14 09:56:08,346 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/countall"]
2015-08-14 09:56:08,373 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/countall/_temporary
2015-08-14 09:56:08,438 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/countall
2015-08-14 09:56:08,463 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:08,464 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:08,479 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-14 09:56:08,479 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:08,480 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average', 'average2', 'first']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/multi"]
2015-08-14 09:56:08,480 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-14 09:56:08,480 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-14 09:56:08,480 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-14 09:56:08,481 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...mblyhelpersplatform/multi
2015-08-14 09:56:08,616 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local391839123_0027
2015-08-14 09:56:08,616 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-14 09:56:08,621 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:08,646 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:08,646 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:08,657 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:08,657 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-14 09:56:08,659 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:08,659 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 212, total: 522, max: 672
2015-08-14 09:56:08,659 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:08,661 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:08,661 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 212, total: 522, max: 672
2015-08-14 09:56:08,661 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:08,662 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:08,662 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 522, max: 672
2015-08-14 09:56:08,662 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:08,663 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:08,663 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 522, max: 672
2015-08-14 09:56:08,663 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:08,681 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:08,681 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:08,691 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by:[{1}:'char']]
2015-08-14 09:56:08,691 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average', 'average2', 'first']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/multi"]
2015-08-14 09:56:08,724 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/multi/_temporary
2015-08-14 09:56:08,792 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/multi
2015-08-14 09:56:08,814 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:08,814 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:08,825 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-14 09:56:08,825 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt"]
2015-08-14 09:56:08,825 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/retainnarrow"]
2015-08-14 09:56:08,825 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-14 09:56:08,825 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-14 09:56:08,825 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-14 09:56:08,826 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...persplatform/retainnarrow
2015-08-14 09:56:08,950 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local2014744093_0028
2015-08-14 09:56:08,951 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-14 09:56:08,956 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt
2015-08-14 09:56:08,963 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:08,963 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:08,967 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt"]
2015-08-14 09:56:08,967 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/retainnarrow"]
2015-08-14 09:56:08,985 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/retainnarrow/_temporary
2015-08-14 09:56:09,018 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/retainnarrow
2015-08-14 09:56:09,039 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:09,040 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:09,052 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-14 09:56:09,052 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt"]
2015-08-14 09:56:09,052 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['item']->['char', 'item']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/renamenarrow"]
2015-08-14 09:56:09,052 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-14 09:56:09,053 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-14 09:56:09,053 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-14 09:56:09,053 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...persplatform/renamenarrow
2015-08-14 09:56:09,188 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local2109311308_0029
2015-08-14 09:56:09,188 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-14 09:56:09,194 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt
2015-08-14 09:56:09,201 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:09,201 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:09,205 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt"]
2015-08-14 09:56:09,205 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['item']->['char', 'item']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/renamenarrow"]
2015-08-14 09:56:09,221 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/renamenarrow/_temporary
2015-08-14 09:56:09,254 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/renamenarrow
2015-08-14 09:56:09,281 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:09,282 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:09,296 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average] starting
2015-08-14 09:56:09,297 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:09,297 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  sink: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/averagenull"]
2015-08-14 09:56:09,297 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  parallel execution is enabled: false
2015-08-14 09:56:09,297 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  starting jobs: 1
2015-08-14 09:56:09,297 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  allocating threads: 1
2015-08-14 09:56:09,298 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] starting step: (1/1) ...lpersplatform/averagenull
2015-08-14 09:56:09,432 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] submitted hadoop job: job_local835870542_0030
2015-08-14 09:56:09,433 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] tracking url: http://localhost:8080/
2015-08-14 09:56:09,438 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:09,458 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:09,458 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:09,464 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:09,464 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(average)[by:[{1}:'char']]
2015-08-14 09:56:09,468 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:09,468 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 177, total: 522, max: 672
2015-08-14 09:56:09,469 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:09,469 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:09,470 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 177, total: 522, max: 672
2015-08-14 09:56:09,470 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:09,471 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:09,471 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 177, total: 522, max: 672
2015-08-14 09:56:09,471 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:09,471 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:09,472 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 177, total: 522, max: 672
2015-08-14 09:56:09,472 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:09,487 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:09,487 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:09,492 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(average)[by:[{1}:'char']]
2015-08-14 09:56:09,492 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/averagenull"]
2015-08-14 09:56:09,519 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/averagenull/_temporary
2015-08-14 09:56:09,586 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/averagenull
2015-08-14 09:56:09,608 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:09,608 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:09,619 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce] starting
2015-08-14 09:56:09,619 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt"]
2015-08-14 09:56:09,619 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  sink: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/coerce"]
2015-08-14 09:56:09,620 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  parallel execution is enabled: false
2015-08-14 09:56:09,620 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  starting jobs: 1
2015-08-14 09:56:09,620 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  allocating threads: 1
2015-08-14 09:56:09,621 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] starting step: (1/1) ...blyhelpersplatform/coerce
2015-08-14 09:56:09,743 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] submitted hadoop job: job_local1488910777_0031
2015-08-14 09:56:09,744 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] tracking url: http://localhost:8080/
2015-08-14 09:56:09,748 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt
2015-08-14 09:56:09,755 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:09,756 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:09,759 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lower.txt"]
2015-08-14 09:56:09,760 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/coerce"]
2015-08-14 09:56:09,777 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/coerce/_temporary
2015-08-14 09:56:09,810 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/coerce
2015-08-14 09:56:09,831 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:09,832 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:09,843 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first] starting
2015-08-14 09:56:09,843 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  source: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs+rhs-cross-rev.txt"]
2015-08-14 09:56:09,843 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  sink: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/firstnfieldswithoutcomparator"]
2015-08-14 09:56:09,843 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  parallel execution is enabled: false
2015-08-14 09:56:09,844 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  starting jobs: 1
2015-08-14 09:56:09,844 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  allocating threads: 1
2015-08-14 09:56:09,844 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] starting step: (1/1) ...tnfieldswithoutcomparator
2015-08-14 09:56:09,981 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] submitted hadoop job: job_local550156891_0032
2015-08-14 09:56:09,981 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] tracking url: http://localhost:8080/
2015-08-14 09:56:09,986 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs+rhs-cross-rev.txt
2015-08-14 09:56:10,006 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:10,006 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:10,011 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs+rhs-cross-rev.txt"]
2015-08-14 09:56:10,011 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(first)[by:[{1}:'num']]
2015-08-14 09:56:10,014 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:10,014 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 193, total: 523, max: 672
2015-08-14 09:56:10,014 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,016 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:10,016 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 193, total: 523, max: 672
2015-08-14 09:56:10,016 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,031 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:10,031 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:10,036 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(first)[by:[{1}:'num']]
2015-08-14 09:56:10,036 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/firstnfieldswithoutcomparator"]
2015-08-14 09:56:10,067 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/firstnfieldswithoutcomparator/_temporary
2015-08-14 09:56:10,100 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/firstnfieldswithoutcomparator
2015-08-14 09:56:10,126 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:10,127 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:10,145 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-14 09:56:10,146 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:56:10,146 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:10,146 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/multimerge+false654"]
2015-08-14 09:56:10,146 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-14 09:56:10,146 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-14 09:56:10,146 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-14 09:56:10,147 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...tform/multimerge+false654
2015-08-14 09:56:10,269 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local197389823_0033
2015-08-14 09:56:10,270 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-14 09:56:10,274 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:10,299 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:10,300 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:10,307 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:10,308 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-14 09:56:10,309 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:10,309 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 212, total: 523, max: 672
2015-08-14 09:56:10,310 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,311 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:10,311 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 212, total: 523, max: 672
2015-08-14 09:56:10,311 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,312 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:10,312 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 212, total: 523, max: 672
2015-08-14 09:56:10,312 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,313 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:10,313 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 212, total: 523, max: 672
2015-08-14 09:56:10,313 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,323 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt
2015-08-14 09:56:10,344 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:10,344 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:10,352 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:56:10,352 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-14 09:56:10,356 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:10,357 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 110, total: 523, max: 672
2015-08-14 09:56:10,357 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,358 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:10,358 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 110, total: 523, max: 672
2015-08-14 09:56:10,358 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,359 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:10,359 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 110, total: 523, max: 672
2015-08-14 09:56:10,360 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,360 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:10,360 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 110, total: 523, max: 672
2015-08-14 09:56:10,361 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,379 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:10,380 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:10,387 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-14 09:56:10,387 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/multimerge+false654"]
2015-08-14 09:56:10,419 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/multimerge+false654/_temporary
2015-08-14 09:56:10,482 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/multimerge+false654
2015-08-14 09:56:10,508 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:10,508 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:10,561 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...] starting
2015-08-14 09:56:10,562 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:10,562 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  sink: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/samesourcemergethreeway"]
2015-08-14 09:56:10,563 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  parallel execution is enabled: false
2015-08-14 09:56:10,563 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  starting jobs: 5
2015-08-14 09:56:10,563 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  allocating threads: 1
2015-08-14 09:56:10,564 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (1/5)
2015-08-14 09:56:10,694 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local349879792_0034
2015-08-14 09:56:10,694 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-14 09:56:10,699 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:10,719 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:10,719 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:10,725 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:10,725 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(source)[by:[{1}:'char']]
2015-08-14 09:56:10,726 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:10,727 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 179, total: 523, max: 672
2015-08-14 09:56:10,727 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,728 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:10,728 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 179, total: 523, max: 672
2015-08-14 09:56:10,728 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,728 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 09:56:10,729 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 179, total: 523, max: 672
2015-08-14 09:56:10,729 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,729 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 09:56:10,729 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 179, total: 523, max: 672
2015-08-14 09:56:10,729 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,745 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:10,746 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:10,750 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(source)[by:[{1}:'char']]
2015-08-14 09:56:10,750 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][6347023931/source/]
2015-08-14 09:56:10,781 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (3/5)
2015-08-14 09:56:10,919 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local983608263_0035
2015-08-14 09:56:10,920 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-14 09:56:10,924 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/6347023931_source_D98DF89D5A6E4C1EB69B03ABB0DE198C/part-00000
2015-08-14 09:56:10,949 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:10,950 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:10,955 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][6347023931/source/]
2015-08-14 09:56:10,955 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count-lhs)[by:[{1}:'char']]
2015-08-14 09:56:10,957 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:10,957 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 212, total: 523, max: 672
2015-08-14 09:56:10,957 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,957 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:10,958 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 212, total: 523, max: 672
2015-08-14 09:56:10,958 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:10,972 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:10,972 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:10,976 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count-lhs)[by:[{1}:'char']]
2015-08-14 09:56:10,977 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][718366412/count-lhs/]
2015-08-14 09:56:11,009 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (4/5)
2015-08-14 09:56:11,146 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local1803571236_0036
2015-08-14 09:56:11,147 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-14 09:56:11,152 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/6347023931_source_D98DF89D5A6E4C1EB69B03ABB0DE198C/part-00000
2015-08-14 09:56:11,176 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:11,176 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:11,182 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][6347023931/source/]
2015-08-14 09:56:11,182 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count-rhs)[by:[{1}:'char']]
2015-08-14 09:56:11,183 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 09:56:11,183 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 523, max: 672
2015-08-14 09:56:11,183 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:11,184 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 09:56:11,184 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 523, max: 672
2015-08-14 09:56:11,184 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 09:56:11,199 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:11,199 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:11,203 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count-rhs)[by:[{1}:'char']]
2015-08-14 09:56:11,203 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][3716029952/count-rhs/]
2015-08-14 09:56:11,234 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (2/5)
2015-08-14 09:56:11,379 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local1072746064_0037
2015-08-14 09:56:11,379 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-14 09:56:11,385 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/6347023931_source_D98DF89D5A6E4C1EB69B03ABB0DE198C/part-00000
2015-08-14 09:56:11,411 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:11,412 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:11,418 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][6347023931/source/]
2015-08-14 09:56:11,418 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(source*count-rhs)[by: source:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-14 09:56:11,426 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/3716029952_count_rhs_349DD07751C14EA7BA8BDCA330F9CBB7/part-00000
2015-08-14 09:56:11,446 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:11,446 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:11,451 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][3716029952/count-rhs/]
2015-08-14 09:56:11,451 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(source*count-rhs)[by: source:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-14 09:56:11,468 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:11,469 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:11,473 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(source*count-rhs)[by: source:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-14 09:56:11,473 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'num', 'char2', 'count']]"][1042659984/source_count-rhs/]
2015-08-14 09:56:11,486 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-14 09:56:11,486 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-14 09:56:11,508 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (5/5) ...m/samesourcemergethreeway
2015-08-14 09:56:11,668 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local1100578743_0038
2015-08-14 09:56:11,669 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-14 09:56:11,674 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/1042659984_source_count_rhs_5B6D4A0BF5F64F4C99F50E3C2693032A/part-00000
2015-08-14 09:56:11,693 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:11,694 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:11,700 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'num', 'char2', 'count']]"][1042659984/source_count-rhs/]
2015-08-14 09:56:11,700 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(count-lhs*source*count-rhs)[by: count-lhs:[{1}:'char'] source*count-rhs:[{1}:'char']]
2015-08-14 09:56:11,709 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/718366412_count_lhs_644ABCB8DF7B4C0495EFD5E6EAAF16A7/part-00000
2015-08-14 09:56:11,729 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:11,729 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:11,735 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][718366412/count-lhs/]
2015-08-14 09:56:11,735 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(count-lhs*source*count-rhs)[by: count-lhs:[{1}:'char'] source*count-rhs:[{1}:'char']]
2015-08-14 09:56:11,752 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:11,753 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:11,758 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(count-lhs*source*count-rhs)[by: count-lhs:[{1}:'char'] source*count-rhs:[{1}:'char']]
2015-08-14 09:56:11,758 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/samesourcemergethreeway"]
2015-08-14 09:56:11,765 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-14 09:56:11,765 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-14 09:56:11,788 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/samesourcemergethreeway/_temporary
2015-08-14 09:56:11,856 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/samesourcemergethreeway
2015-08-14 09:56:11,883 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:11,883 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:11,901 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs] starting
2015-08-14 09:56:11,901 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:56:11,901 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:11,902 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  sink: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/uniquemerge-nondeterministic"]
2015-08-14 09:56:11,902 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  parallel execution is enabled: false
2015-08-14 09:56:11,902 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  starting jobs: 1
2015-08-14 09:56:11,902 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  allocating threads: 1
2015-08-14 09:56:11,903 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [lhs+rhs] starting step: (1/1) ...quemerge-nondeterministic
2015-08-14 09:56:12,025 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [lhs+rhs] submitted hadoop job: job_local1556579331_0039
2015-08-14 09:56:12,026 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [lhs+rhs] tracking url: http://localhost:8080/
2015-08-14 09:56:12,031 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:12,050 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:12,050 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:12,055 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:12,055 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-08-14 09:56:12,069 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt
2015-08-14 09:56:12,093 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:12,093 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:12,097 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/rhs.txt"]
2015-08-14 09:56:12,097 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-08-14 09:56:12,117 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:12,117 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:12,122 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-08-14 09:56:12,122 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/uniquemerge-nondeterministic"]
2015-08-14 09:56:12,157 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/uniquemerge-nondeterministic/_temporary
2015-08-14 09:56:12,190 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/uniquemerge-nondeterministic
2015-08-14 09:56:12,213 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:12,213 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:12,225 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-14 09:56:12,225 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:12,226 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/unique"]
2015-08-14 09:56:12,226 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-14 09:56:12,226 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-14 09:56:12,226 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-14 09:56:12,227 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...blyhelpersplatform/unique
2015-08-14 09:56:12,349 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local254361603_0040
2015-08-14 09:56:12,350 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-14 09:56:12,355 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:12,379 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:12,379 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:12,383 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:12,384 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(shape)[by:[{1}:'num']]
2015-08-14 09:56:12,400 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:12,401 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:12,404 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(shape)[by:[{1}:'num']]
2015-08-14 09:56:12,404 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/unique"]
2015-08-14 09:56:12,437 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/unique/_temporary
2015-08-14 09:56:12,469 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/unique
2015-08-14 09:56:12,493 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 09:56:12,494 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.7.1/78a07fbd83388056abdb4b5e48f666735b06cf7c/cascading-hadoop2-mr1-2.7.1.jar
2015-08-14 09:56:12,506 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-14 09:56:12,507 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:12,507 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['notnull', 'null']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/countnullnotnull"]
2015-08-14 09:56:12,507 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-14 09:56:12,507 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 1
2015-08-14 09:56:12,507 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-14 09:56:12,508 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/1) ...platform/countnullnotnull
2015-08-14 09:56:12,629 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local213688275_0041
2015-08-14 09:56:12,629 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-14 09:56:12,634 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt
2015-08-14 09:56:12,658 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 09:56:12,658 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 09:56:12,665 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/classes/test/data/lhs.txt"]
2015-08-14 09:56:12,665 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{?}:NONE]]
2015-08-14 09:56:12,684 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 09:56:12,684 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 09:56:12,690 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{?}:NONE]]
2015-08-14 09:56:12,690 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['notnull', 'null']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/countnullnotnull"]
2015-08-14 09:56:12,715 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output/hadoop2-mr1/assemblyhelpersplatform/countnullnotnull/_temporary
2015-08-14 09:56:12,777 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-2.6.x/build/test/output//hadoop2-mr1/assemblyhelpersplatform/countnullnotnull