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