Class cascading.pipe.assembly.AssemblyHelpersPlatformTest

35

tests

0

failures

10.216s

duration

100%

successful

Tests

Test Duration Result
testAverageBy 0.145s passed
testAverageByNull 0.144s passed
testAverageMerge 0.581s passed
testCoerce 0.078s passed
testCoerceFields 0.131s passed
testCount 0.187s passed
testCountAll 0.135s passed
testCountCount 0.798s passed
testCountMerge 0.305s passed
testCountNullNotNull 0.143s passed
testDiscardNarrow 0.102s passed
testFirstBy 0.202s passed
testFirstByWithoutComparator 0.325s passed
testMaxBy 0.187s passed
testMaxByNullSafety 0.147s passed
testMaxByString 0.323s passed
testMinBy 0.167s passed
testMinByNullSafety 0.215s passed
testMinByString 0.453s passed
testParallelAggregates 0.161s passed
testParallelAggregatesMerge 2.369s passed
testParallelAggregatesMergeLegacyHash 0.207s passed
testParallelAggregatesPriorMerge 0.241s passed
testParallelAggregatesPriorMergeLegacyHash 0.242s passed
testRenameAll 0.170s passed
testRenameNamed 0.088s passed
testRenameNarrow 0.082s passed
testRetainNarrow 0.080s passed
testSameSourceMerge 0.281s passed
testSameSourceMergeThreeWay 0.664s passed
testSumBy 0.173s passed
testSumByNulls 0.157s passed
testSumMerge 0.237s passed
testUnique 0.123s passed
testUniqueMerge 0.173s passed

Standard output

