Class cascading.pipe.assembly.AssemblyHelpersPlatformTest

all > cascading.pipe.assembly > AssemblyHelpersPlatformTest
35

tests
0

failures
4m20.68s

duration
100%

successful

Tests

Test Duration Result
testAverageBy 6.091s passed
testAverageByNull 6.090s passed
testAverageMerge 9.224s passed
testCoerce 3.085s passed
testCoerceFields 3.109s passed
testCount 6.116s passed
testCountAll 6.086s passed
testCountCount 12.277s passed
testCountMerge 9.151s passed
testCountNullNotNull 6.088s passed
testDiscardNarrow 3.085s passed
testFirstBy 6.121s passed
testFirstByWithoutComparator 6.078s passed
testMaxBy 6.132s passed
testMaxByNullSafety 6.091s passed
testMaxByString 6.134s passed
testMinBy 6.097s passed
testMinByNullSafety 6.130s passed
testMinByString 6.243s passed
testParallelAggregates 6.108s passed
testParallelAggregatesMerge 10.438s passed
testParallelAggregatesMergeLegacyHash 9.102s passed
testParallelAggregatesPriorMerge 9.133s passed
testParallelAggregatesPriorMergeLegacyHash 9.127s passed
testRenameAll 3.126s passed
testRenameNamed 3.093s passed
testRenameNarrow 3.070s passed
testRetainNarrow 3.075s passed
testSameSourceMerge 12.189s passed
testSameSourceMergeThreeWay 36.322s passed
testSumBy 6.100s passed
testSumByNulls 6.092s passed
testSumMerge 9.112s passed
testUnique 6.075s passed
testUniqueMerge 9.086s passed

Standard output

2015-08-13 19:15:45,375 INFO  platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2015-08-13 19:15:45,423 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop
2015-08-13 19:15:45,423 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.pipe.assembly.AssemblyHelpersPlatformTest
2015-08-13 19:15:45,467 INFO  hadoop.HadoopPlatform (HadoopPlatform.java:setUp(112)) - not using cluster
2015-08-13 19:15:45,749 INFO  platform.TestPlatform (TestPlatform.java:getGlobalProperties(72)) - platform property overrides: 
2015-08-13 19:15:46,147 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:15:46,149 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:15:46,162 INFO  property.AppProps (AppProps.java:getAppID(169)) - using app.id: 414E1547D7B24D3A9A54AD2293EA67BF
2015-08-13 19:15:46,452 INFO  util.Version (Version.java:printBanner(85)) - Concurrent, Inc - Cascading 2.7.1
2015-08-13 19:15:46,454 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-13 19:15:46,455 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:15:46,456 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:15:46,456 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false162"]
2015-08-13 19:15:46,457 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-13 19:15:46,457 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-13 19:15:46,458 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-13 19:15:46,461 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...tform/multimerge+false162
2015-08-13 19:15:46,503 WARN  util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2015-08-13 19:15:46,763 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local_0001
2015-08-13 19:15:46,765 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-13 19:15:46,842 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:15:47,010 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:15:47,010 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:15:47,081 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:15:47,082 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-13 19:15:47,103 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:15:47,103 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 83, total: 197, max: 672
2015-08-13 19:15:47,103 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-13 19:15:47,105 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:15:47,105 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 83, total: 197, max: 672
2015-08-13 19:15:47,105 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-13 19:15:47,106 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:15:47,107 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 83, total: 197, max: 672
2015-08-13 19:15:47,107 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-13 19:15:47,108 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:15:47,108 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 83, total: 197, max: 672
2015-08-13 19:15:47,108 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-13 19:15:49,817 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt
2015-08-13 19:15:49,956 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:15:49,956 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:15:49,984 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:15:49,984 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-13 19:15:50,085 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:15:50,085 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 74, total: 292, max: 672
2015-08-13 19:15:50,085 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 43% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:15:50,087 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:15:50,087 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 74, total: 292, max: 672
2015-08-13 19:15:50,087 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 43% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:15:50,089 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:15:50,089 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 74, total: 292, max: 672
2015-08-13 19:15:50,089 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 43% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:15:50,090 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:15:50,091 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 74, total: 292, max: 672
2015-08-13 19:15:50,091 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 43% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:15:52,849 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:15:52,849 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:15:52,886 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-13 19:15:52,887 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false162"]
2015-08-13 19:15:55,850 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false162/_temporary
2015-08-13 19:15:55,902 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/multimerge+false162
2015-08-13 19:15:55,935 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:15:55,935 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:15:55,973 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-13 19:15:55,974 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:15:55,974 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['num', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/minbystring"]
2015-08-13 19:15:55,975 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-13 19:15:55,975 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-13 19:15:55,976 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-13 19:15:55,977 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...lpersplatform/minbystring
2015-08-13 19:15:56,081 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local_0002
2015-08-13 19:15:56,083 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-13 19:15:56,092 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:15:56,228 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:15:56,229 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:15:56,242 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:15:56,243 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'num']]
2015-08-13 19:15:56,245 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:15:56,245 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 83, total: 387, max: 672
2015-08-13 19:15:56,246 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 57% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:15:56,246 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:15:56,247 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 83, total: 387, max: 672
2015-08-13 19:15:56,247 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 57% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:15:59,097 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:15:59,097 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:15:59,110 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'num']]
2015-08-13 19:15:59,111 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/minbystring"]
2015-08-13 19:16:02,103 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/minbystring/_temporary
2015-08-13 19:16:02,147 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/minbystring
2015-08-13 19:16:02,179 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:16:02,179 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:16:02,220 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs] starting
2015-08-13 19:16:02,221 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:16:02,221 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:16:02,221 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  sink: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/mergeaverage"]
2015-08-13 19:16:02,222 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  parallel execution is enabled: false
2015-08-13 19:16:02,222 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  starting jobs: 1
2015-08-13 19:16:02,222 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  allocating threads: 1
2015-08-13 19:16:02,223 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average-lhs+average-rhs] starting step: (1/1) ...persplatform/mergeaverage
2015-08-13 19:16:02,312 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average-lhs+average-rhs] submitted hadoop job: job_local_0003
2015-08-13 19:16:02,314 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average-lhs+average-rhs] tracking url: http://localhost:8080/
2015-08-13 19:16:02,319 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:16:02,469 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:16:02,470 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:16:02,486 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:16:02,486 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-13 19:16:02,488 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:16:02,488 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 93, total: 482, max: 672
2015-08-13 19:16:02,488 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 71% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:02,489 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:16:02,490 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 93, total: 482, max: 672
2015-08-13 19:16:02,490 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 71% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:02,491 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:16:02,491 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 93, total: 482, max: 672
2015-08-13 19:16:02,491 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 71% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:02,492 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:16:02,492 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 93, total: 482, max: 672
2015-08-13 19:16:02,492 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 71% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:05,323 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt
2015-08-13 19:16:05,456 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:16:05,456 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:16:05,472 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:16:05,472 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-13 19:16:05,477 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:16:05,477 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 45, total: 535, max: 672
2015-08-13 19:16:05,478 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 79% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:05,479 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:16:05,479 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 45, total: 535, max: 672
2015-08-13 19:16:05,479 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 79% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:05,480 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:16:05,480 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 45, total: 535, max: 672
2015-08-13 19:16:05,480 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 79% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:05,481 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:16:05,481 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 45, total: 535, max: 672
2015-08-13 19:16:05,482 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 79% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:08,334 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:16:08,335 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:16:08,350 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-13 19:16:08,350 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/mergeaverage"]
2015-08-13 19:16:11,346 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/mergeaverage/_temporary
2015-08-13 19:16:11,373 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/mergeaverage
2015-08-13 19:16:11,391 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:16:11,391 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:16:11,415 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-13 19:16:11,415 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2015-08-13 19:16:11,415 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/renameall"]
2015-08-13 19:16:11,416 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-13 19:16:11,416 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-13 19:16:11,416 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-13 19:16:11,417 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...helpersplatform/renameall
2015-08-13 19:16:11,468 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local_0004
2015-08-13 19:16:11,470 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-13 19:16:11,475 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt
2015-08-13 19:16:11,482 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:16:11,482 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:16:11,491 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2015-08-13 19:16:11,491 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/renameall"]
2015-08-13 19:16:14,487 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/renameall/_temporary
2015-08-13 19:16:14,500 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/renameall
2015-08-13 19:16:14,520 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:16:14,521 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:16:14,572 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-13 19:16:14,573 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:16:14,573 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['count', 'count2']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/countcount"]
2015-08-13 19:16:14,574 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-13 19:16:14,574 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 2
2015-08-13 19:16:14,574 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-13 19:16:14,575 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/2)
2015-08-13 19:16:14,646 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local_0005
2015-08-13 19:16:14,646 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-13 19:16:14,651 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:16:15,008 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:16:15,008 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:16:15,020 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:16:15,020 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{1}:'char']]
2015-08-13 19:16:15,022 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:16:15,022 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 72, total: 176, max: 672
2015-08-13 19:16:15,022 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 26% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:15,023 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:16:15,024 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 72, total: 176, max: 672
2015-08-13 19:16:15,024 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 26% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:15,024 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:16:15,025 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 72, total: 176, max: 672
2015-08-13 19:16:15,025 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 26% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:15,025 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:16:15,026 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 72, total: 176, max: 672
2015-08-13 19:16:15,026 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 26% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:17,658 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:16:17,658 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:16:17,670 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{1}:'char']]
2015-08-13 19:16:17,670 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['count', 'count2']]"][411535100/count/]
2015-08-13 19:16:17,684 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:16:17,684 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 71, total: 176, max: 672
2015-08-13 19:16:17,684 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 26% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:20,661 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (2/2) ...elpersplatform/countcount
2015-08-13 19:16:20,727 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local_0006
2015-08-13 19:16:20,729 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-13 19:16:20,736 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/411535100_count_6ADFD4A83A294C629371F99E5B209DCF/part-00000
2015-08-13 19:16:20,890 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:16:20,891 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:16:20,904 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['count', 'count2']]"][411535100/count/]
2015-08-13 19:16:20,904 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{1}:'count']]
2015-08-13 19:16:23,743 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:16:23,743 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:16:23,755 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{1}:'count']]
2015-08-13 19:16:23,755 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['count', 'count2']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/countcount"]
2015-08-13 19:16:26,753 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/countcount/_temporary
2015-08-13 19:16:26,777 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/countcount
2015-08-13 19:16:26,797 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:16:26,797 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:16:26,830 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs] starting
2015-08-13 19:16:26,830 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:16:26,830 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:16:26,831 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  sink: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/mergecount"]
2015-08-13 19:16:26,831 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  parallel execution is enabled: false
2015-08-13 19:16:26,831 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  starting jobs: 1
2015-08-13 19:16:26,831 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  allocating threads: 1
2015-08-13 19:16:26,832 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs+count-rhs] starting step: (1/1) ...elpersplatform/mergecount
2015-08-13 19:16:26,876 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs+count-rhs] submitted hadoop job: job_local_0007
2015-08-13 19:16:26,877 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs+count-rhs] tracking url: http://localhost:8080/
2015-08-13 19:16:26,882 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:16:27,027 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:16:27,027 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:16:27,041 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:16:27,042 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-13 19:16:27,043 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:16:27,044 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 93, total: 392, max: 672
2015-08-13 19:16:27,044 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-13 19:16:27,045 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:16:27,045 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 93, total: 392, max: 672
2015-08-13 19:16:27,045 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-13 19:16:27,046 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:16:27,046 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 93, total: 392, max: 672
2015-08-13 19:16:27,046 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-13 19:16:27,047 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:16:27,047 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 93, total: 392, max: 672
2015-08-13 19:16:27,047 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-13 19:16:29,885 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt
2015-08-13 19:16:30,019 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:16:30,020 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:16:30,034 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:16:30,034 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-13 19:16:30,038 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:16:30,038 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 86, total: 487, max: 672
2015-08-13 19:16:30,039 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:30,040 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:16:30,040 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 86, total: 487, max: 672
2015-08-13 19:16:30,040 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:30,041 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:16:30,041 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 86, total: 487, max: 672
2015-08-13 19:16:30,041 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:30,042 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:16:30,042 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 86, total: 487, max: 672
2015-08-13 19:16:30,042 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:32,895 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:16:32,896 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:16:32,909 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-13 19:16:32,909 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/mergecount"]
2015-08-13 19:16:35,906 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/mergecount/_temporary
2015-08-13 19:16:35,929 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/mergecount
2015-08-13 19:16:35,945 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:16:35,946 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:16:35,970 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min] starting
2015-08-13 19:16:35,970 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:16:35,970 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  sink: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/minbynullsafety"]
2015-08-13 19:16:35,971 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  parallel execution is enabled: false
2015-08-13 19:16:35,971 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  starting jobs: 1
2015-08-13 19:16:35,971 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  allocating threads: 1
2015-08-13 19:16:35,972 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] starting step: (1/1) ...splatform/minbynullsafety
2015-08-13 19:16:36,014 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] submitted hadoop job: job_local_0008
2015-08-13 19:16:36,014 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] tracking url: http://localhost:8080/
2015-08-13 19:16:36,019 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:16:36,155 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:16:36,155 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:16:36,167 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:16:36,168 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(min)[by:[{1}:'char']]
2015-08-13 19:16:36,170 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:16:36,170 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 48, total: 560, max: 672
2015-08-13 19:16:36,171 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:16:36,171 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 48, total: 560, max: 672
2015-08-13 19:16:36,172 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:16:36,172 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 48, total: 560, max: 672
2015-08-13 19:16:36,173 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:16:36,173 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 48, total: 560, max: 672
2015-08-13 19:16:39,025 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:16:39,026 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:16:39,037 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(min)[by:[{1}:'char']]
2015-08-13 19:16:39,037 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/minbynullsafety"]
2015-08-13 19:16:42,037 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/minbynullsafety/_temporary
2015-08-13 19:16:42,059 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/minbynullsafety
2015-08-13 19:16:42,076 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:16:42,076 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:16:42,101 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-13 19:16:42,101 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:16:42,101 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['num', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/maxbystring"]
2015-08-13 19:16:42,102 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-13 19:16:42,102 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-13 19:16:42,102 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-13 19:16:42,103 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...lpersplatform/maxbystring
2015-08-13 19:16:42,148 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local_0009
2015-08-13 19:16:42,149 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-13 19:16:42,155 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:16:42,485 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:16:42,485 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:16:42,496 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:16:42,496 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'num']]
2015-08-13 19:16:42,498 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:16:42,499 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 100, total: 204, max: 672
2015-08-13 19:16:42,499 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 30% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:42,500 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:16:42,500 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 100, total: 204, max: 672
2015-08-13 19:16:42,500 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 30% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:16:45,161 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:16:45,161 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:16:45,171 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'num']]
2015-08-13 19:16:45,172 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/maxbystring"]
2015-08-13 19:16:48,172 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/maxbystring/_temporary
2015-08-13 19:16:48,193 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/maxbystring
2015-08-13 19:16:48,210 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:16:48,211 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:16:48,239 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first] starting
2015-08-13 19:16:48,239 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  source: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs+rhs-cross.txt"]
2015-08-13 19:16:48,240 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  sink: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/firstnfields"]
2015-08-13 19:16:48,240 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  parallel execution is enabled: false
2015-08-13 19:16:48,240 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  starting jobs: 1
2015-08-13 19:16:48,240 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  allocating threads: 1
2015-08-13 19:16:48,241 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] starting step: (1/1) ...persplatform/firstnfields
2015-08-13 19:16:48,279 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] submitted hadoop job: job_local_0010
2015-08-13 19:16:48,280 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] tracking url: http://localhost:8080/
2015-08-13 19:16:48,287 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs+rhs-cross.txt
2015-08-13 19:16:48,437 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:16:48,437 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:16:48,448 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs+rhs-cross.txt"]
2015-08-13 19:16:48,448 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(first)[by:[{1}:'num']]
2015-08-13 19:16:48,452 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:16:48,452 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 84, total: 299, max: 672
2015-08-13 19:16:48,452 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-13 19:16:48,454 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:16:48,454 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 84, total: 299, max: 672
2015-08-13 19:16:48,454 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-13 19:16:51,294 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:16:51,294 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:16:51,304 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(first)[by:[{1}:'num']]
2015-08-13 19:16:51,304 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/firstnfields"]
2015-08-13 19:16:54,304 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/firstnfields/_temporary
2015-08-13 19:16:54,314 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/firstnfields
2015-08-13 19:16:54,332 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:16:54,332 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:16:54,354 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce] starting
2015-08-13 19:16:54,355 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2015-08-13 19:16:54,355 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  sink: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/coercefields"]
2015-08-13 19:16:54,356 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  parallel execution is enabled: false
2015-08-13 19:16:54,357 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  starting jobs: 1
2015-08-13 19:16:54,357 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  allocating threads: 1
2015-08-13 19:16:54,358 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] starting step: (1/1) ...persplatform/coercefields
2015-08-13 19:16:54,396 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] submitted hadoop job: job_local_0011
2015-08-13 19:16:54,397 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] tracking url: http://localhost:8080/
2015-08-13 19:16:54,402 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt
2015-08-13 19:16:54,406 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:16:54,406 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:16:54,415 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2015-08-13 19:16:54,416 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/coercefields"]
2015-08-13 19:16:57,413 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/coercefields/_temporary
2015-08-13 19:16:57,424 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/coercefields
2015-08-13 19:16:57,437 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:16:57,438 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:16:57,456 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-13 19:16:57,457 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:16:57,457 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/count"]
2015-08-13 19:16:57,458 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-13 19:16:57,458 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 1
2015-08-13 19:16:57,459 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-13 19:16:57,460 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/1) ...mblyhelpersplatform/count
2015-08-13 19:16:57,495 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local_0012
2015-08-13 19:16:57,495 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-13 19:16:57,500 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:16:57,641 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:16:57,641 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:16:57,652 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:16:57,652 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{1}:'char']]
2015-08-13 19:16:57,654 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:16:57,654 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 63, total: 394, max: 672
2015-08-13 19:16:57,654 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-13 19:16:57,655 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:16:57,656 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 63, total: 394, max: 672
2015-08-13 19:16:57,656 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-13 19:16:57,656 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:16:57,657 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 63, total: 394, max: 672
2015-08-13 19:16:57,657 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-13 19:16:57,657 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:16:57,658 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 63, total: 394, max: 672
2015-08-13 19:16:57,658 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-13 19:17:00,508 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:17:00,508 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:17:00,521 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{1}:'char']]
2015-08-13 19:17:00,521 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/count"]
2015-08-13 19:17:03,517 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/count/_temporary
2015-08-13 19:17:03,540 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/count
2015-08-13 19:17:03,557 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:17:03,557 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:17:03,577 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-13 19:17:03,578 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:17:03,578 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/maxby"]
2015-08-13 19:17:03,579 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-13 19:17:03,579 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-13 19:17:03,579 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-13 19:17:03,581 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...mblyhelpersplatform/maxby
2015-08-13 19:17:03,621 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local_0013
2015-08-13 19:17:03,621 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-13 19:17:03,639 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:17:03,776 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:17:03,777 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:17:03,787 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:17:03,788 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'char']]
2015-08-13 19:17:03,790 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:17:03,790 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 95, total: 489, max: 672
2015-08-13 19:17:03,791 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:03,792 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:17:03,792 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 95, total: 489, max: 672
2015-08-13 19:17:03,793 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:03,794 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:17:03,794 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 95, total: 489, max: 672
2015-08-13 19:17:03,795 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:03,796 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:17:03,796 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 95, total: 489, max: 672
2015-08-13 19:17:03,797 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:06,644 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:17:06,646 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:17:06,655 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'char']]
2015-08-13 19:17:06,656 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/maxby"]
2015-08-13 19:17:09,653 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/maxby/_temporary
2015-08-13 19:17:09,673 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/maxby
2015-08-13 19:17:09,685 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:17:09,685 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:17:09,702 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min] starting
2015-08-13 19:17:09,702 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:17:09,703 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  sink: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/minby"]
2015-08-13 19:17:09,703 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  parallel execution is enabled: false
2015-08-13 19:17:09,703 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  starting jobs: 1
2015-08-13 19:17:09,703 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  allocating threads: 1
2015-08-13 19:17:09,704 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] starting step: (1/1) ...mblyhelpersplatform/minby
2015-08-13 19:17:09,737 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] submitted hadoop job: job_local_0014
2015-08-13 19:17:09,737 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] tracking url: http://localhost:8080/
2015-08-13 19:17:09,741 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:17:09,873 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:17:09,873 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:17:09,883 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:17:09,883 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(min)[by:[{1}:'char']]
2015-08-13 19:17:09,885 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:17:09,885 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 55, total: 560, max: 672
2015-08-13 19:17:09,886 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:17:09,886 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 55, total: 560, max: 672
2015-08-13 19:17:09,887 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:17:09,887 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 55, total: 560, max: 672
2015-08-13 19:17:09,887 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:17:09,888 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 55, total: 560, max: 672
2015-08-13 19:17:12,747 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:17:12,747 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:17:12,756 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(min)[by:[{1}:'char']]
2015-08-13 19:17:12,756 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/minby"]
2015-08-13 19:17:15,751 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/minby/_temporary
2015-08-13 19:17:15,771 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/minby
2015-08-13 19:17:15,783 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:17:15,783 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:17:15,801 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum] starting
2015-08-13 19:17:15,801 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:17:15,801 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  sink: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/sum"]
2015-08-13 19:17:15,802 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  parallel execution is enabled: false
2015-08-13 19:17:15,802 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  starting jobs: 1
2015-08-13 19:17:15,802 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  allocating threads: 1
2015-08-13 19:17:15,805 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] starting step: (1/1) ...semblyhelpersplatform/sum
2015-08-13 19:17:15,836 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] submitted hadoop job: job_local_0015
2015-08-13 19:17:15,836 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] tracking url: http://localhost:8080/
2015-08-13 19:17:15,840 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:17:16,176 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:17:16,177 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:17:16,187 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:17:16,187 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(sum)[by:[{1}:'char']]
2015-08-13 19:17:16,189 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:17:16,189 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 132, total: 236, max: 672
2015-08-13 19:17:16,189 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 35% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:16,190 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:17:16,191 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 132, total: 236, max: 672
2015-08-13 19:17:16,191 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 35% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:16,191 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:17:16,192 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 132, total: 236, max: 672
2015-08-13 19:17:16,192 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 35% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:16,192 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:17:16,192 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 132, total: 236, max: 672
2015-08-13 19:17:16,193 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 35% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:18,845 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:17:18,845 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:17:18,855 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(sum)[by:[{1}:'char']]
2015-08-13 19:17:18,855 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/sum"]
2015-08-13 19:17:21,852 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/sum/_temporary
2015-08-13 19:17:21,871 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/sum
2015-08-13 19:17:21,885 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:17:21,886 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:17:21,908 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs] starting
2015-08-13 19:17:21,908 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:17:21,908 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:17:21,908 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  sink: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/mergesum"]
2015-08-13 19:17:21,909 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  parallel execution is enabled: false
2015-08-13 19:17:21,910 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  starting jobs: 1
2015-08-13 19:17:21,910 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  allocating threads: 1
2015-08-13 19:17:21,911 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum-lhs+sum-rhs] starting step: (1/1) ...yhelpersplatform/mergesum
2015-08-13 19:17:21,945 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum-lhs+sum-rhs] submitted hadoop job: job_local_0016
2015-08-13 19:17:21,947 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum-lhs+sum-rhs] tracking url: http://localhost:8080/
2015-08-13 19:17:21,951 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:17:22,087 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:17:22,088 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:17:22,099 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:17:22,099 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-13 19:17:22,101 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:17:22,102 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 116, total: 331, max: 672
2015-08-13 19:17:22,102 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-13 19:17:22,103 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:17:22,103 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 116, total: 331, max: 672
2015-08-13 19:17:22,103 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-13 19:17:22,104 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:17:22,104 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 115, total: 331, max: 672
2015-08-13 19:17:22,104 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-13 19:17:22,105 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:17:22,105 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 115, total: 331, max: 672
2015-08-13 19:17:22,105 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-13 19:17:24,954 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt
2015-08-13 19:17:25,085 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:17:25,086 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:17:25,098 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:17:25,098 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-13 19:17:25,102 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:17:25,102 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 109, total: 426, max: 672
2015-08-13 19:17:25,102 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 63% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:25,103 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:17:25,103 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 109, total: 426, max: 672
2015-08-13 19:17:25,104 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 63% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:25,104 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:17:25,104 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 109, total: 426, max: 672
2015-08-13 19:17:25,105 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 63% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:25,105 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:17:25,105 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 109, total: 426, max: 672
2015-08-13 19:17:25,106 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 63% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:27,962 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:17:27,962 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:17:27,973 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-13 19:17:27,973 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/mergesum"]
2015-08-13 19:17:30,965 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/mergesum/_temporary
2015-08-13 19:17:30,984 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/mergesum
2015-08-13 19:17:30,996 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:17:30,996 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:17:31,009 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-13 19:17:31,010 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2015-08-13 19:17:31,010 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/discardnarrow"]
2015-08-13 19:17:31,010 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-13 19:17:31,011 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-13 19:17:31,011 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-13 19:17:31,011 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...ersplatform/discardnarrow
2015-08-13 19:17:31,043 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local_0017
2015-08-13 19:17:31,044 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-13 19:17:31,048 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt
2015-08-13 19:17:31,051 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:17:31,051 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:17:31,057 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2015-08-13 19:17:31,058 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/discardnarrow"]
2015-08-13 19:17:34,060 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/discardnarrow/_temporary
2015-08-13 19:17:34,070 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/discardnarrow
2015-08-13 19:17:34,086 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:17:34,087 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:17:34,118 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-13 19:17:34,118 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:17:34,118 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:17:34,118 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true163"]
2015-08-13 19:17:34,119 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-13 19:17:34,119 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-13 19:17:34,120 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-13 19:17:34,121 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...atform/multimerge+true163
2015-08-13 19:17:34,151 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local_0018
2015-08-13 19:17:34,152 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-13 19:17:34,155 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:17:34,296 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:17:34,296 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:17:34,312 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:17:34,312 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-13 19:17:34,315 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:17:34,315 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 85, total: 522, max: 672
2015-08-13 19:17:34,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-13 19:17:34,316 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:17:34,316 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 85, total: 522, max: 672
2015-08-13 19:17:34,317 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-13 19:17:34,318 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:17:34,318 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 85, total: 522, max: 672
2015-08-13 19:17:34,318 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-13 19:17:34,319 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:17:34,319 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 85, total: 522, max: 672
2015-08-13 19:17:34,319 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-13 19:17:37,158 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt
2015-08-13 19:17:37,301 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:17:37,301 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:17:37,317 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:17:37,317 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-13 19:17:37,322 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:17:37,322 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 53, total: 591, max: 672
2015-08-13 19:17:37,324 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:17:37,324 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 53, total: 591, max: 672
2015-08-13 19:17:37,325 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:17:37,325 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 53, total: 591, max: 672
2015-08-13 19:17:37,326 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:17:37,326 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 53, total: 591, max: 672
2015-08-13 19:17:40,169 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:17:40,170 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:17:40,184 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by:[{1}:'char']]
2015-08-13 19:17:40,184 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true163"]
2015-08-13 19:17:43,175 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true163/_temporary
2015-08-13 19:17:43,197 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/multimerge+true163
2015-08-13 19:17:43,209 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:17:43,210 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:17:43,223 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-13 19:17:43,224 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2015-08-13 19:17:43,224 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/rename"]
2015-08-13 19:17:43,224 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-13 19:17:43,224 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-13 19:17:43,225 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-13 19:17:43,225 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...blyhelpersplatform/rename
2015-08-13 19:17:43,261 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local_0019
2015-08-13 19:17:43,263 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-13 19:17:43,267 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt
2015-08-13 19:17:43,271 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:17:43,271 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:17:43,278 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2015-08-13 19:17:43,278 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/rename"]
2015-08-13 19:17:46,279 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/rename/_temporary
2015-08-13 19:17:46,290 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/rename
2015-08-13 19:17:46,309 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:17:46,310 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:17:46,339 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-13 19:17:46,339 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:17:46,340 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:17:46,340 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true162"]
2015-08-13 19:17:46,341 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-13 19:17:46,341 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-13 19:17:46,341 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-13 19:17:46,342 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...atform/multimerge+true162
2015-08-13 19:17:46,378 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local_0020
2015-08-13 19:17:46,378 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-13 19:17:46,383 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:17:46,441 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:17:46,442 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:17:46,457 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:17:46,458 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-13 19:17:46,460 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:17:46,461 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 54, total: 639, max: 672
2015-08-13 19:17:46,462 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:17:46,463 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 54, total: 639, max: 672
2015-08-13 19:17:46,464 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:17:46,464 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 54, total: 639, max: 672
2015-08-13 19:17:46,466 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:17:46,466 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 54, total: 639, max: 672
2015-08-13 19:17:49,386 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt
2015-08-13 19:17:49,693 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:17:49,694 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:17:49,705 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:17:49,705 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-13 19:17:49,710 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:17:49,711 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 86, total: 190, max: 672
2015-08-13 19:17:49,711 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-13 19:17:49,712 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:17:49,712 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 86, total: 190, max: 672
2015-08-13 19:17:49,712 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-13 19:17:49,713 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:17:49,714 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 86, total: 190, max: 672
2015-08-13 19:17:49,714 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-13 19:17:49,715 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:17:49,715 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 86, total: 190, max: 672
2015-08-13 19:17:49,715 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-13 19:17:52,396 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:17:52,396 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:17:52,408 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by:[{1}:'char']]
2015-08-13 19:17:52,409 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true162"]
2015-08-13 19:17:55,401 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true162/_temporary
2015-08-13 19:17:55,423 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/multimerge+true162
2015-08-13 19:17:55,443 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:17:55,443 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:17:55,483 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second] starting
2015-08-13 19:17:55,483 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:17:55,484 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  sink: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergecount"]
2015-08-13 19:17:55,484 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  parallel execution is enabled: false
2015-08-13 19:17:55,484 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  starting jobs: 2
2015-08-13 19:17:55,485 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  allocating threads: 1
2015-08-13 19:17:55,485 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] starting step: (1/2)
2015-08-13 19:17:55,519 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] submitted hadoop job: job_local_0021
2015-08-13 19:17:55,520 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] tracking url: http://localhost:8080/
2015-08-13 19:17:55,524 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:17:55,603 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:17:55,603 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:17:55,615 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:17:55,615 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(first)[by:[{1}:'char']]
2015-08-13 19:17:55,620 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:17:55,620 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 67, total: 285, max: 672
2015-08-13 19:17:55,620 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 42% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:55,621 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:17:55,622 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 67, total: 285, max: 672
2015-08-13 19:17:55,622 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 42% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:55,623 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:17:55,623 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 67, total: 285, max: 672
2015-08-13 19:17:55,623 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 42% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:55,624 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:17:55,624 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 67, total: 285, max: 672
2015-08-13 19:17:55,624 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 42% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:17:58,530 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:17:58,531 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:17:58,539 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(first)[by:[{1}:'char']]
2015-08-13 19:17:58,539 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][5449234733/first/]
2015-08-13 19:18:01,537 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] starting step: (2/2) ...form/samesourcemergecount
2015-08-13 19:18:01,572 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] submitted hadoop job: job_local_0022
2015-08-13 19:18:01,574 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] tracking url: http://localhost:8080/
2015-08-13 19:18:01,579 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/5449234733_first_4D95101A55BA4271A173FEBE9E85BD1E/part-00000
2015-08-13 19:18:01,715 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:18:01,716 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:18:01,726 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][5449234733/first/]
2015-08-13 19:18:01,726 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(second)[by:[{1}:'char']]
2015-08-13 19:18:01,728 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:18:01,728 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 57, total: 380, max: 672
2015-08-13 19:18:01,729 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 56% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:01,730 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:18:01,730 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 57, total: 380, max: 672
2015-08-13 19:18:01,730 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 56% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:04,583 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:18:04,584 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:18:04,592 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(second)[by:[{1}:'char']]
2015-08-13 19:18:04,593 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergecount"]
2015-08-13 19:18:07,595 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergecount/_temporary
2015-08-13 19:18:07,613 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/samesourcemergecount
2015-08-13 19:18:07,624 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:18:07,625 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:18:07,636 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average] starting
2015-08-13 19:18:07,637 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:18:07,637 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  sink: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/average"]
2015-08-13 19:18:07,637 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  parallel execution is enabled: false
2015-08-13 19:18:07,637 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  starting jobs: 1
2015-08-13 19:18:07,637 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  allocating threads: 1
2015-08-13 19:18:07,640 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] starting step: (1/1) ...lyhelpersplatform/average
2015-08-13 19:18:07,668 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] submitted hadoop job: job_local_0023
2015-08-13 19:18:07,669 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] tracking url: http://localhost:8080/
2015-08-13 19:18:07,674 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:18:07,697 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:18:07,698 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:18:07,706 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:18:07,706 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(average)[by:[{1}:'char']]
2015-08-13 19:18:07,708 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:18:07,708 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 139, total: 456, max: 672
2015-08-13 19:18:07,708 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-13 19:18:07,709 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:18:07,709 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 139, total: 456, max: 672
2015-08-13 19:18:07,710 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-13 19:18:07,710 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:18:07,711 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 139, total: 456, max: 672
2015-08-13 19:18:07,711 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-13 19:18:07,711 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:18:07,712 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 139, total: 456, max: 672
2015-08-13 19:18:07,712 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-13 19:18:10,678 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:18:10,679 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:18:10,686 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(average)[by:[{1}:'char']]
2015-08-13 19:18:10,686 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/average"]
2015-08-13 19:18:13,686 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/average/_temporary
2015-08-13 19:18:13,704 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/average
2015-08-13 19:18:13,716 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:18:13,716 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:18:13,728 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-13 19:18:13,728 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:18:13,728 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/maxbynullsafety"]
2015-08-13 19:18:13,729 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-13 19:18:13,729 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-13 19:18:13,729 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-13 19:18:13,731 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...splatform/maxbynullsafety
2015-08-13 19:18:13,761 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local_0024
2015-08-13 19:18:13,762 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-13 19:18:13,766 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:18:13,791 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:18:13,792 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:18:13,799 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:18:13,799 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'char']]
2015-08-13 19:18:13,801 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:18:13,801 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 154, total: 457, max: 672
2015-08-13 19:18:13,802 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 68% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:13,803 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:18:13,803 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 154, total: 457, max: 672
2015-08-13 19:18:13,804 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 68% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:13,804 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:18:13,805 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 154, total: 457, max: 672
2015-08-13 19:18:13,805 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 68% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:13,806 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:18:13,806 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 154, total: 457, max: 672
2015-08-13 19:18:13,807 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 68% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:16,771 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:18:16,772 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:18:16,779 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'char']]
2015-08-13 19:18:16,779 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/maxbynullsafety"]
2015-08-13 19:18:19,778 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/maxbynullsafety/_temporary
2015-08-13 19:18:19,796 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/maxbynullsafety
2015-08-13 19:18:19,808 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:18:19,809 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:18:19,822 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum] starting
2015-08-13 19:18:19,822 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:18:19,822 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  sink: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/sumnulls"]
2015-08-13 19:18:19,823 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  parallel execution is enabled: false
2015-08-13 19:18:19,823 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  starting jobs: 1
2015-08-13 19:18:19,824 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  allocating threads: 1
2015-08-13 19:18:19,825 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] starting step: (1/1) ...yhelpersplatform/sumnulls
2015-08-13 19:18:19,854 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] submitted hadoop job: job_local_0025
2015-08-13 19:18:19,856 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] tracking url: http://localhost:8080/
2015-08-13 19:18:19,859 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:18:19,884 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:18:19,884 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:18:19,891 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:18:19,891 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(sum)[by:[{1}:'char']]
2015-08-13 19:18:19,900 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:18:19,900 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 186, total: 490, max: 672
2015-08-13 19:18:19,900 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:19,901 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:18:19,902 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 186, total: 490, max: 672
2015-08-13 19:18:19,902 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:19,903 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:18:19,903 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 186, total: 490, max: 672
2015-08-13 19:18:19,903 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:19,904 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:18:19,904 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 186, total: 490, max: 672
2015-08-13 19:18:19,904 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:22,864 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:18:22,864 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:18:22,870 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(sum)[by:[{1}:'char']]
2015-08-13 19:18:22,871 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/sumnulls"]
2015-08-13 19:18:25,871 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/sumnulls/_temporary
2015-08-13 19:18:25,889 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/sumnulls
2015-08-13 19:18:25,900 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:18:25,901 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:18:25,911 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-13 19:18:25,911 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:18:25,912 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/countall"]
2015-08-13 19:18:25,912 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-13 19:18:25,912 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 1
2015-08-13 19:18:25,912 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-13 19:18:25,913 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/1) ...yhelpersplatform/countall
2015-08-13 19:18:25,941 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local_0026
2015-08-13 19:18:25,941 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-13 19:18:25,945 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:18:26,065 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:18:26,065 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:18:26,073 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:18:26,073 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{?}:NONE]]
2015-08-13 19:18:28,951 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:18:28,951 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:18:28,957 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{?}:NONE]]
2015-08-13 19:18:28,958 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/countall"]
2015-08-13 19:18:31,958 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/countall/_temporary
2015-08-13 19:18:31,976 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/countall
2015-08-13 19:18:31,993 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:18:31,994 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:18:32,011 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-13 19:18:32,012 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:18:32,012 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-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/multi"]
2015-08-13 19:18:32,013 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-13 19:18:32,013 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-13 19:18:32,013 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-13 19:18:32,014 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...mblyhelpersplatform/multi
2015-08-13 19:18:32,048 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local_0027
2015-08-13 19:18:32,049 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-13 19:18:32,053 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:18:32,080 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:18:32,081 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:18:32,089 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:18:32,090 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-13 19:18:32,091 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:18:32,092 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 180, total: 484, max: 672
2015-08-13 19:18:32,092 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:32,093 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:18:32,093 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 180, total: 484, max: 672
2015-08-13 19:18:32,093 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:32,095 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:18:32,095 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 180, total: 484, max: 672
2015-08-13 19:18:32,095 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:32,096 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:18:32,096 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 180, total: 484, max: 672
2015-08-13 19:18:32,096 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:35,059 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:18:35,059 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:18:35,068 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by:[{1}:'char']]
2015-08-13 19:18:35,068 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-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/multi"]
2015-08-13 19:18:38,066 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/multi/_temporary
2015-08-13 19:18:38,084 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/multi
2015-08-13 19:18:38,094 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:18:38,094 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:18:38,104 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-13 19:18:38,104 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2015-08-13 19:18:38,105 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/retainnarrow"]
2015-08-13 19:18:38,105 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-13 19:18:38,105 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-13 19:18:38,106 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-13 19:18:38,107 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...persplatform/retainnarrow
2015-08-13 19:18:38,134 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local_0028
2015-08-13 19:18:38,135 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-13 19:18:38,139 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt
2015-08-13 19:18:38,142 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:18:38,142 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:18:38,146 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2015-08-13 19:18:38,146 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/retainnarrow"]
2015-08-13 19:18:41,151 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/retainnarrow/_temporary
2015-08-13 19:18:41,160 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/retainnarrow
2015-08-13 19:18:41,169 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:18:41,170 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:18:41,178 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-13 19:18:41,178 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2015-08-13 19:18:41,179 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['item']->['char', 'item']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/renamenarrow"]
2015-08-13 19:18:41,179 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-13 19:18:41,179 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-13 19:18:41,179 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-13 19:18:41,180 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...persplatform/renamenarrow
2015-08-13 19:18:41,206 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local_0029
2015-08-13 19:18:41,206 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-13 19:18:41,211 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt
2015-08-13 19:18:41,215 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:18:41,215 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:18:41,220 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2015-08-13 19:18:41,220 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['item']->['char', 'item']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/renamenarrow"]
2015-08-13 19:18:44,221 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/renamenarrow/_temporary
2015-08-13 19:18:44,230 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/renamenarrow
2015-08-13 19:18:44,242 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:18:44,243 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:18:44,253 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average] starting
2015-08-13 19:18:44,254 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:18:44,254 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  sink: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/averagenull"]
2015-08-13 19:18:44,254 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  parallel execution is enabled: false
2015-08-13 19:18:44,254 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  starting jobs: 1
2015-08-13 19:18:44,255 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  allocating threads: 1
2015-08-13 19:18:44,255 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] starting step: (1/1) ...lpersplatform/averagenull
2015-08-13 19:18:44,283 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] submitted hadoop job: job_local_0030
2015-08-13 19:18:44,284 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] tracking url: http://localhost:8080/
2015-08-13 19:18:44,287 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:18:44,317 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:18:44,317 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:18:44,324 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:18:44,324 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(average)[by:[{1}:'char']]
2015-08-13 19:18:44,328 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:18:44,328 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 49, total: 484, max: 672
2015-08-13 19:18:44,329 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:44,330 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:18:44,330 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 49, total: 484, max: 672
2015-08-13 19:18:44,330 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:44,331 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:18:44,331 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 49, total: 484, max: 672
2015-08-13 19:18:44,331 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:44,332 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:18:44,332 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 49, total: 484, max: 672
2015-08-13 19:18:44,332 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:47,292 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:18:47,293 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:18:47,301 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(average)[by:[{1}:'char']]
2015-08-13 19:18:47,301 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/averagenull"]
2015-08-13 19:18:50,300 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/averagenull/_temporary
2015-08-13 19:18:50,321 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/averagenull
2015-08-13 19:18:50,332 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:18:50,333 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:18:50,343 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce] starting
2015-08-13 19:18:50,344 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2015-08-13 19:18:50,344 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  sink: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/coerce"]
2015-08-13 19:18:50,344 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  parallel execution is enabled: false
2015-08-13 19:18:50,344 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  starting jobs: 1
2015-08-13 19:18:50,344 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  allocating threads: 1
2015-08-13 19:18:50,345 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] starting step: (1/1) ...blyhelpersplatform/coerce
2015-08-13 19:18:50,382 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] submitted hadoop job: job_local_0031
2015-08-13 19:18:50,383 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] tracking url: http://localhost:8080/
2015-08-13 19:18:50,386 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt
2015-08-13 19:18:50,389 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:18:50,389 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:18:50,394 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2015-08-13 19:18:50,394 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/coerce"]
2015-08-13 19:18:53,397 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/coerce/_temporary
2015-08-13 19:18:53,406 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/coerce
2015-08-13 19:18:53,417 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:18:53,417 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:18:53,427 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first] starting
2015-08-13 19:18:53,428 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  source: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs+rhs-cross-rev.txt"]
2015-08-13 19:18:53,428 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  sink: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/firstnfieldswithoutcomparator"]
2015-08-13 19:18:53,429 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  parallel execution is enabled: false
2015-08-13 19:18:53,429 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  starting jobs: 1
2015-08-13 19:18:53,429 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  allocating threads: 1
2015-08-13 19:18:53,430 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] starting step: (1/1) ...tnfieldswithoutcomparator
2015-08-13 19:18:53,456 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] submitted hadoop job: job_local_0032
2015-08-13 19:18:53,457 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] tracking url: http://localhost:8080/
2015-08-13 19:18:53,460 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs+rhs-cross-rev.txt
2015-08-13 19:18:53,479 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:18:53,480 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:18:53,486 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs+rhs-cross-rev.txt"]
2015-08-13 19:18:53,487 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(first)[by:[{1}:'num']]
2015-08-13 19:18:53,490 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:18:53,490 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 173, total: 490, max: 672
2015-08-13 19:18:53,490 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:53,492 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:18:53,492 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 173, total: 490, max: 672
2015-08-13 19:18:53,492 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:56,465 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:18:56,465 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:18:56,471 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(first)[by:[{1}:'num']]
2015-08-13 19:18:56,472 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/firstnfieldswithoutcomparator"]
2015-08-13 19:18:59,475 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/firstnfieldswithoutcomparator/_temporary
2015-08-13 19:18:59,484 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/firstnfieldswithoutcomparator
2015-08-13 19:18:59,498 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:18:59,499 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:18:59,516 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-13 19:18:59,516 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:18:59,516 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:18:59,516 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false163"]
2015-08-13 19:18:59,517 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-13 19:18:59,517 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-13 19:18:59,517 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-13 19:18:59,518 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...tform/multimerge+false163
2015-08-13 19:18:59,546 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local_0033
2015-08-13 19:18:59,547 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-13 19:18:59,550 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:18:59,570 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:18:59,570 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:18:59,580 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:18:59,580 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-13 19:18:59,582 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:18:59,582 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 61, total: 490, max: 672
2015-08-13 19:18:59,582 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:59,583 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:18:59,584 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 61, total: 490, max: 672
2015-08-13 19:18:59,584 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:59,585 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:18:59,585 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 61, total: 490, max: 672
2015-08-13 19:18:59,585 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:18:59,586 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:18:59,586 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 61, total: 490, max: 672
2015-08-13 19:18:59,586 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:19:02,553 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt
2015-08-13 19:19:02,578 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:19:02,578 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:19:02,588 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:19:02,588 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-13 19:19:02,592 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:19:02,593 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 185, total: 490, max: 672
2015-08-13 19:19:02,593 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:19:02,594 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:19:02,594 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 185, total: 490, max: 672
2015-08-13 19:19:02,594 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:19:02,595 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:19:02,596 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 185, total: 490, max: 672
2015-08-13 19:19:02,596 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:19:02,597 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:19:02,597 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 185, total: 490, max: 672
2015-08-13 19:19:02,597 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:19:05,561 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:19:05,562 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:19:05,570 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-13 19:19:05,570 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false163"]
2015-08-13 19:19:08,567 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false163/_temporary
2015-08-13 19:19:08,586 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/multimerge+false163
2015-08-13 19:19:08,601 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:19:08,601 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:19:08,650 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...] starting
2015-08-13 19:19:08,650 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:19:08,651 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  sink: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergethreeway"]
2015-08-13 19:19:08,652 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  parallel execution is enabled: false
2015-08-13 19:19:08,652 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  starting jobs: 5
2015-08-13 19:19:08,653 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  allocating threads: 1
2015-08-13 19:19:08,654 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (1/5)
2015-08-13 19:19:08,683 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local_0034
2015-08-13 19:19:08,683 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-13 19:19:08,686 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:19:08,705 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:19:08,705 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:19:08,711 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:19:08,711 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(source)[by:[{1}:'char']]
2015-08-13 19:19:08,713 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:19:08,713 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 68, total: 490, max: 672
2015-08-13 19:19:08,713 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:19:08,714 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:19:08,714 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 68, total: 490, max: 672
2015-08-13 19:19:08,714 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:19:08,715 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 19:19:08,715 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 68, total: 490, max: 672
2015-08-13 19:19:08,715 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:19:08,716 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 19:19:08,716 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 68, total: 490, max: 672
2015-08-13 19:19:08,716 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:19:11,691 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:19:11,691 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:19:11,697 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(source)[by:[{1}:'char']]
2015-08-13 19:19:11,697 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][506615544/source/]
2015-08-13 19:19:14,700 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (3/5)
2015-08-13 19:19:14,727 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local_0035
2015-08-13 19:19:14,728 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-13 19:19:14,731 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/506615544_source_FEDDD5641B3C4B96BD660858C394438C/part-00000
2015-08-13 19:19:14,756 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:19:14,756 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:19:14,762 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][506615544/source/]
2015-08-13 19:19:14,763 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count-lhs)[by:[{1}:'char']]
2015-08-13 19:19:14,764 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:19:14,764 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 185, total: 490, max: 672
2015-08-13 19:19:14,765 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:19:14,766 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:19:14,766 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 185, total: 490, max: 672
2015-08-13 19:19:14,767 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:19:17,736 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:19:17,736 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:19:17,741 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count-lhs)[by:[{1}:'char']]
2015-08-13 19:19:17,742 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][1041398921/count-lhs/]
2015-08-13 19:19:20,744 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (4/5)
2015-08-13 19:19:20,772 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local_0036
2015-08-13 19:19:20,774 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-13 19:19:20,777 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/506615544_source_FEDDD5641B3C4B96BD660858C394438C/part-00000
2015-08-13 19:19:20,796 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:19:20,797 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:19:20,802 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][506615544/source/]
2015-08-13 19:19:20,803 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count-rhs)[by:[{1}:'char']]
2015-08-13 19:19:20,804 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 19:19:20,804 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 79, total: 490, max: 672
2015-08-13 19:19:20,804 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:19:20,805 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 19:19:20,805 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 79, total: 490, max: 672
2015-08-13 19:19:20,805 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 72% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 19:19:23,782 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:19:23,782 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:19:23,787 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count-rhs)[by:[{1}:'char']]
2015-08-13 19:19:23,787 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][4372497276/count-rhs/]
2015-08-13 19:19:26,789 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (2/5)
2015-08-13 19:19:26,818 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local_0037
2015-08-13 19:19:26,819 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-13 19:19:26,823 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/506615544_source_FEDDD5641B3C4B96BD660858C394438C/part-00000
2015-08-13 19:19:26,849 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:19:26,849 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:19:26,856 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][506615544/source/]
2015-08-13 19:19:26,856 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(source*count-rhs)[by: source:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-13 19:19:29,825 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/4372497276_count_rhs_2A3891840CAE45FC90C44234BF08E27E/part-00000
2015-08-13 19:19:29,845 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:19:29,845 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:19:29,851 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][4372497276/count-rhs/]
2015-08-13 19:19:29,852 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(source*count-rhs)[by: source:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-13 19:19:32,833 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:19:32,833 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:19:32,839 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(source*count-rhs)[by: source:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-13 19:19:32,839 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'num', 'char2', 'count']]"][5968960564/source_count-rhs/]
2015-08-13 19:19:32,848 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-13 19:19:32,849 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-13 19:19:35,839 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (5/5) ...m/samesourcemergethreeway
2015-08-13 19:19:35,868 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local_0038
2015-08-13 19:19:35,869 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-13 19:19:35,872 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/5968960564_source_count_rhs_0D9094BD756942718A934054CBAF1FDE/part-00000
2015-08-13 19:19:35,897 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:19:35,898 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:19:35,905 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'num', 'char2', 'count']]"][5968960564/source_count-rhs/]
2015-08-13 19:19:35,905 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-13 19:19:38,875 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/1041398921_count_lhs_2D02A12FD1AC48C18A4BFDBA891B71F0/part-00000
2015-08-13 19:19:38,895 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:19:38,896 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:19:38,903 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][1041398921/count-lhs/]
2015-08-13 19:19:38,903 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-13 19:19:41,884 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:19:41,884 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:19:41,891 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-13 19:19:41,891 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergethreeway"]
2015-08-13 19:19:41,894 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-13 19:19:41,894 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-13 19:19:44,891 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergethreeway/_temporary
2015-08-13 19:19:44,908 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/samesourcemergethreeway
2015-08-13 19:19:44,922 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:19:44,923 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:19:44,938 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs] starting
2015-08-13 19:19:44,938 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:19:44,938 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:19:44,939 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  sink: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/uniquemerge-nondeterministic"]
2015-08-13 19:19:44,939 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  parallel execution is enabled: false
2015-08-13 19:19:44,939 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  starting jobs: 1
2015-08-13 19:19:44,939 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  allocating threads: 1
2015-08-13 19:19:44,940 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [lhs+rhs] starting step: (1/1) ...quemerge-nondeterministic
2015-08-13 19:19:44,968 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [lhs+rhs] submitted hadoop job: job_local_0039
2015-08-13 19:19:44,968 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [lhs+rhs] tracking url: http://localhost:8080/
2015-08-13 19:19:44,971 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:19:44,995 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:19:44,995 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:19:45,000 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:19:45,001 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-08-13 19:19:47,973 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt
2015-08-13 19:19:47,993 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:19:47,993 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:19:47,998 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/rhs.txt"]
2015-08-13 19:19:47,998 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-08-13 19:19:50,981 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:19:50,981 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:19:50,986 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-08-13 19:19:50,987 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/uniquemerge-nondeterministic"]
2015-08-13 19:19:53,985 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/uniquemerge-nondeterministic/_temporary
2015-08-13 19:19:53,995 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/uniquemerge-nondeterministic
2015-08-13 19:19:54,004 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:19:54,005 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:19:54,014 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-13 19:19:54,014 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:19:54,014 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/unique"]
2015-08-13 19:19:54,014 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-13 19:19:54,014 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-13 19:19:54,015 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-13 19:19:54,015 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...blyhelpersplatform/unique
2015-08-13 19:19:54,043 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local_0040
2015-08-13 19:19:54,043 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-13 19:19:54,046 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:19:54,070 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:19:54,070 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:19:54,074 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:19:54,075 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(shape)[by:[{1}:'num']]
2015-08-13 19:19:57,050 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:19:57,051 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:19:57,055 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(shape)[by:[{1}:'num']]
2015-08-13 19:19:57,055 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/unique"]
2015-08-13 19:20:00,061 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/unique/_temporary
2015-08-13 19:20:00,070 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/unique
2015-08-13 19:20:00,082 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 19:20:00,082 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 19:20:00,093 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-13 19:20:00,093 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:20:00,094 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['notnull', 'null']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/countnullnotnull"]
2015-08-13 19:20:00,094 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-13 19:20:00,094 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 1
2015-08-13 19:20:00,094 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-13 19:20:00,095 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/1) ...platform/countnullnotnull
2015-08-13 19:20:00,122 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local_0041
2015-08-13 19:20:00,123 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-13 19:20:00,126 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt
2015-08-13 19:20:00,146 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 19:20:00,146 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 19:20:00,153 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2015-08-13 19:20:00,153 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{?}:NONE]]
2015-08-13 19:20:03,131 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 19:20:03,131 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 19:20:03,138 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{?}:NONE]]
2015-08-13 19:20:03,138 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['notnull', 'null']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/countnullnotnull"]
2015-08-13 19:20:06,142 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output/hadoop/assemblyhelpersplatform/countnullnotnull/_temporary
2015-08-13 19:20:06,159 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-0.20.205.0/build/test/output//hadoop/assemblyhelpersplatform/countnullnotnull