2015-08-14 00:35:43,824 INFO  platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2015-08-14 00:35:43,872 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop
2015-08-14 00:35:43,872 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.pipe.assembly.AssemblyHelpersPlatformTest
2015-08-14 00:35:43,918 INFO  hadoop.HadoopPlatform (HadoopPlatform.java:setUp(112)) - not using cluster
2015-08-14 00:35:44,249 INFO  platform.TestPlatform (TestPlatform.java:getGlobalProperties(72)) - platform property overrides: 
2015-08-14 00:35:44,686 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:44,689 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-14 00:35:44,703 INFO  property.AppProps (AppProps.java:getAppID(169)) - using app.id: 8A9380BE43D5462B89AC457CBD4F85C4
2015-08-14 00:35:45,006 INFO  util.Version (Version.java:printBanner(85)) - Concurrent, Inc - Cascading 2.7.1
2015-08-14 00:35:45,008 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-14 00:35:45,010 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:45,011 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:45,012 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false187"]
2015-08-14 00:35:45,012 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-14 00:35:45,012 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-14 00:35:45,012 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-14 00:35:45,016 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...tform/multimerge+false187
2015-08-14 00:35:45,069 WARN  util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2015-08-14 00:35:45,139 WARN  snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2015-08-14 00:35:45,377 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local1340475188_0001
2015-08-14 00:35:45,379 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-14 00:35:45,489 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:45,683 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:45,683 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:45,754 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:45,755 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-14 00:35:45,777 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:45,777 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 79, total: 197, max: 672
2015-08-14 00:35:45,777 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 29% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:45,779 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:45,779 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 79, total: 197, max: 672
2015-08-14 00:35:45,780 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 29% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:45,781 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:45,781 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 79, total: 197, max: 672
2015-08-14 00:35:45,781 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 29% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:45,782 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:45,782 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 79, total: 197, max: 672
2015-08-14 00:35:45,783 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 29% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:45,808 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt
2015-08-14 00:35:45,949 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:45,950 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:45,976 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:45,976 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-14 00:35:46,100 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:46,101 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 91, total: 292, max: 672
2015-08-14 00:35:46,101 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-14 00:35:46,103 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:46,103 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 91, total: 292, max: 672
2015-08-14 00:35:46,103 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-14 00:35:46,105 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:46,105 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 91, total: 292, max: 672
2015-08-14 00:35:46,105 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-14 00:35:46,106 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:46,107 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 91, total: 292, max: 672
2015-08-14 00:35:46,107 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-14 00:35:46,152 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:46,153 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:46,180 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-14 00:35:46,181 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false187"]
2015-08-14 00:35:46,232 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false187/_temporary
2015-08-14 00:35:46,283 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/multimerge+false187
2015-08-14 00:35:46,316 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:46,317 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-14 00:35:46,351 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-14 00:35:46,352 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:46,352 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['num', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/minbystring"]
2015-08-14 00:35:46,353 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-14 00:35:46,353 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-14 00:35:46,354 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-14 00:35:46,355 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...lpersplatform/minbystring
2015-08-14 00:35:46,469 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local1437421355_0002
2015-08-14 00:35:46,470 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-14 00:35:46,477 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:46,619 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:46,620 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:46,633 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:46,633 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'num']]
2015-08-14 00:35:46,636 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:46,636 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 73, total: 387, max: 672
2015-08-14 00:35:46,636 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-14 00:35:46,637 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:46,637 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 73, total: 387, max: 672
2015-08-14 00:35:46,638 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-14 00:35:46,654 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:46,654 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:46,667 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'num']]
2015-08-14 00:35:46,668 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/minbystring"]
2015-08-14 00:35:46,694 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/minbystring/_temporary
2015-08-14 00:35:46,740 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/minbystring
2015-08-14 00:35:46,771 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:46,771 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-14 00:35:46,822 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs] starting
2015-08-14 00:35:46,822 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:46,822 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:46,823 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  sink: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/mergeaverage"]
2015-08-14 00:35:46,823 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  parallel execution is enabled: false
2015-08-14 00:35:46,824 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  starting jobs: 1
2015-08-14 00:35:46,824 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  allocating threads: 1
2015-08-14 00:35:46,826 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average-lhs+average-rhs] starting step: (1/1) ...persplatform/mergeaverage
2015-08-14 00:35:46,891 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average-lhs+average-rhs] submitted hadoop job: job_local1361630562_0003
2015-08-14 00:35:46,891 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average-lhs+average-rhs] tracking url: http://localhost:8080/
2015-08-14 00:35:46,898 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:47,035 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:47,035 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:47,051 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:47,051 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(average-lhs+average-rhs)[by: average-lhs:[{1}:'char'] average-rhs:[{1}:'char']]
2015-08-14 00:35:47,053 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:47,053 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 108, total: 509, max: 672
2015-08-14 00:35:47,054 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 75% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:47,055 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:47,055 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 108, total: 509, max: 672
2015-08-14 00:35:47,055 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 75% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:47,056 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:47,056 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 108, total: 509, max: 672
2015-08-14 00:35:47,056 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 75% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:47,057 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:47,057 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 108, total: 509, max: 672
2015-08-14 00:35:47,058 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 75% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:47,070 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt
2015-08-14 00:35:47,207 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:47,207 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:47,222 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:47,223 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(average-lhs+average-rhs)[by: average-lhs:[{1}:'char'] average-rhs:[{1}:'char']]
2015-08-14 00:35:47,227 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:47,227 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 59, total: 561, max: 672
2015-08-14 00:35:47,229 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:47,229 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 59, total: 561, max: 672
2015-08-14 00:35:47,230 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:47,230 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 59, total: 561, max: 672
2015-08-14 00:35:47,231 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:47,231 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 59, total: 561, max: 672
2015-08-14 00:35:47,252 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:47,252 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:47,265 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(average-lhs+average-rhs)[by: average-lhs:[{1}:'char'] average-rhs:[{1}:'char']]
2015-08-14 00:35:47,266 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/mergeaverage"]
2015-08-14 00:35:47,293 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/mergeaverage/_temporary
2015-08-14 00:35:47,322 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/mergeaverage
2015-08-14 00:35:47,340 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:47,340 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-14 00:35:47,364 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-14 00:35:47,365 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt"]
2015-08-14 00:35:47,365 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/renameall"]
2015-08-14 00:35:47,366 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-14 00:35:47,366 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-14 00:35:47,366 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-14 00:35:47,367 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...helpersplatform/renameall
2015-08-14 00:35:47,430 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local777122761_0004
2015-08-14 00:35:47,431 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-14 00:35:47,437 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt
2015-08-14 00:35:47,444 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:47,444 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:47,454 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt"]
2015-08-14 00:35:47,454 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/renameall"]
2015-08-14 00:35:47,477 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/renameall/_temporary
2015-08-14 00:35:47,492 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/renameall
2015-08-14 00:35:47,512 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:47,513 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-14 00:35:47,569 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-14 00:35:47,569 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:47,570 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['count', 'count2']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/countcount"]
2015-08-14 00:35:47,570 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-14 00:35:47,570 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 2
2015-08-14 00:35:47,570 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-14 00:35:47,571 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/2)
2015-08-14 00:35:47,635 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local1588620175_0005
2015-08-14 00:35:47,635 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-14 00:35:47,642 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:48,015 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:48,015 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:48,027 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:48,028 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{1}:'char']]
2015-08-14 00:35:48,029 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:48,030 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 61, total: 165, max: 672
2015-08-14 00:35:48,030 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 24% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:48,031 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:48,031 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 61, total: 165, max: 672
2015-08-14 00:35:48,031 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 24% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:48,032 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:48,032 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 61, total: 165, max: 672
2015-08-14 00:35:48,032 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 24% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:48,033 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:48,033 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 61, total: 165, max: 672
2015-08-14 00:35:48,033 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 24% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:48,050 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:48,050 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:48,062 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{1}:'char']]
2015-08-14 00:35:48,062 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['count', 'count2']]"][3768733829/count/]
2015-08-14 00:35:48,076 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:48,076 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 59, total: 165, max: 672
2015-08-14 00:35:48,077 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 24% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:48,101 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (2/2) ...elpersplatform/countcount
2015-08-14 00:35:48,170 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local52989871_0006
2015-08-14 00:35:48,172 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-14 00:35:48,180 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/3768733829_count_88B9A616DCBC4C899D6ECA1E9760E7F1/part-00000
2015-08-14 00:35:48,206 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:48,207 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:48,218 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['count', 'count2']]"][3768733829/count/]
2015-08-14 00:35:48,218 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{1}:'count']]
2015-08-14 00:35:48,233 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:48,234 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:48,245 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{1}:'count']]
2015-08-14 00:35:48,246 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['count', 'count2']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/countcount"]
2015-08-14 00:35:48,267 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/countcount/_temporary
2015-08-14 00:35:48,290 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/countcount
2015-08-14 00:35:48,320 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:48,321 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-14 00:35:48,353 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs] starting
2015-08-14 00:35:48,354 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:48,354 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:48,354 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  sink: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/mergecount"]
2015-08-14 00:35:48,355 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  parallel execution is enabled: false
2015-08-14 00:35:48,355 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  starting jobs: 1
2015-08-14 00:35:48,355 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  allocating threads: 1
2015-08-14 00:35:48,356 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs+count-rhs] starting step: (1/1) ...elpersplatform/mergecount
2015-08-14 00:35:48,404 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs+count-rhs] submitted hadoop job: job_local1818120030_0007
2015-08-14 00:35:48,405 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs+count-rhs] tracking url: http://localhost:8080/
2015-08-14 00:35:48,411 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:48,431 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:48,432 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:48,445 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:48,445 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count-lhs+count-rhs)[by: count-lhs:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-14 00:35:48,447 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:48,447 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 140, total: 262, max: 672
2015-08-14 00:35:48,447 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 38% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:48,448 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:48,448 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 140, total: 262, max: 672
2015-08-14 00:35:48,449 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 38% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:48,449 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:48,449 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 140, total: 262, max: 672
2015-08-14 00:35:48,450 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 38% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:48,450 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:48,450 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 140, total: 262, max: 672
2015-08-14 00:35:48,451 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 38% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:48,461 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt
2015-08-14 00:35:48,490 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:48,490 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:48,504 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:48,504 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count-lhs+count-rhs)[by: count-lhs:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-14 00:35:48,508 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:48,508 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 153, total: 263, max: 672
2015-08-14 00:35:48,509 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 39% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:48,510 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:48,510 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 153, total: 263, max: 672
2015-08-14 00:35:48,510 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 39% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:48,511 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:48,511 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 153, total: 263, max: 672
2015-08-14 00:35:48,511 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 39% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:48,512 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:48,512 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 153, total: 263, max: 672
2015-08-14 00:35:48,512 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 39% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:48,530 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:48,530 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:48,543 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count-lhs+count-rhs)[by: count-lhs:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-14 00:35:48,543 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/mergecount"]
2015-08-14 00:35:48,570 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/mergecount/_temporary
2015-08-14 00:35:48,596 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/mergecount
2015-08-14 00:35:48,612 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:48,613 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-14 00:35:48,637 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min] starting
2015-08-14 00:35:48,638 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:48,638 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  sink: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/minbynullsafety"]
2015-08-14 00:35:48,638 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  parallel execution is enabled: false
2015-08-14 00:35:48,639 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  starting jobs: 1
2015-08-14 00:35:48,639 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  allocating threads: 1
2015-08-14 00:35:48,639 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] starting step: (1/1) ...splatform/minbynullsafety
2015-08-14 00:35:48,687 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] submitted hadoop job: job_local65338434_0008
2015-08-14 00:35:48,688 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] tracking url: http://localhost:8080/
2015-08-14 00:35:48,694 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:48,718 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:48,719 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:48,731 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:48,731 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(min)[by:[{1}:'char']]
2015-08-14 00:35:48,733 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:48,733 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 185, total: 295, max: 672
2015-08-14 00:35:48,734 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-14 00:35:48,735 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:48,735 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 185, total: 295, max: 672
2015-08-14 00:35:48,735 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-14 00:35:48,736 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:48,736 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 185, total: 295, max: 672
2015-08-14 00:35:48,736 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-14 00:35:48,737 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:48,737 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 185, total: 295, max: 672
2015-08-14 00:35:48,738 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-14 00:35:48,752 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:48,753 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:48,762 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(min)[by:[{1}:'char']]
2015-08-14 00:35:48,762 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/minbynullsafety"]
2015-08-14 00:35:48,788 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/minbynullsafety/_temporary
2015-08-14 00:35:48,811 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/minbynullsafety
2015-08-14 00:35:48,827 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:48,828 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-14 00:35:48,851 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-14 00:35:48,852 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:48,852 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['num', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/maxbystring"]
2015-08-14 00:35:48,852 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-14 00:35:48,853 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-14 00:35:48,853 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-14 00:35:48,854 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...lpersplatform/maxbystring
2015-08-14 00:35:48,893 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local410071894_0009
2015-08-14 00:35:48,894 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-14 00:35:48,900 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:49,041 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:49,042 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:49,052 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:49,053 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'num']]
2015-08-14 00:35:49,055 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:49,056 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 68, total: 295, max: 672
2015-08-14 00:35:49,056 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-14 00:35:49,058 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:49,058 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 68, total: 295, max: 672
2015-08-14 00:35:49,059 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-14 00:35:49,073 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:49,073 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:49,083 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'num']]
2015-08-14 00:35:49,085 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/maxbystring"]
2015-08-14 00:35:49,108 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/maxbystring/_temporary
2015-08-14 00:35:49,135 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/maxbystring
2015-08-14 00:35:49,154 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:49,155 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-14 00:35:49,184 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first] starting
2015-08-14 00:35:49,185 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  source: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs+rhs-cross.txt"]
2015-08-14 00:35:49,185 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  sink: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/firstnfields"]
2015-08-14 00:35:49,186 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  parallel execution is enabled: false
2015-08-14 00:35:49,186 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  starting jobs: 1
2015-08-14 00:35:49,186 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  allocating threads: 1
2015-08-14 00:35:49,188 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] starting step: (1/1) ...persplatform/firstnfields
2015-08-14 00:35:49,237 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] submitted hadoop job: job_local635605823_0010
2015-08-14 00:35:49,237 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] tracking url: http://localhost:8080/
2015-08-14 00:35:49,243 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs+rhs-cross.txt
2015-08-14 00:35:49,268 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:49,268 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:49,277 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs+rhs-cross.txt"]
2015-08-14 00:35:49,277 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(first)[by:[{1}:'num']]
2015-08-14 00:35:49,281 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:49,281 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 178, total: 288, max: 672
2015-08-14 00:35:49,281 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-14 00:35:49,283 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:49,283 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 178, total: 288, max: 672
2015-08-14 00:35:49,283 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-14 00:35:49,297 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:49,297 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:49,305 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(first)[by:[{1}:'num']]
2015-08-14 00:35:49,305 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/firstnfields"]
2015-08-14 00:35:49,326 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/firstnfields/_temporary
2015-08-14 00:35:49,337 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/firstnfields
2015-08-14 00:35:49,355 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:49,355 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-14 00:35:49,376 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce] starting
2015-08-14 00:35:49,376 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt"]
2015-08-14 00:35:49,377 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  sink: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/coercefields"]
2015-08-14 00:35:49,377 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  parallel execution is enabled: false
2015-08-14 00:35:49,377 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  starting jobs: 1
2015-08-14 00:35:49,377 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  allocating threads: 1
2015-08-14 00:35:49,378 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] starting step: (1/1) ...persplatform/coercefields
2015-08-14 00:35:49,414 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] submitted hadoop job: job_local32913725_0011
2015-08-14 00:35:49,416 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] tracking url: http://localhost:8080/
2015-08-14 00:35:49,421 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt
2015-08-14 00:35:49,426 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:49,426 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:49,434 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt"]
2015-08-14 00:35:49,435 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/coercefields"]
2015-08-14 00:35:49,458 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/coercefields/_temporary
2015-08-14 00:35:49,469 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/coercefields
2015-08-14 00:35:49,483 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:49,483 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-14 00:35:49,501 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-14 00:35:49,502 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:49,502 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/count"]
2015-08-14 00:35:49,502 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-14 00:35:49,502 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 1
2015-08-14 00:35:49,502 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-14 00:35:49,503 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/1) ...mblyhelpersplatform/count
2015-08-14 00:35:49,539 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local1384644424_0012
2015-08-14 00:35:49,540 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-14 00:35:49,545 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:49,569 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:49,569 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:49,580 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:49,580 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{1}:'char']]
2015-08-14 00:35:49,581 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:49,582 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 51, total: 288, max: 672
2015-08-14 00:35:49,582 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-14 00:35:49,583 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:49,583 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 51, total: 288, max: 672
2015-08-14 00:35:49,583 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-14 00:35:49,584 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:49,584 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 51, total: 288, max: 672
2015-08-14 00:35:49,584 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-14 00:35:49,585 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:49,585 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 51, total: 288, max: 672
2015-08-14 00:35:49,585 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-14 00:35:49,598 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:49,599 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:49,607 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{1}:'char']]
2015-08-14 00:35:49,607 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/count"]
2015-08-14 00:35:49,634 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/count/_temporary
2015-08-14 00:35:49,657 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/count
2015-08-14 00:35:49,673 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:49,674 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-14 00:35:49,693 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-14 00:35:49,693 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:49,694 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/maxby"]
2015-08-14 00:35:49,694 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-14 00:35:49,695 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-14 00:35:49,696 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-14 00:35:49,697 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...mblyhelpersplatform/maxby
2015-08-14 00:35:49,740 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local482546748_0013
2015-08-14 00:35:49,740 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-14 00:35:49,746 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:49,766 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:49,766 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:49,775 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:49,775 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'char']]
2015-08-14 00:35:49,776 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:49,776 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 180, total: 295, max: 672
2015-08-14 00:35:49,777 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-14 00:35:49,778 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:49,778 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 180, total: 295, max: 672
2015-08-14 00:35:49,778 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-14 00:35:49,779 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:49,779 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 180, total: 295, max: 672
2015-08-14 00:35:49,779 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-14 00:35:49,780 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:49,780 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 180, total: 295, max: 672
2015-08-14 00:35:49,780 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-14 00:35:49,792 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:49,792 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:49,799 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'char']]
2015-08-14 00:35:49,799 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/maxby"]
2015-08-14 00:35:49,824 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/maxby/_temporary
2015-08-14 00:35:49,844 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/maxby
2015-08-14 00:35:49,856 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:49,857 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-14 00:35:49,873 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min] starting
2015-08-14 00:35:49,873 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:49,873 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  sink: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/minby"]
2015-08-14 00:35:49,873 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  parallel execution is enabled: false
2015-08-14 00:35:49,874 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  starting jobs: 1
2015-08-14 00:35:49,874 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  allocating threads: 1
2015-08-14 00:35:49,875 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] starting step: (1/1) ...mblyhelpersplatform/minby
2015-08-14 00:35:49,908 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] submitted hadoop job: job_local1826195131_0014
2015-08-14 00:35:49,909 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] tracking url: http://localhost:8080/
2015-08-14 00:35:49,913 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:49,933 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:49,933 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:49,942 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:49,942 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(min)[by:[{1}:'char']]
2015-08-14 00:35:49,944 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:49,944 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 65, total: 295, max: 672
2015-08-14 00:35:49,944 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-14 00:35:49,945 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:49,945 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 65, total: 295, max: 672
2015-08-14 00:35:49,945 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-14 00:35:49,946 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:49,946 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 65, total: 295, max: 672
2015-08-14 00:35:49,946 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-14 00:35:49,947 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:49,947 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 65, total: 295, max: 672
2015-08-14 00:35:49,947 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-14 00:35:49,960 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:49,960 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:49,967 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(min)[by:[{1}:'char']]
2015-08-14 00:35:49,968 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/minby"]
2015-08-14 00:35:49,992 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/minby/_temporary
2015-08-14 00:35:50,012 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/minby
2015-08-14 00:35:50,024 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:50,024 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-14 00:35:50,041 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum] starting
2015-08-14 00:35:50,042 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:50,042 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  sink: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/sum"]
2015-08-14 00:35:50,042 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  parallel execution is enabled: false
2015-08-14 00:35:50,042 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  starting jobs: 1
2015-08-14 00:35:50,042 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  allocating threads: 1
2015-08-14 00:35:50,043 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] starting step: (1/1) ...semblyhelpersplatform/sum
2015-08-14 00:35:50,075 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] submitted hadoop job: job_local531560092_0015
2015-08-14 00:35:50,076 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] tracking url: http://localhost:8080/
2015-08-14 00:35:50,081 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:50,105 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:50,106 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:50,115 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:50,116 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(sum)[by:[{1}:'char']]
2015-08-14 00:35:50,118 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:50,118 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 177, total: 287, max: 672
2015-08-14 00:35:50,118 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-14 00:35:50,119 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:50,119 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 177, total: 287, max: 672
2015-08-14 00:35:50,119 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-14 00:35:50,120 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:50,120 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 177, total: 287, max: 672
2015-08-14 00:35:50,120 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-14 00:35:50,121 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:50,121 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 177, total: 287, max: 672
2015-08-14 00:35:50,122 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-14 00:35:50,134 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:50,134 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:50,142 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(sum)[by:[{1}:'char']]
2015-08-14 00:35:50,142 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/sum"]
2015-08-14 00:35:50,165 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/sum/_temporary
2015-08-14 00:35:50,185 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/sum
2015-08-14 00:35:50,199 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:50,200 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-14 00:35:50,221 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs] starting
2015-08-14 00:35:50,221 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:50,222 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:50,222 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  sink: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/mergesum"]
2015-08-14 00:35:50,222 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  parallel execution is enabled: false
2015-08-14 00:35:50,222 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  starting jobs: 1
2015-08-14 00:35:50,222 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  allocating threads: 1
2015-08-14 00:35:50,223 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum-lhs+sum-rhs] starting step: (1/1) ...yhelpersplatform/mergesum
2015-08-14 00:35:50,257 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum-lhs+sum-rhs] submitted hadoop job: job_local1439820436_0016
2015-08-14 00:35:50,258 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum-lhs+sum-rhs] tracking url: http://localhost:8080/
2015-08-14 00:35:50,262 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:50,284 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:50,285 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:50,295 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:50,296 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(sum-lhs+sum-rhs)[by: sum-lhs:[{1}:'char'] sum-rhs:[{1}:'char']]
2015-08-14 00:35:50,298 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:50,298 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 61, total: 287, max: 672
2015-08-14 00:35:50,299 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-14 00:35:50,300 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:50,300 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 61, total: 287, max: 672
2015-08-14 00:35:50,301 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-14 00:35:50,302 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:50,302 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 61, total: 287, max: 672
2015-08-14 00:35:50,303 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-14 00:35:50,304 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:50,304 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 61, total: 287, max: 672
2015-08-14 00:35:50,305 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-14 00:35:50,313 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt
2015-08-14 00:35:50,335 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:50,336 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:50,346 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:50,346 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(sum-lhs+sum-rhs)[by: sum-lhs:[{1}:'char'] sum-rhs:[{1}:'char']]
2015-08-14 00:35:50,350 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:50,351 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 183, total: 295, max: 672
2015-08-14 00:35:50,351 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-14 00:35:50,353 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:50,353 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 183, total: 295, max: 672
2015-08-14 00:35:50,354 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-14 00:35:50,355 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:50,355 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 183, total: 295, max: 672
2015-08-14 00:35:50,356 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-14 00:35:50,357 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:50,357 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 183, total: 295, max: 672
2015-08-14 00:35:50,358 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-14 00:35:50,373 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:50,373 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:50,382 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(sum-lhs+sum-rhs)[by: sum-lhs:[{1}:'char'] sum-rhs:[{1}:'char']]
2015-08-14 00:35:50,382 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/mergesum"]
2015-08-14 00:35:50,402 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/mergesum/_temporary
2015-08-14 00:35:50,423 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/mergesum
2015-08-14 00:35:50,434 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:50,435 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-14 00:35:50,448 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-14 00:35:50,448 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt"]
2015-08-14 00:35:50,449 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/discardnarrow"]
2015-08-14 00:35:50,449 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-14 00:35:50,449 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-14 00:35:50,449 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-14 00:35:50,450 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...ersplatform/discardnarrow
2015-08-14 00:35:50,483 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local979701169_0017
2015-08-14 00:35:50,484 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-14 00:35:50,488 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt
2015-08-14 00:35:50,492 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:50,492 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:50,497 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt"]
2015-08-14 00:35:50,497 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/discardnarrow"]
2015-08-14 00:35:50,515 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/discardnarrow/_temporary
2015-08-14 00:35:50,526 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/discardnarrow
2015-08-14 00:35:50,541 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:50,542 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-14 00:35:50,568 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-14 00:35:50,569 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:50,569 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:50,569 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true188"]
2015-08-14 00:35:50,569 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-14 00:35:50,569 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-14 00:35:50,569 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-14 00:35:50,570 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...atform/multimerge+true188
2015-08-14 00:35:50,603 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local1064160815_0018
2015-08-14 00:35:50,603 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-14 00:35:50,609 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:50,629 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:50,629 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:50,641 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:50,641 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-14 00:35:50,643 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:50,644 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 55, total: 295, max: 672
2015-08-14 00:35:50,644 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-14 00:35:50,645 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:50,645 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 55, total: 295, max: 672
2015-08-14 00:35:50,645 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-14 00:35:50,646 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:50,646 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 55, total: 295, max: 672
2015-08-14 00:35:50,646 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-14 00:35:50,647 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:50,647 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 55, total: 295, max: 672
2015-08-14 00:35:50,647 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-14 00:35:50,656 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt
2015-08-14 00:35:50,678 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:50,679 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:50,690 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:50,690 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-14 00:35:50,695 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:50,695 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 175, total: 287, max: 672
2015-08-14 00:35:50,695 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-14 00:35:50,697 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:50,697 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 175, total: 287, max: 672
2015-08-14 00:35:50,697 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-14 00:35:50,698 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:50,698 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 175, total: 287, max: 672
2015-08-14 00:35:50,698 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-14 00:35:50,699 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:50,699 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 175, total: 287, max: 672
2015-08-14 00:35:50,699 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-14 00:35:50,716 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:50,716 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:50,727 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by:[{1}:'char']]
2015-08-14 00:35:50,727 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true188"]
2015-08-14 00:35:50,748 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true188/_temporary
2015-08-14 00:35:50,768 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/multimerge+true188
2015-08-14 00:35:50,778 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:50,779 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-14 00:35:50,789 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-14 00:35:50,790 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt"]
2015-08-14 00:35:50,790 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/rename"]
2015-08-14 00:35:50,790 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-14 00:35:50,790 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-14 00:35:50,790 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-14 00:35:50,791 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...blyhelpersplatform/rename
2015-08-14 00:35:50,824 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local1717765903_0019
2015-08-14 00:35:50,824 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-14 00:35:50,829 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt
2015-08-14 00:35:50,832 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:50,832 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:50,837 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt"]
2015-08-14 00:35:50,837 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/rename"]
2015-08-14 00:35:50,847 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/rename/_temporary
2015-08-14 00:35:50,857 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/rename
2015-08-14 00:35:50,871 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:50,872 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-14 00:35:50,895 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-14 00:35:50,895 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:50,895 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:50,896 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true187"]
2015-08-14 00:35:50,896 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-14 00:35:50,896 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-14 00:35:50,896 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-14 00:35:50,897 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...atform/multimerge+true187
2015-08-14 00:35:50,931 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local1303483888_0020
2015-08-14 00:35:50,932 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-14 00:35:50,938 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:50,958 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:50,958 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:50,969 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:50,969 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-14 00:35:50,971 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:50,972 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 48, total: 287, max: 672
2015-08-14 00:35:50,972 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-14 00:35:50,973 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:50,973 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 48, total: 287, max: 672
2015-08-14 00:35:50,973 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-14 00:35:50,974 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:50,974 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 48, total: 287, max: 672
2015-08-14 00:35:50,975 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-14 00:35:50,975 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:50,975 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 48, total: 287, max: 672
2015-08-14 00:35:50,976 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-14 00:35:50,984 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt
2015-08-14 00:35:51,006 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:51,007 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:51,018 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:51,018 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-14 00:35:51,022 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:51,023 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 183, total: 295, max: 672
2015-08-14 00:35:51,023 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-14 00:35:51,024 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:51,024 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 183, total: 295, max: 672
2015-08-14 00:35:51,025 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-14 00:35:51,025 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:51,026 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 183, total: 295, max: 672
2015-08-14 00:35:51,026 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-14 00:35:51,027 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:51,027 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 183, total: 295, max: 672
2015-08-14 00:35:51,027 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-14 00:35:51,043 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:51,043 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:51,053 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by:[{1}:'char']]
2015-08-14 00:35:51,053 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true187"]
2015-08-14 00:35:51,078 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true187/_temporary
2015-08-14 00:35:51,098 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/multimerge+true187
2015-08-14 00:35:51,113 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:51,114 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-14 00:35:51,147 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second] starting
2015-08-14 00:35:51,147 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:51,147 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  sink: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergecount"]
2015-08-14 00:35:51,148 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  parallel execution is enabled: false
2015-08-14 00:35:51,148 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  starting jobs: 2
2015-08-14 00:35:51,148 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  allocating threads: 1
2015-08-14 00:35:51,150 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] starting step: (1/2)
2015-08-14 00:35:51,180 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] submitted hadoop job: job_local312993457_0021
2015-08-14 00:35:51,180 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] tracking url: http://localhost:8080/
2015-08-14 00:35:51,184 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:51,205 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:51,205 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:51,214 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:51,214 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(first)[by:[{1}:'char']]
2015-08-14 00:35:51,218 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:51,218 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:51,219 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-14 00:35:51,220 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:51,220 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:51,220 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-14 00:35:51,221 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:51,221 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:51,221 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-14 00:35:51,222 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:51,222 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:51,222 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-14 00:35:51,233 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:51,234 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:51,241 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(first)[by:[{1}:'char']]
2015-08-14 00:35:51,241 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][8049896238/first/]
2015-08-14 00:35:51,253 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] starting step: (2/2) ...form/samesourcemergecount
2015-08-14 00:35:51,283 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] submitted hadoop job: job_local772579090_0022
2015-08-14 00:35:51,283 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] tracking url: http://localhost:8080/
2015-08-14 00:35:51,288 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/8049896238_first_1A8247DD0F5149C792EA97249F743DC2/part-00000
2015-08-14 00:35:51,309 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:51,310 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:51,319 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][8049896238/first/]
2015-08-14 00:35:51,319 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(second)[by:[{1}:'char']]
2015-08-14 00:35:51,320 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:51,320 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 180, total: 295, max: 672
2015-08-14 00:35:51,321 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-14 00:35:51,321 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:51,321 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 180, total: 295, max: 672
2015-08-14 00:35:51,322 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-14 00:35:51,332 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:51,332 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:51,340 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(second)[by:[{1}:'char']]
2015-08-14 00:35:51,341 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergecount"]
2015-08-14 00:35:51,360 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergecount/_temporary
2015-08-14 00:35:51,379 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/samesourcemergecount
2015-08-14 00:35:51,390 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:51,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-14 00:35:51,402 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average] starting
2015-08-14 00:35:51,402 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:51,402 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  sink: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/average"]
2015-08-14 00:35:51,402 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  parallel execution is enabled: false
2015-08-14 00:35:51,403 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  starting jobs: 1
2015-08-14 00:35:51,403 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  allocating threads: 1
2015-08-14 00:35:51,403 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] starting step: (1/1) ...lyhelpersplatform/average
2015-08-14 00:35:51,433 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] submitted hadoop job: job_local175552193_0023
2015-08-14 00:35:51,433 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] tracking url: http://localhost:8080/
2015-08-14 00:35:51,438 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:51,457 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:51,457 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:51,464 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:51,464 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(average)[by:[{1}:'char']]
2015-08-14 00:35:51,466 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:51,466 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:51,466 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-14 00:35:51,467 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:51,467 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:51,467 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-14 00:35:51,468 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:51,468 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:51,468 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-14 00:35:51,469 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:51,469 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:51,469 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-14 00:35:51,481 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:51,481 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:51,487 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(average)[by:[{1}:'char']]
2015-08-14 00:35:51,487 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/average"]
2015-08-14 00:35:51,506 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/average/_temporary
2015-08-14 00:35:51,525 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/average
2015-08-14 00:35:51,536 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:51,536 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-14 00:35:51,547 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-14 00:35:51,548 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:51,548 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/maxbynullsafety"]
2015-08-14 00:35:51,548 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-14 00:35:51,548 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-14 00:35:51,549 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-14 00:35:51,550 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...splatform/maxbynullsafety
2015-08-14 00:35:51,580 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local285288014_0024
2015-08-14 00:35:51,580 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-14 00:35:51,585 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:51,607 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:51,607 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:51,614 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:51,615 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'char']]
2015-08-14 00:35:51,616 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:51,616 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 181, total: 295, max: 672
2015-08-14 00:35:51,616 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-14 00:35:51,617 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:51,618 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 181, total: 295, max: 672
2015-08-14 00:35:51,618 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-14 00:35:51,619 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:51,619 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 180, total: 295, max: 672
2015-08-14 00:35:51,619 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-14 00:35:51,619 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:51,620 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 180, total: 295, max: 672
2015-08-14 00:35:51,620 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-14 00:35:51,630 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:51,630 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:51,637 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'char']]
2015-08-14 00:35:51,637 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/maxbynullsafety"]
2015-08-14 00:35:51,653 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/maxbynullsafety/_temporary
2015-08-14 00:35:51,672 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/maxbynullsafety
2015-08-14 00:35:51,684 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:51,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-14 00:35:51,697 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum] starting
2015-08-14 00:35:51,697 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:51,697 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  sink: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/sumnulls"]
2015-08-14 00:35:51,697 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  parallel execution is enabled: false
2015-08-14 00:35:51,697 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  starting jobs: 1
2015-08-14 00:35:51,698 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  allocating threads: 1
2015-08-14 00:35:51,698 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] starting step: (1/1) ...yhelpersplatform/sumnulls
2015-08-14 00:35:51,727 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] submitted hadoop job: job_local685553143_0025
2015-08-14 00:35:51,727 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] tracking url: http://localhost:8080/
2015-08-14 00:35:51,732 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:51,752 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:51,752 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:51,759 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:51,759 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(sum)[by:[{1}:'char']]
2015-08-14 00:35:51,768 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:51,768 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:51,768 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-14 00:35:51,769 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:51,770 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:51,770 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-14 00:35:51,770 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:51,771 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:51,771 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-14 00:35:51,771 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:51,772 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:51,772 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-14 00:35:51,782 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:51,783 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:51,789 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(sum)[by:[{1}:'char']]
2015-08-14 00:35:51,789 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/sumnulls"]
2015-08-14 00:35:51,810 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/sumnulls/_temporary
2015-08-14 00:35:51,829 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/sumnulls
2015-08-14 00:35:51,840 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:51,841 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-14 00:35:51,851 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-14 00:35:51,851 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:51,851 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/countall"]
2015-08-14 00:35:51,851 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-14 00:35:51,851 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 1
2015-08-14 00:35:51,851 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-14 00:35:51,852 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/1) ...yhelpersplatform/countall
2015-08-14 00:35:51,882 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local282566428_0026
2015-08-14 00:35:51,883 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-14 00:35:51,887 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:51,908 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:51,908 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:51,915 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:51,915 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{?}:NONE]]
2015-08-14 00:35:51,926 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:51,927 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:51,932 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{?}:NONE]]
2015-08-14 00:35:51,933 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/countall"]
2015-08-14 00:35:51,946 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/countall/_temporary
2015-08-14 00:35:51,964 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/countall
2015-08-14 00:35:51,978 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:51,978 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-14 00:35:51,992 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-14 00:35:51,992 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:51,992 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-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/multi"]
2015-08-14 00:35:51,993 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-14 00:35:51,993 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-14 00:35:51,993 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-14 00:35:51,993 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...mblyhelpersplatform/multi
2015-08-14 00:35:52,022 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local1184333988_0027
2015-08-14 00:35:52,022 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-14 00:35:52,026 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:52,046 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:52,046 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:52,054 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:52,055 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-14 00:35:52,056 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:52,056 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:52,057 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-14 00:35:52,058 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:52,058 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:52,058 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-14 00:35:52,059 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:52,060 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:52,060 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-14 00:35:52,061 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:52,061 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 66, total: 295, max: 672
2015-08-14 00:35:52,061 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-14 00:35:52,072 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:52,072 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:52,080 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by:[{1}:'char']]
2015-08-14 00:35:52,080 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-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/multi"]
2015-08-14 00:35:52,105 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/multi/_temporary
2015-08-14 00:35:52,124 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/multi
2015-08-14 00:35:52,134 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:52,135 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-14 00:35:52,144 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-14 00:35:52,144 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt"]
2015-08-14 00:35:52,144 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/retainnarrow"]
2015-08-14 00:35:52,145 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-14 00:35:52,145 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-14 00:35:52,145 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-14 00:35:52,145 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...persplatform/retainnarrow
2015-08-14 00:35:52,173 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local538062630_0028
2015-08-14 00:35:52,174 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-14 00:35:52,178 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt
2015-08-14 00:35:52,181 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:52,181 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:52,185 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt"]
2015-08-14 00:35:52,185 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/retainnarrow"]
2015-08-14 00:35:52,195 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/retainnarrow/_temporary
2015-08-14 00:35:52,205 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/retainnarrow
2015-08-14 00:35:52,214 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:52,215 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-14 00:35:52,223 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-14 00:35:52,223 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt"]
2015-08-14 00:35:52,223 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['item']->['char', 'item']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/renamenarrow"]
2015-08-14 00:35:52,223 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-14 00:35:52,223 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-14 00:35:52,224 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-14 00:35:52,225 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...persplatform/renamenarrow
2015-08-14 00:35:52,256 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local1127707067_0029
2015-08-14 00:35:52,256 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-14 00:35:52,260 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt
2015-08-14 00:35:52,263 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:52,263 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:52,267 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt"]
2015-08-14 00:35:52,267 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['item']->['char', 'item']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/renamenarrow"]
2015-08-14 00:35:52,278 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/renamenarrow/_temporary
2015-08-14 00:35:52,287 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/renamenarrow
2015-08-14 00:35:52,298 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:52,299 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-14 00:35:52,309 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average] starting
2015-08-14 00:35:52,309 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:52,309 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  sink: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/averagenull"]
2015-08-14 00:35:52,310 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  parallel execution is enabled: false
2015-08-14 00:35:52,310 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  starting jobs: 1
2015-08-14 00:35:52,310 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  allocating threads: 1
2015-08-14 00:35:52,310 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] starting step: (1/1) ...lpersplatform/averagenull
2015-08-14 00:35:52,338 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] submitted hadoop job: job_local1409248560_0030
2015-08-14 00:35:52,339 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] tracking url: http://localhost:8080/
2015-08-14 00:35:52,343 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:52,362 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:52,362 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:52,368 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:52,368 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(average)[by:[{1}:'char']]
2015-08-14 00:35:52,372 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:52,373 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 169, total: 296, max: 672
2015-08-14 00:35:52,373 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 44% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:52,374 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:52,374 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 169, total: 296, max: 672
2015-08-14 00:35:52,374 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 44% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:52,375 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:52,375 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 168, total: 296, max: 672
2015-08-14 00:35:52,375 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 44% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:52,376 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:52,376 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 168, total: 296, max: 672
2015-08-14 00:35:52,376 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 44% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:52,386 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:52,387 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:52,391 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(average)[by:[{1}:'char']]
2015-08-14 00:35:52,392 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/averagenull"]
2015-08-14 00:35:52,411 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/averagenull/_temporary
2015-08-14 00:35:52,431 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/averagenull
2015-08-14 00:35:52,441 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:52,441 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-14 00:35:52,449 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce] starting
2015-08-14 00:35:52,449 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt"]
2015-08-14 00:35:52,450 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  sink: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/coerce"]
2015-08-14 00:35:52,450 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  parallel execution is enabled: false
2015-08-14 00:35:52,450 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  starting jobs: 1
2015-08-14 00:35:52,450 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  allocating threads: 1
2015-08-14 00:35:52,451 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] starting step: (1/1) ...blyhelpersplatform/coerce
2015-08-14 00:35:52,478 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] submitted hadoop job: job_local1808103781_0031
2015-08-14 00:35:52,479 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] tracking url: http://localhost:8080/
2015-08-14 00:35:52,483 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt
2015-08-14 00:35:52,486 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:52,486 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:52,490 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lower.txt"]
2015-08-14 00:35:52,490 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/coerce"]
2015-08-14 00:35:52,501 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/coerce/_temporary
2015-08-14 00:35:52,510 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/coerce
2015-08-14 00:35:52,521 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:52,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-14 00:35:52,531 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first] starting
2015-08-14 00:35:52,531 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  source: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs+rhs-cross-rev.txt"]
2015-08-14 00:35:52,531 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  sink: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/firstnfieldswithoutcomparator"]
2015-08-14 00:35:52,531 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  parallel execution is enabled: false
2015-08-14 00:35:52,532 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  starting jobs: 1
2015-08-14 00:35:52,532 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  allocating threads: 1
2015-08-14 00:35:52,532 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] starting step: (1/1) ...tnfieldswithoutcomparator
2015-08-14 00:35:52,560 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] submitted hadoop job: job_local214419388_0032
2015-08-14 00:35:52,560 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] tracking url: http://localhost:8080/
2015-08-14 00:35:52,564 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs+rhs-cross-rev.txt
2015-08-14 00:35:52,784 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:52,785 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:52,790 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs+rhs-cross-rev.txt"]
2015-08-14 00:35:52,790 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(first)[by:[{1}:'num']]
2015-08-14 00:35:52,792 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:52,793 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 325, total: 437, max: 672
2015-08-14 00:35:52,793 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:52,794 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:52,794 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 325, total: 437, max: 672
2015-08-14 00:35:52,795 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:52,805 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:52,805 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:52,810 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(first)[by:[{1}:'num']]
2015-08-14 00:35:52,810 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/firstnfieldswithoutcomparator"]
2015-08-14 00:35:52,825 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/firstnfieldswithoutcomparator/_temporary
2015-08-14 00:35:52,834 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/firstnfieldswithoutcomparator
2015-08-14 00:35:52,849 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:52,849 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-14 00:35:52,865 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-14 00:35:52,865 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:52,865 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:52,865 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false188"]
2015-08-14 00:35:52,866 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-14 00:35:52,866 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-14 00:35:52,866 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-14 00:35:52,866 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...tform/multimerge+false188
2015-08-14 00:35:52,896 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local1876117171_0033
2015-08-14 00:35:52,896 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-14 00:35:52,900 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:52,921 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:52,921 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:52,930 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:52,930 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-14 00:35:52,932 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:52,932 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 209, total: 437, max: 672
2015-08-14 00:35:52,932 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:52,933 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:52,933 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 209, total: 437, max: 672
2015-08-14 00:35:52,933 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:52,934 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:52,934 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 209, total: 437, max: 672
2015-08-14 00:35:52,935 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:52,935 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:52,935 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 209, total: 437, max: 672
2015-08-14 00:35:52,936 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:52,943 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt
2015-08-14 00:35:52,965 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:52,965 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:52,974 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:52,974 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-14 00:35:52,979 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:52,979 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 108, total: 437, max: 672
2015-08-14 00:35:52,979 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:52,980 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:52,981 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 108, total: 437, max: 672
2015-08-14 00:35:52,981 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:52,982 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:52,982 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 108, total: 437, max: 672
2015-08-14 00:35:52,982 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:52,983 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:52,983 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 108, total: 437, max: 672
2015-08-14 00:35:52,983 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:52,997 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:52,998 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,005 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-14 00:35:53,005 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false188"]
2015-08-14 00:35:53,020 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false188/_temporary
2015-08-14 00:35:53,041 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/multimerge+false188
2015-08-14 00:35:53,057 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:53,057 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-14 00:35:53,105 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...] starting
2015-08-14 00:35:53,106 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:53,106 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  sink: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergethreeway"]
2015-08-14 00:35:53,106 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  parallel execution is enabled: false
2015-08-14 00:35:53,106 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  starting jobs: 5
2015-08-14 00:35:53,106 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  allocating threads: 1
2015-08-14 00:35:53,107 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (1/5)
2015-08-14 00:35:53,142 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local447967921_0034
2015-08-14 00:35:53,142 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-14 00:35:53,146 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:53,166 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:53,166 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,171 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:53,172 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(source)[by:[{1}:'char']]
2015-08-14 00:35:53,173 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:53,173 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 221, total: 437, max: 672
2015-08-14 00:35:53,173 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:53,174 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:53,174 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 221, total: 437, max: 672
2015-08-14 00:35:53,174 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:53,175 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-14 00:35:53,175 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 221, total: 437, max: 672
2015-08-14 00:35:53,175 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:53,176 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-14 00:35:53,176 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 221, total: 437, max: 672
2015-08-14 00:35:53,176 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:53,186 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:53,186 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,190 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(source)[by:[{1}:'char']]
2015-08-14 00:35:53,191 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][4230231661/source/]
2015-08-14 00:35:53,205 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (3/5)
2015-08-14 00:35:53,233 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local827404158_0035
2015-08-14 00:35:53,233 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-14 00:35:53,236 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/4230231661_source_7EF207886D684F7B9E5538FD36353D32/part-00000
2015-08-14 00:35:53,258 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:53,258 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,263 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][4230231661/source/]
2015-08-14 00:35:53,263 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count-lhs)[by:[{1}:'char']]
2015-08-14 00:35:53,264 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:53,264 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 114, total: 437, max: 672
2015-08-14 00:35:53,264 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:53,265 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:53,265 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 114, total: 437, max: 672
2015-08-14 00:35:53,265 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:53,275 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:53,275 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,279 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count-lhs)[by:[{1}:'char']]
2015-08-14 00:35:53,279 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][4635596228/count-lhs/]
2015-08-14 00:35:53,295 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (4/5)
2015-08-14 00:35:53,323 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local1002366949_0036
2015-08-14 00:35:53,324 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-14 00:35:53,327 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/4230231661_source_7EF207886D684F7B9E5538FD36353D32/part-00000
2015-08-14 00:35:53,352 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:53,352 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,357 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][4230231661/source/]
2015-08-14 00:35:53,357 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count-rhs)[by:[{1}:'char']]
2015-08-14 00:35:53,359 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-14 00:35:53,359 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 224, total: 437, max: 672
2015-08-14 00:35:53,359 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:53,360 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-14 00:35:53,360 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 224, total: 437, max: 672
2015-08-14 00:35:53,360 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 65% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-14 00:35:53,369 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:53,369 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,374 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count-rhs)[by:[{1}:'char']]
2015-08-14 00:35:53,374 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][6366612295/count-rhs/]
2015-08-14 00:35:53,386 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (2/5)
2015-08-14 00:35:53,417 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local919510980_0037
2015-08-14 00:35:53,417 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-14 00:35:53,421 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/4230231661_source_7EF207886D684F7B9E5538FD36353D32/part-00000
2015-08-14 00:35:53,443 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:53,443 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,449 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][4230231661/source/]
2015-08-14 00:35:53,449 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(source*count-rhs)[by: source:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-14 00:35:53,458 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/6366612295_count_rhs_FD4A71928A764619BEFE24B5A5E64DE2/part-00000
2015-08-14 00:35:53,487 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:53,487 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,492 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][6366612295/count-rhs/]
2015-08-14 00:35:53,493 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(source*count-rhs)[by: source:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-14 00:35:53,507 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:53,507 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,511 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(source*count-rhs)[by: source:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-14 00:35:53,511 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'num', 'char2', 'count']]"][8056798775/source_count-rhs/]
2015-08-14 00:35:53,520 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-14 00:35:53,520 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-14 00:35:53,540 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (5/5) ...m/samesourcemergethreeway
2015-08-14 00:35:53,572 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local2076472649_0038
2015-08-14 00:35:53,573 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-14 00:35:53,576 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/8056798775_source_count_rhs_62271DF5C9074390A39D80EC7A80C614/part-00000
2015-08-14 00:35:53,596 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:53,596 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,604 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'num', 'char2', 'count']]"][8056798775/source_count-rhs/]
2015-08-14 00:35:53,604 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(count-lhs*source*count-rhs)[by: count-lhs:[{1}:'char'] source*count-rhs:[{1}:'char']]
2015-08-14 00:35:53,612 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/4635596228_count_lhs_0EE65CAC50FB4D5CB5397F1ECBB7F7B5/part-00000
2015-08-14 00:35:53,637 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:53,637 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,644 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][4635596228/count-lhs/]
2015-08-14 00:35:53,644 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(count-lhs*source*count-rhs)[by: count-lhs:[{1}:'char'] source*count-rhs:[{1}:'char']]
2015-08-14 00:35:53,658 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:53,658 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,664 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(count-lhs*source*count-rhs)[by: count-lhs:[{1}:'char'] source*count-rhs:[{1}:'char']]
2015-08-14 00:35:53,664 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergethreeway"]
2015-08-14 00:35:53,667 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-14 00:35:53,667 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-14 00:35:53,688 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergethreeway/_temporary
2015-08-14 00:35:53,706 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/samesourcemergethreeway
2015-08-14 00:35:53,720 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:53,720 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-14 00:35:53,735 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs] starting
2015-08-14 00:35:53,735 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:53,736 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:53,736 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  sink: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/uniquemerge-nondeterministic"]
2015-08-14 00:35:53,736 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  parallel execution is enabled: false
2015-08-14 00:35:53,736 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  starting jobs: 1
2015-08-14 00:35:53,736 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  allocating threads: 1
2015-08-14 00:35:53,737 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [lhs+rhs] starting step: (1/1) ...quemerge-nondeterministic
2015-08-14 00:35:53,766 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [lhs+rhs] submitted hadoop job: job_local1746448442_0039
2015-08-14 00:35:53,766 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [lhs+rhs] tracking url: http://localhost:8080/
2015-08-14 00:35:53,770 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:53,789 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:53,790 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,794 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:53,795 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-08-14 00:35:53,806 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt
2015-08-14 00:35:53,831 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:53,831 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,835 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/rhs.txt"]
2015-08-14 00:35:53,836 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-08-14 00:35:53,850 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:53,850 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,855 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-08-14 00:35:53,855 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/uniquemerge-nondeterministic"]
2015-08-14 00:35:53,870 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/uniquemerge-nondeterministic/_temporary
2015-08-14 00:35:53,880 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/uniquemerge-nondeterministic
2015-08-14 00:35:53,890 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:53,890 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-14 00:35:53,899 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-14 00:35:53,899 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:53,899 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/unique"]
2015-08-14 00:35:53,899 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-14 00:35:53,900 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-14 00:35:53,900 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-14 00:35:53,900 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...blyhelpersplatform/unique
2015-08-14 00:35:53,930 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local764793856_0040
2015-08-14 00:35:53,930 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-14 00:35:53,934 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:53,954 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:53,954 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,958 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:53,958 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(shape)[by:[{1}:'num']]
2015-08-14 00:35:53,969 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:53,969 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:53,974 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(shape)[by:[{1}:'num']]
2015-08-14 00:35:53,974 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/unique"]
2015-08-14 00:35:53,993 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/unique/_temporary
2015-08-14 00:35:54,002 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/unique
2015-08-14 00:35:54,014 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-14 00:35:54,015 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-14 00:35:54,025 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-14 00:35:54,025 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:54,025 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['notnull', 'null']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/countnullnotnull"]
2015-08-14 00:35:54,025 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-14 00:35:54,026 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 1
2015-08-14 00:35:54,026 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-14 00:35:54,026 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/1) ...platform/countnullnotnull
2015-08-14 00:35:54,056 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local1580665906_0041
2015-08-14 00:35:54,056 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-14 00:35:54,060 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt
2015-08-14 00:35:54,085 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-14 00:35:54,085 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-14 00:35:54,091 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/classes/test/data/lhs.txt"]
2015-08-14 00:35:54,091 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{?}:NONE]]
2015-08-14 00:35:54,105 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-14 00:35:54,105 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-14 00:35:54,111 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{?}:NONE]]
2015-08-14 00:35:54,111 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['notnull', 'null']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/countnullnotnull"]
2015-08-14 00:35:54,129 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output/hadoop/assemblyhelpersplatform/countnullnotnull/_temporary
2015-08-14 00:35:54,146 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.2.x/build/test/output//hadoop/assemblyhelpersplatform/countnullnotnull