Class cascading.pipe.assembly.AssemblyHelpersPlatformTest

35

tests

0

failures

12.801s

duration

100%

successful

Tests

Test Duration Result
testAverageBy 0.189s passed
testAverageByNull 0.254s passed
testAverageMerge 0.592s passed
testCoerce 0.088s passed
testCoerceFields 0.130s passed
testCount 0.294s passed
testCountAll 0.139s passed
testCountCount 0.872s passed
testCountMerge 0.543s passed
testCountNullNotNull 0.135s passed
testDiscardNarrow 0.099s passed
testFirstBy 0.306s passed
testFirstByWithoutComparator 0.135s passed
testMaxBy 0.304s passed
testMaxByNullSafety 0.269s passed
testMaxByString 0.549s passed
testMinBy 0.303s passed
testMinByNullSafety 0.328s passed
testMinByString 0.444s passed
testParallelAggregates 0.276s passed
testParallelAggregatesMerge 2.259s passed
testParallelAggregatesMergeLegacyHash 0.286s passed
testParallelAggregatesPriorMerge 0.513s passed
testParallelAggregatesPriorMergeLegacyHash 0.369s passed
testRenameAll 0.174s passed
testRenameNamed 0.096s passed
testRenameNarrow 0.078s passed
testRetainNarrow 0.081s passed
testSameSourceMerge 0.710s passed
testSameSourceMergeThreeWay 0.647s passed
testSumBy 0.451s passed
testSumByNulls 0.273s passed
testSumMerge 0.298s passed
testUnique 0.132s passed
testUniqueMerge 0.185s passed

Standard output

2015-08-13 23:26:28,755 INFO  platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2015-08-13 23:26:28,803 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop
2015-08-13 23:26:28,804 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.pipe.assembly.AssemblyHelpersPlatformTest
2015-08-13 23:26:28,849 INFO  hadoop.HadoopPlatform (HadoopPlatform.java:setUp(112)) - not using cluster
2015-08-13 23:26:29,145 INFO  platform.TestPlatform (TestPlatform.java:getGlobalProperties(72)) - platform property overrides: 
2015-08-13 23:26:29,543 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:29,546 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:29,560 INFO  property.AppProps (AppProps.java:getAppID(169)) - using app.id: 1021F879BC81477FB4127CF6015E4419
2015-08-13 23:26:29,850 INFO  util.Version (Version.java:printBanner(85)) - Concurrent, Inc - Cascading 2.7.1
2015-08-13 23:26:29,852 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-13 23:26:29,853 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:29,854 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:29,854 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false177"]
2015-08-13 23:26:29,855 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-13 23:26:29,855 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-13 23:26:29,856 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-13 23:26:29,858 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...tform/multimerge+false177
2015-08-13 23:26:29,911 WARN  util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2015-08-13 23:26:29,980 WARN  snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2015-08-13 23:26:30,260 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local_0001
2015-08-13 23:26:30,262 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-13 23:26:30,342 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:30,526 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:30,527 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:30,597 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:30,598 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-13 23:26:30,619 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:30,620 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 79, total: 197, max: 672
2015-08-13 23:26:30,620 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 29% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:30,622 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:30,622 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 79, total: 197, max: 672
2015-08-13 23:26:30,623 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 29% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:30,624 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:30,624 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 79, total: 197, max: 672
2015-08-13 23:26:30,625 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 29% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:30,626 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:30,626 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 79, total: 197, max: 672
2015-08-13 23:26:30,626 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 29% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:30,651 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt
2015-08-13 23:26:30,790 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:30,791 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:30,819 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:30,819 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-13 23:26:30,931 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:30,931 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 91, total: 292, max: 672
2015-08-13 23:26:30,932 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 43% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:30,933 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:30,934 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 91, total: 292, max: 672
2015-08-13 23:26:30,934 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 43% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:30,936 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:30,936 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 90, total: 292, max: 672
2015-08-13 23:26:30,937 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 43% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:30,938 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:30,938 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 90, total: 292, max: 672
2015-08-13 23:26:30,939 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 43% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:30,981 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:30,981 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:31,008 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-13 23:26:31,009 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false177"]
2015-08-13 23:26:31,054 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false177/_temporary
2015-08-13 23:26:31,105 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/multimerge+false177
2015-08-13 23:26:31,138 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:31,139 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:31,175 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-13 23:26:31,175 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:31,176 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['num', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/minbystring"]
2015-08-13 23:26:31,176 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-13 23:26:31,176 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-13 23:26:31,177 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-13 23:26:31,177 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...lpersplatform/minbystring
2015-08-13 23:26:31,291 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local_0002
2015-08-13 23:26:31,292 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-13 23:26:31,297 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:31,439 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:31,439 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:31,452 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:31,453 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'num']]
2015-08-13 23:26:31,455 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:31,455 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 71, total: 387, max: 672
2015-08-13 23:26:31,456 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 57% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:31,457 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:31,457 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 71, total: 387, max: 672
2015-08-13 23:26:31,457 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 57% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:31,473 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:31,473 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:31,485 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'num']]
2015-08-13 23:26:31,486 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/minbystring"]
2015-08-13 23:26:31,505 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/minbystring/_temporary
2015-08-13 23:26:31,552 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/minbystring
2015-08-13 23:26:31,591 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:31,592 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:31,633 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs] starting
2015-08-13 23:26:31,634 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.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:31,635 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.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:31,635 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.1.x/build/test/output/hadoop/assemblyhelpersplatform/mergeaverage"]
2015-08-13 23:26:31,635 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  parallel execution is enabled: false
2015-08-13 23:26:31,636 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  starting jobs: 1
2015-08-13 23:26:31,636 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average-lhs+average-rhs]  allocating threads: 1
2015-08-13 23:26:31,637 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average-lhs+average-rhs] starting step: (1/1) ...persplatform/mergeaverage
2015-08-13 23:26:31,713 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average-lhs+average-rhs] submitted hadoop job: job_local_0003
2015-08-13 23:26:31,713 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average-lhs+average-rhs] tracking url: http://localhost:8080/
2015-08-13 23:26:31,718 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:31,856 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:31,857 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:31,873 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:31,873 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(average-lhs+average-rhs)[by: average-lhs:[{1}:'char'] average-rhs:[{1}:'char']]
2015-08-13 23:26:31,875 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:31,876 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 81, total: 482, max: 672
2015-08-13 23:26:31,876 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 71% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:31,877 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:31,877 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 81, total: 482, max: 672
2015-08-13 23:26:31,878 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 71% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:31,879 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:31,879 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 81, total: 482, max: 672
2015-08-13 23:26:31,879 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 71% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:31,880 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:31,880 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 81, total: 482, max: 672
2015-08-13 23:26:31,881 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 71% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:31,892 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt
2015-08-13 23:26:32,029 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:32,030 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:32,045 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:32,046 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(average-lhs+average-rhs)[by: average-lhs:[{1}:'char'] average-rhs:[{1}:'char']]
2015-08-13 23:26:32,050 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:32,051 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 32, total: 535, max: 672
2015-08-13 23:26:32,051 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 79% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:32,052 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:32,053 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 32, total: 535, max: 672
2015-08-13 23:26:32,053 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 79% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:32,054 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:32,055 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 32, total: 535, max: 672
2015-08-13 23:26:32,055 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 79% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:32,056 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:32,056 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 32, total: 535, max: 672
2015-08-13 23:26:32,057 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 79% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:32,076 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:32,076 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:32,090 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(average-lhs+average-rhs)[by: average-lhs:[{1}:'char'] average-rhs:[{1}:'char']]
2015-08-13 23:26:32,091 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/mergeaverage"]
2015-08-13 23:26:32,117 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/mergeaverage/_temporary
2015-08-13 23:26:32,145 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/mergeaverage
2015-08-13 23:26:32,163 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:32,164 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:32,204 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-13 23:26:32,205 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt"]
2015-08-13 23:26:32,205 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/renameall"]
2015-08-13 23:26:32,206 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-13 23:26:32,206 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-13 23:26:32,206 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-13 23:26:32,207 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...helpersplatform/renameall
2015-08-13 23:26:32,263 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local_0004
2015-08-13 23:26:32,264 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-13 23:26:32,269 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt
2015-08-13 23:26:32,276 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:32,276 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:32,284 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt"]
2015-08-13 23:26:32,285 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/renameall"]
2015-08-13 23:26:32,306 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/renameall/_temporary
2015-08-13 23:26:32,320 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/renameall
2015-08-13 23:26:32,340 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:32,341 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:32,393 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-13 23:26:32,394 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:32,394 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['count', 'count2']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/countcount"]
2015-08-13 23:26:32,395 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-13 23:26:32,395 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 2
2015-08-13 23:26:32,395 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-13 23:26:32,396 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/2)
2015-08-13 23:26:32,451 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local_0005
2015-08-13 23:26:32,453 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-13 23:26:32,457 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:32,825 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:32,825 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:32,837 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:32,838 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{1}:'char']]
2015-08-13 23:26:32,839 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:32,840 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 77, total: 181, max: 672
2015-08-13 23:26:32,840 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 26% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:32,841 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:32,841 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 77, total: 181, max: 672
2015-08-13 23:26:32,842 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 26% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:32,843 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:32,843 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 77, total: 181, max: 672
2015-08-13 23:26:32,843 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 26% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:32,844 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:32,844 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 77, total: 181, max: 672
2015-08-13 23:26:32,845 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 26% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:32,859 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:32,860 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:32,871 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{1}:'char']]
2015-08-13 23:26:32,871 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['count', 'count2']]"][2920354748/count/]
2015-08-13 23:26:32,885 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:32,885 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 75, total: 181, max: 672
2015-08-13 23:26:32,885 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 26% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:32,901 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (2/2) ...elpersplatform/countcount
2015-08-13 23:26:32,954 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local_0006
2015-08-13 23:26:32,954 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-13 23:26:32,960 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/2920354748_count_CFBF3B0A392641CD86F08C1F5B05C286/part-00000
2015-08-13 23:26:33,104 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:33,105 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:33,117 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['count', 'count2']]"][2920354748/count/]
2015-08-13 23:26:33,117 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{1}:'count']]
2015-08-13 23:26:33,131 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:33,131 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:33,142 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{1}:'count']]
2015-08-13 23:26:33,143 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['count', 'count2']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/countcount"]
2015-08-13 23:26:33,168 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/countcount/_temporary
2015-08-13 23:26:33,193 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/countcount
2015-08-13 23:26:33,213 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:33,213 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:33,247 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs] starting
2015-08-13 23:26:33,248 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.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:33,248 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.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:33,248 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.1.x/build/test/output/hadoop/assemblyhelpersplatform/mergecount"]
2015-08-13 23:26:33,249 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  parallel execution is enabled: false
2015-08-13 23:26:33,249 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  starting jobs: 1
2015-08-13 23:26:33,249 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs+count-rhs]  allocating threads: 1
2015-08-13 23:26:33,250 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs+count-rhs] starting step: (1/1) ...elpersplatform/mergecount
2015-08-13 23:26:33,308 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs+count-rhs] submitted hadoop job: job_local_0007
2015-08-13 23:26:33,309 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs+count-rhs] tracking url: http://localhost:8080/
2015-08-13 23:26:33,314 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:33,455 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:33,456 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:33,470 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:33,470 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count-lhs+count-rhs)[by: count-lhs:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-13 23:26:33,472 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:33,473 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 92, total: 396, max: 672
2015-08-13 23:26:33,474 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 58% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:33,475 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:33,475 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 92, total: 396, max: 672
2015-08-13 23:26:33,476 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 58% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:33,477 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:33,478 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 92, total: 396, max: 672
2015-08-13 23:26:33,478 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 58% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:33,479 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:33,480 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 92, total: 396, max: 672
2015-08-13 23:26:33,480 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 58% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:33,491 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt
2015-08-13 23:26:33,627 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:33,628 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:33,642 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:33,643 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count-lhs+count-rhs)[by: count-lhs:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-13 23:26:33,647 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:33,648 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 86, total: 491, max: 672
2015-08-13 23:26:33,649 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 73% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:33,650 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:33,651 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 85, total: 491, max: 672
2015-08-13 23:26:33,651 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 73% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:33,653 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:33,653 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 85, total: 491, max: 672
2015-08-13 23:26:33,654 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 73% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:33,655 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:33,656 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 85, total: 491, max: 672
2015-08-13 23:26:33,656 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 73% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:33,673 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:33,674 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:33,687 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count-lhs+count-rhs)[by: count-lhs:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-13 23:26:33,688 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/mergecount"]
2015-08-13 23:26:33,713 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/mergecount/_temporary
2015-08-13 23:26:33,737 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/mergecount
2015-08-13 23:26:33,753 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:33,754 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:33,778 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min] starting
2015-08-13 23:26:33,779 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:33,779 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  sink: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/minbynullsafety"]
2015-08-13 23:26:33,780 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  parallel execution is enabled: false
2015-08-13 23:26:33,780 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  starting jobs: 1
2015-08-13 23:26:33,780 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  allocating threads: 1
2015-08-13 23:26:33,781 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] starting step: (1/1) ...splatform/minbynullsafety
2015-08-13 23:26:33,826 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] submitted hadoop job: job_local_0008
2015-08-13 23:26:33,827 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] tracking url: http://localhost:8080/
2015-08-13 23:26:33,832 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:33,976 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:33,977 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:33,989 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:33,989 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(min)[by:[{1}:'char']]
2015-08-13 23:26:33,991 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:33,992 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 43, total: 561, max: 672
2015-08-13 23:26:33,993 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:33,993 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 43, total: 561, max: 672
2015-08-13 23:26:33,994 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:33,994 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 43, total: 561, max: 672
2015-08-13 23:26:33,995 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:33,996 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 43, total: 561, max: 672
2015-08-13 23:26:34,010 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:34,010 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:34,024 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(min)[by:[{1}:'char']]
2015-08-13 23:26:34,024 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/minbynullsafety"]
2015-08-13 23:26:34,040 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/minbynullsafety/_temporary
2015-08-13 23:26:34,065 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/minbynullsafety
2015-08-13 23:26:34,084 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:34,085 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:34,112 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-13 23:26:34,113 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:34,113 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['num', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/maxbystring"]
2015-08-13 23:26:34,114 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-13 23:26:34,114 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-13 23:26:34,114 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-13 23:26:34,116 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...lpersplatform/maxbystring
2015-08-13 23:26:34,167 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local_0009
2015-08-13 23:26:34,169 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-13 23:26:34,174 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:34,535 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:34,536 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:34,547 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:34,547 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'num']]
2015-08-13 23:26:34,549 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:34,549 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 134, total: 239, max: 672
2015-08-13 23:26:34,550 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 35% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:34,550 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:34,551 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 134, total: 239, max: 672
2015-08-13 23:26:34,551 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 35% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:34,564 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:34,564 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:34,573 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'num']]
2015-08-13 23:26:34,574 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/maxbystring"]
2015-08-13 23:26:34,593 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/maxbystring/_temporary
2015-08-13 23:26:34,616 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/maxbystring
2015-08-13 23:26:34,632 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:34,632 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:34,661 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first] starting
2015-08-13 23:26:34,662 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  source: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs+rhs-cross.txt"]
2015-08-13 23:26:34,662 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  sink: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/firstnfields"]
2015-08-13 23:26:34,662 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  parallel execution is enabled: false
2015-08-13 23:26:34,662 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  starting jobs: 1
2015-08-13 23:26:34,663 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  allocating threads: 1
2015-08-13 23:26:34,663 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] starting step: (1/1) ...persplatform/firstnfields
2015-08-13 23:26:34,707 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] submitted hadoop job: job_local_0010
2015-08-13 23:26:34,707 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] tracking url: http://localhost:8080/
2015-08-13 23:26:34,712 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs+rhs-cross.txt
2015-08-13 23:26:34,851 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:34,851 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:34,860 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs+rhs-cross.txt"]
2015-08-13 23:26:34,860 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(first)[by:[{1}:'num']]
2015-08-13 23:26:34,864 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:34,864 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 116, total: 334, max: 672
2015-08-13 23:26:34,864 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 49% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:34,866 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:34,866 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 116, total: 334, max: 672
2015-08-13 23:26:34,867 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 49% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:34,880 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:34,880 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:34,888 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(first)[by:[{1}:'num']]
2015-08-13 23:26:34,888 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/firstnfields"]
2015-08-13 23:26:34,911 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/firstnfields/_temporary
2015-08-13 23:26:34,922 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/firstnfields
2015-08-13 23:26:34,938 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:34,939 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:34,961 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce] starting
2015-08-13 23:26:34,962 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt"]
2015-08-13 23:26:34,962 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  sink: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/coercefields"]
2015-08-13 23:26:34,962 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  parallel execution is enabled: false
2015-08-13 23:26:34,962 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  starting jobs: 1
2015-08-13 23:26:34,962 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  allocating threads: 1
2015-08-13 23:26:34,963 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] starting step: (1/1) ...persplatform/coercefields
2015-08-13 23:26:35,000 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] submitted hadoop job: job_local_0011
2015-08-13 23:26:35,001 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] tracking url: http://localhost:8080/
2015-08-13 23:26:35,005 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt
2015-08-13 23:26:35,009 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:35,009 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:35,018 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt"]
2015-08-13 23:26:35,019 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/coercefields"]
2015-08-13 23:26:35,042 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/coercefields/_temporary
2015-08-13 23:26:35,053 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/coercefields
2015-08-13 23:26:35,066 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:35,066 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:35,084 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-13 23:26:35,084 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:35,084 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/count"]
2015-08-13 23:26:35,085 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-13 23:26:35,085 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 1
2015-08-13 23:26:35,085 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-13 23:26:35,086 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/1) ...mblyhelpersplatform/count
2015-08-13 23:26:35,122 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local_0012
2015-08-13 23:26:35,123 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-13 23:26:35,127 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:35,271 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:35,271 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:35,281 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:35,282 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{1}:'char']]
2015-08-13 23:26:35,283 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:35,283 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 89, total: 429, max: 672
2015-08-13 23:26:35,284 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 63% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:35,285 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:35,285 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 89, total: 429, max: 672
2015-08-13 23:26:35,285 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 63% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:35,286 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:35,286 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 89, total: 429, max: 672
2015-08-13 23:26:35,286 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 63% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:35,287 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:35,287 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 89, total: 429, max: 672
2015-08-13 23:26:35,288 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 63% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:35,300 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:35,300 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:35,308 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{1}:'char']]
2015-08-13 23:26:35,309 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/count"]
2015-08-13 23:26:35,325 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/count/_temporary
2015-08-13 23:26:35,347 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/count
2015-08-13 23:26:35,360 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:35,361 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:35,379 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-13 23:26:35,379 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:35,380 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/maxby"]
2015-08-13 23:26:35,381 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-13 23:26:35,381 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-13 23:26:35,382 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-13 23:26:35,383 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...mblyhelpersplatform/maxby
2015-08-13 23:26:35,423 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local_0013
2015-08-13 23:26:35,424 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-13 23:26:35,430 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:35,571 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:35,572 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:35,581 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:35,581 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'char']]
2015-08-13 23:26:35,583 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:35,583 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 72, total: 524, max: 672
2015-08-13 23:26:35,584 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:35,585 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:35,585 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 72, total: 524, max: 672
2015-08-13 23:26:35,585 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:35,586 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:35,586 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 72, total: 524, max: 672
2015-08-13 23:26:35,586 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:35,587 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:35,588 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 72, total: 524, max: 672
2015-08-13 23:26:35,588 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 77% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:35,601 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:35,601 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:35,609 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'char']]
2015-08-13 23:26:35,609 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/maxby"]
2015-08-13 23:26:35,627 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/maxby/_temporary
2015-08-13 23:26:35,651 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/maxby
2015-08-13 23:26:35,667 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:35,667 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:35,686 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min] starting
2015-08-13 23:26:35,687 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:35,687 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  sink: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/minby"]
2015-08-13 23:26:35,687 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  parallel execution is enabled: false
2015-08-13 23:26:35,688 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  starting jobs: 1
2015-08-13 23:26:35,688 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [min]  allocating threads: 1
2015-08-13 23:26:35,688 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] starting step: (1/1) ...mblyhelpersplatform/minby
2015-08-13 23:26:35,742 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] submitted hadoop job: job_local_0014
2015-08-13 23:26:35,742 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [min] tracking url: http://localhost:8080/
2015-08-13 23:26:35,746 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:35,887 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:35,887 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:35,896 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:35,896 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(min)[by:[{1}:'char']]
2015-08-13 23:26:35,898 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:35,898 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 101, total: 591, max: 672
2015-08-13 23:26:35,899 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:35,899 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 100, total: 591, max: 672
2015-08-13 23:26:35,900 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:35,900 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 100, total: 591, max: 672
2015-08-13 23:26:35,901 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:35,901 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 100, total: 591, max: 672
2015-08-13 23:26:35,912 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:35,912 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:35,920 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(min)[by:[{1}:'char']]
2015-08-13 23:26:35,920 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'min']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/minby"]
2015-08-13 23:26:35,935 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/minby/_temporary
2015-08-13 23:26:35,954 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/minby
2015-08-13 23:26:35,966 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:35,967 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:35,984 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum] starting
2015-08-13 23:26:35,984 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:35,984 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  sink: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/sum"]
2015-08-13 23:26:35,984 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  parallel execution is enabled: false
2015-08-13 23:26:35,984 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  starting jobs: 1
2015-08-13 23:26:35,985 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  allocating threads: 1
2015-08-13 23:26:35,985 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] starting step: (1/1) ...semblyhelpersplatform/sum
2015-08-13 23:26:36,017 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] submitted hadoop job: job_local_0015
2015-08-13 23:26:36,018 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] tracking url: http://localhost:8080/
2015-08-13 23:26:36,021 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:36,330 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:36,330 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:36,339 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:36,340 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(sum)[by:[{1}:'char']]
2015-08-13 23:26:36,342 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:36,342 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 83, total: 189, max: 672
2015-08-13 23:26:36,342 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 28% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,343 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:36,344 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 83, total: 189, max: 672
2015-08-13 23:26:36,344 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 28% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,345 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:36,345 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 83, total: 189, max: 672
2015-08-13 23:26:36,345 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 28% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,346 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:36,346 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 83, total: 189, max: 672
2015-08-13 23:26:36,346 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 28% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,358 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:36,359 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:36,367 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(sum)[by:[{1}:'char']]
2015-08-13 23:26:36,367 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/sum"]
2015-08-13 23:26:36,382 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/sum/_temporary
2015-08-13 23:26:36,406 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/sum
2015-08-13 23:26:36,423 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:36,424 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:36,449 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs] starting
2015-08-13 23:26:36,449 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.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:36,450 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.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:36,450 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.1.x/build/test/output/hadoop/assemblyhelpersplatform/mergesum"]
2015-08-13 23:26:36,450 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  parallel execution is enabled: false
2015-08-13 23:26:36,450 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  starting jobs: 1
2015-08-13 23:26:36,450 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum-lhs+sum-rhs]  allocating threads: 1
2015-08-13 23:26:36,451 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum-lhs+sum-rhs] starting step: (1/1) ...yhelpersplatform/mergesum
2015-08-13 23:26:36,491 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum-lhs+sum-rhs] submitted hadoop job: job_local_0016
2015-08-13 23:26:36,492 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum-lhs+sum-rhs] tracking url: http://localhost:8080/
2015-08-13 23:26:36,496 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:36,571 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:36,571 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:36,582 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:36,582 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(sum-lhs+sum-rhs)[by: sum-lhs:[{1}:'char'] sum-rhs:[{1}:'char']]
2015-08-13 23:26:36,584 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:36,584 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 63, total: 284, max: 672
2015-08-13 23:26:36,593 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 42% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,595 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:36,595 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 174, total: 285, max: 672
2015-08-13 23:26:36,596 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 42% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,596 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:36,596 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 174, total: 285, max: 672
2015-08-13 23:26:36,597 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 42% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,597 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:36,597 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 174, total: 285, max: 672
2015-08-13 23:26:36,597 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 42% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,606 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt
2015-08-13 23:26:36,626 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:36,626 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:36,635 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:36,636 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(sum-lhs+sum-rhs)[by: sum-lhs:[{1}:'char'] sum-rhs:[{1}:'char']]
2015-08-13 23:26:36,640 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:36,640 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 72, total: 285, max: 672
2015-08-13 23:26:36,640 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 42% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,641 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:36,642 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 72, total: 285, max: 672
2015-08-13 23:26:36,642 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 42% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,643 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:36,643 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 72, total: 285, max: 672
2015-08-13 23:26:36,643 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 42% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,644 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:36,644 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 72, total: 285, max: 672
2015-08-13 23:26:36,645 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 42% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,659 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:36,660 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:36,668 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(sum-lhs+sum-rhs)[by: sum-lhs:[{1}:'char'] sum-rhs:[{1}:'char']]
2015-08-13 23:26:36,668 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/mergesum"]
2015-08-13 23:26:36,686 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/mergesum/_temporary
2015-08-13 23:26:36,705 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/mergesum
2015-08-13 23:26:36,717 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:36,717 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:36,731 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-13 23:26:36,731 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt"]
2015-08-13 23:26:36,732 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/discardnarrow"]
2015-08-13 23:26:36,732 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-13 23:26:36,732 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-13 23:26:36,732 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-13 23:26:36,733 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...ersplatform/discardnarrow
2015-08-13 23:26:36,763 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local_0017
2015-08-13 23:26:36,764 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-13 23:26:36,768 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt
2015-08-13 23:26:36,771 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:36,772 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:36,778 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt"]
2015-08-13 23:26:36,778 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/discardnarrow"]
2015-08-13 23:26:36,795 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/discardnarrow/_temporary
2015-08-13 23:26:36,805 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/discardnarrow
2015-08-13 23:26:36,820 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:36,821 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:36,856 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-13 23:26:36,857 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:36,857 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:36,857 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true178"]
2015-08-13 23:26:36,857 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-13 23:26:36,857 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-13 23:26:36,857 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-13 23:26:36,859 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...atform/multimerge+true178
2015-08-13 23:26:36,891 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local_0018
2015-08-13 23:26:36,892 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-13 23:26:36,895 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:36,915 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:36,916 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:36,927 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:36,928 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-13 23:26:36,930 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:36,930 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 123, total: 340, max: 672
2015-08-13 23:26:36,930 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 50% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,932 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:36,932 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 123, total: 340, max: 672
2015-08-13 23:26:36,932 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 50% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,934 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:36,934 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 123, total: 340, max: 672
2015-08-13 23:26:36,934 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 50% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,935 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:36,935 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 123, total: 340, max: 672
2015-08-13 23:26:36,935 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 50% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:36,943 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt
2015-08-13 23:26:37,084 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:37,084 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:37,097 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:37,097 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-13 23:26:37,102 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:37,103 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 116, total: 435, max: 672
2015-08-13 23:26:37,103 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 64% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:37,104 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:37,104 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 115, total: 435, max: 672
2015-08-13 23:26:37,105 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 64% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:37,106 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:37,106 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 115, total: 435, max: 672
2015-08-13 23:26:37,106 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 64% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:37,107 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:37,107 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 115, total: 435, max: 672
2015-08-13 23:26:37,107 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 64% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:37,123 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:37,123 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:37,134 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by:[{1}:'char']]
2015-08-13 23:26:37,134 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true178"]
2015-08-13 23:26:37,155 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true178/_temporary
2015-08-13 23:26:37,175 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/multimerge+true178
2015-08-13 23:26:37,185 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:37,185 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:37,195 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-13 23:26:37,196 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt"]
2015-08-13 23:26:37,196 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/rename"]
2015-08-13 23:26:37,197 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-13 23:26:37,197 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-13 23:26:37,198 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-13 23:26:37,199 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...blyhelpersplatform/rename
2015-08-13 23:26:37,230 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local_0019
2015-08-13 23:26:37,231 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-13 23:26:37,235 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt
2015-08-13 23:26:37,239 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:37,239 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:37,244 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt"]
2015-08-13 23:26:37,244 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['item', 'element']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/rename"]
2015-08-13 23:26:37,262 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/rename/_temporary
2015-08-13 23:26:37,272 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/rename
2015-08-13 23:26:37,290 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:37,291 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:37,316 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-13 23:26:37,317 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:37,318 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:37,319 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true177"]
2015-08-13 23:26:37,319 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-13 23:26:37,320 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-13 23:26:37,320 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-13 23:26:37,321 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...atform/multimerge+true177
2015-08-13 23:26:37,366 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local_0020
2015-08-13 23:26:37,366 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-13 23:26:37,370 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:37,515 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:37,515 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:37,527 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:37,528 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-13 23:26:37,530 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:37,530 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 83, total: 530, max: 672
2015-08-13 23:26:37,531 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 78% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:37,532 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:37,532 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 83, total: 530, max: 672
2015-08-13 23:26:37,532 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 78% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:37,533 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:37,534 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 83, total: 530, max: 672
2015-08-13 23:26:37,534 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 78% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:37,535 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:37,535 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 83, total: 530, max: 672
2015-08-13 23:26:37,535 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 78% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:37,544 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt
2015-08-13 23:26:37,690 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:37,690 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:37,702 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:37,703 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-13 23:26:37,708 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:37,708 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 77, total: 625, max: 672
2015-08-13 23:26:37,710 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:37,710 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 77, total: 625, max: 672
2015-08-13 23:26:37,711 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:37,711 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 76, total: 625, max: 672
2015-08-13 23:26:37,712 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:37,713 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 76, total: 625, max: 672
2015-08-13 23:26:37,730 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:37,730 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:37,743 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by:[{1}:'char']]
2015-08-13 23:26:37,743 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true177"]
2015-08-13 23:26:37,761 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+true177/_temporary
2015-08-13 23:26:37,784 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/multimerge+true177
2015-08-13 23:26:37,804 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:37,805 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:37,841 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second] starting
2015-08-13 23:26:37,842 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:37,842 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  sink: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergecount"]
2015-08-13 23:26:37,842 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  parallel execution is enabled: false
2015-08-13 23:26:37,842 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  starting jobs: 2
2015-08-13 23:26:37,843 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [second]  allocating threads: 1
2015-08-13 23:26:37,844 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] starting step: (1/2)
2015-08-13 23:26:37,887 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] submitted hadoop job: job_local_0021
2015-08-13 23:26:37,887 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] tracking url: http://localhost:8080/
2015-08-13 23:26:37,891 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:38,032 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:38,032 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:38,041 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:38,042 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(first)[by:[{1}:'char']]
2015-08-13 23:26:38,046 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:38,046 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 23, total: 689, max: 689
2015-08-13 23:26:38,048 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:38,048 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 23, total: 689, max: 689
2015-08-13 23:26:38,049 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:38,049 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 23, total: 689, max: 689
2015-08-13 23:26:38,050 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:38,050 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 23, total: 689, max: 689
2015-08-13 23:26:38,061 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:38,062 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:38,361 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(first)[by:[{1}:'char']]
2015-08-13 23:26:38,361 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][1339496937/first/]
2015-08-13 23:26:38,372 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] starting step: (2/2) ...form/samesourcemergecount
2015-08-13 23:26:38,402 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] submitted hadoop job: job_local_0022
2015-08-13 23:26:38,403 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [second] tracking url: http://localhost:8080/
2015-08-13 23:26:38,406 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/1339496937_first_5E47CFEF519543ED9A51774E6C6A3789/part-00000
2015-08-13 23:26:38,426 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:38,426 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:38,436 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][1339496937/first/]
2015-08-13 23:26:38,436 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(second)[by:[{1}:'char']]
2015-08-13 23:26:38,437 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:38,437 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 141, total: 250, max: 672
2015-08-13 23:26:38,438 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 37% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:38,438 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:38,439 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 140, total: 250, max: 672
2015-08-13 23:26:38,439 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 37% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:38,450 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:38,450 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:38,458 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(second)[by:[{1}:'char']]
2015-08-13 23:26:38,458 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergecount"]
2015-08-13 23:26:38,475 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergecount/_temporary
2015-08-13 23:26:38,494 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/samesourcemergecount
2015-08-13 23:26:38,506 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:38,506 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:38,517 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average] starting
2015-08-13 23:26:38,517 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:38,518 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  sink: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/average"]
2015-08-13 23:26:38,518 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  parallel execution is enabled: false
2015-08-13 23:26:38,518 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  starting jobs: 1
2015-08-13 23:26:38,518 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  allocating threads: 1
2015-08-13 23:26:38,519 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] starting step: (1/1) ...lyhelpersplatform/average
2015-08-13 23:26:38,549 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] submitted hadoop job: job_local_0023
2015-08-13 23:26:38,549 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] tracking url: http://localhost:8080/
2015-08-13 23:26:38,553 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:38,615 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:38,615 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:38,622 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:38,622 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(average)[by:[{1}:'char']]
2015-08-13 23:26:38,624 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:38,625 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 121, total: 345, max: 672
2015-08-13 23:26:38,625 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 51% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:38,626 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:38,627 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 120, total: 345, max: 672
2015-08-13 23:26:38,627 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 51% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:38,628 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:38,628 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 120, total: 345, max: 672
2015-08-13 23:26:38,628 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 51% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:38,629 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:38,630 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 120, total: 345, max: 672
2015-08-13 23:26:38,630 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 51% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:38,640 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:38,641 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:38,647 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(average)[by:[{1}:'char']]
2015-08-13 23:26:38,647 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/average"]
2015-08-13 23:26:38,664 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/average/_temporary
2015-08-13 23:26:38,683 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/average
2015-08-13 23:26:38,695 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:38,696 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:38,707 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max] starting
2015-08-13 23:26:38,707 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:38,707 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  sink: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/maxbynullsafety"]
2015-08-13 23:26:38,707 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  parallel execution is enabled: false
2015-08-13 23:26:38,707 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  starting jobs: 1
2015-08-13 23:26:38,708 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [max]  allocating threads: 1
2015-08-13 23:26:38,708 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] starting step: (1/1) ...splatform/maxbynullsafety
2015-08-13 23:26:38,739 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] submitted hadoop job: job_local_0024
2015-08-13 23:26:38,740 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [max] tracking url: http://localhost:8080/
2015-08-13 23:26:38,743 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:38,884 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:38,884 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:38,892 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:38,892 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(max)[by:[{1}:'char']]
2015-08-13 23:26:38,893 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:38,894 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 102, total: 440, max: 672
2015-08-13 23:26:38,894 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-13 23:26:38,895 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:38,895 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 101, total: 440, max: 672
2015-08-13 23:26:38,895 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-13 23:26:38,896 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:38,896 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 101, total: 440, max: 672
2015-08-13 23:26:38,896 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-13 23:26:38,897 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:38,897 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 101, total: 440, max: 672
2015-08-13 23:26:38,898 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-13 23:26:38,907 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:38,908 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:38,913 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(max)[by:[{1}:'char']]
2015-08-13 23:26:38,914 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'max']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/maxbynullsafety"]
2015-08-13 23:26:38,932 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/maxbynullsafety/_temporary
2015-08-13 23:26:38,952 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/maxbynullsafety
2015-08-13 23:26:38,965 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:38,965 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:38,977 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum] starting
2015-08-13 23:26:38,978 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:38,978 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  sink: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/sumnulls"]
2015-08-13 23:26:38,978 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  parallel execution is enabled: false
2015-08-13 23:26:38,978 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  starting jobs: 1
2015-08-13 23:26:38,978 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [sum]  allocating threads: 1
2015-08-13 23:26:38,979 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] starting step: (1/1) ...yhelpersplatform/sumnulls
2015-08-13 23:26:39,012 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] submitted hadoop job: job_local_0025
2015-08-13 23:26:39,013 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [sum] tracking url: http://localhost:8080/
2015-08-13 23:26:39,018 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:39,155 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:39,155 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:39,162 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:39,162 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(sum)[by:[{1}:'char']]
2015-08-13 23:26:39,171 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:39,171 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 81, total: 535, max: 672
2015-08-13 23:26:39,172 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 79% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:39,173 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:39,173 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 81, total: 535, max: 672
2015-08-13 23:26:39,173 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 79% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:39,174 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:39,174 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 81, total: 535, max: 672
2015-08-13 23:26:39,174 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 79% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:39,175 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:39,175 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 81, total: 535, max: 672
2015-08-13 23:26:39,176 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 79% of max mem, to better utilize unused memory consider increasing the cache size
2015-08-13 23:26:39,186 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:39,186 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:39,192 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(sum)[by:[{1}:'char']]
2015-08-13 23:26:39,192 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/sumnulls"]
2015-08-13 23:26:39,207 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/sumnulls/_temporary
2015-08-13 23:26:39,226 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/sumnulls
2015-08-13 23:26:39,238 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:39,238 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:39,249 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-13 23:26:39,249 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:39,249 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/countall"]
2015-08-13 23:26:39,249 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-13 23:26:39,249 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 1
2015-08-13 23:26:39,249 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-13 23:26:39,250 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/1) ...yhelpersplatform/countall
2015-08-13 23:26:39,280 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local_0026
2015-08-13 23:26:39,285 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-13 23:26:39,290 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:39,310 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:39,311 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:39,318 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:39,318 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{?}:NONE]]
2015-08-13 23:26:39,330 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:39,330 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:39,336 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{?}:NONE]]
2015-08-13 23:26:39,336 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/countall"]
2015-08-13 23:26:39,347 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/countall/_temporary
2015-08-13 23:26:39,366 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/countall
2015-08-13 23:26:39,381 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:39,381 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:39,397 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-13 23:26:39,397 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:39,397 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.1.x/build/test/output/hadoop/assemblyhelpersplatform/multi"]
2015-08-13 23:26:39,397 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-13 23:26:39,397 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-13 23:26:39,398 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-13 23:26:39,398 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...mblyhelpersplatform/multi
2015-08-13 23:26:39,428 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local_0027
2015-08-13 23:26:39,429 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-13 23:26:39,432 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:39,567 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:39,567 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:39,576 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:39,577 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by:[{1}:'char']]
2015-08-13 23:26:39,578 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:39,579 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 125, total: 633, max: 672
2015-08-13 23:26:39,580 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:39,581 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 125, total: 633, max: 672
2015-08-13 23:26:39,582 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:39,582 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 125, total: 633, max: 672
2015-08-13 23:26:39,584 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:39,584 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 124, total: 633, max: 672
2015-08-13 23:26:39,595 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:39,595 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:39,603 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by:[{1}:'char']]
2015-08-13 23:26:39,603 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.1.x/build/test/output/hadoop/assemblyhelpersplatform/multi"]
2015-08-13 23:26:39,621 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/multi/_temporary
2015-08-13 23:26:39,642 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/multi
2015-08-13 23:26:39,653 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:39,654 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:39,664 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-13 23:26:39,664 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt"]
2015-08-13 23:26:39,664 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/retainnarrow"]
2015-08-13 23:26:39,664 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-13 23:26:39,665 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-13 23:26:39,665 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-13 23:26:39,665 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...persplatform/retainnarrow
2015-08-13 23:26:39,693 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local_0028
2015-08-13 23:26:39,694 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-13 23:26:39,697 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt
2015-08-13 23:26:39,700 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:39,701 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:39,704 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt"]
2015-08-13 23:26:39,704 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['num']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/retainnarrow"]
2015-08-13 23:26:39,715 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/retainnarrow/_temporary
2015-08-13 23:26:39,724 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/retainnarrow
2015-08-13 23:26:39,733 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:39,733 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:39,742 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-13 23:26:39,742 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt"]
2015-08-13 23:26:39,742 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['item']->['char', 'item']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/renamenarrow"]
2015-08-13 23:26:39,743 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-13 23:26:39,743 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-13 23:26:39,743 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-13 23:26:39,743 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...persplatform/renamenarrow
2015-08-13 23:26:39,771 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local_0029
2015-08-13 23:26:39,771 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-13 23:26:39,776 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt
2015-08-13 23:26:39,780 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:39,780 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:39,784 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt"]
2015-08-13 23:26:39,784 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['item']->['char', 'item']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/renamenarrow"]
2015-08-13 23:26:39,792 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/renamenarrow/_temporary
2015-08-13 23:26:39,802 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/renamenarrow
2015-08-13 23:26:39,813 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:39,814 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:39,824 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average] starting
2015-08-13 23:26:39,825 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:39,825 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  sink: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/averagenull"]
2015-08-13 23:26:39,825 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  parallel execution is enabled: false
2015-08-13 23:26:39,825 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  starting jobs: 1
2015-08-13 23:26:39,825 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [average]  allocating threads: 1
2015-08-13 23:26:39,826 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] starting step: (1/1) ...lpersplatform/averagenull
2015-08-13 23:26:39,854 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] submitted hadoop job: job_local_0030
2015-08-13 23:26:39,854 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [average] tracking url: http://localhost:8080/
2015-08-13 23:26:39,857 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:39,992 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:39,992 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:39,998 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:39,999 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(average)[by:[{1}:'char']]
2015-08-13 23:26:40,003 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:40,003 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 47, total: 691, max: 691
2015-08-13 23:26:40,004 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:40,004 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 46, total: 691, max: 691
2015-08-13 23:26:40,005 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:40,005 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 46, total: 691, max: 691
2015-08-13 23:26:40,006 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:40,006 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 46, total: 691, max: 691
2015-08-13 23:26:40,016 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:40,016 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:40,021 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(average)[by:[{1}:'char']]
2015-08-13 23:26:40,022 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/averagenull"]
2015-08-13 23:26:40,037 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/averagenull/_temporary
2015-08-13 23:26:40,056 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/averagenull
2015-08-13 23:26:40,066 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:40,066 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:40,074 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce] starting
2015-08-13 23:26:40,074 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt"]
2015-08-13 23:26:40,075 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  sink: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/coerce"]
2015-08-13 23:26:40,075 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  parallel execution is enabled: false
2015-08-13 23:26:40,075 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  starting jobs: 1
2015-08-13 23:26:40,075 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [coerce]  allocating threads: 1
2015-08-13 23:26:40,076 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] starting step: (1/1) ...blyhelpersplatform/coerce
2015-08-13 23:26:40,104 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] submitted hadoop job: job_local_0031
2015-08-13 23:26:40,114 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [coerce] tracking url: http://localhost:8080/
2015-08-13 23:26:40,117 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt
2015-08-13 23:26:40,121 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:40,121 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:40,124 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lower.txt"]
2015-08-13 23:26:40,125 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['line']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/coerce"]
2015-08-13 23:26:40,135 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/coerce/_temporary
2015-08-13 23:26:40,144 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/coerce
2015-08-13 23:26:40,155 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:40,156 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:40,166 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first] starting
2015-08-13 23:26:40,166 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  source: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs+rhs-cross-rev.txt"]
2015-08-13 23:26:40,166 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  sink: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/firstnfieldswithoutcomparator"]
2015-08-13 23:26:40,167 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  parallel execution is enabled: false
2015-08-13 23:26:40,167 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  starting jobs: 1
2015-08-13 23:26:40,167 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [first]  allocating threads: 1
2015-08-13 23:26:40,167 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] starting step: (1/1) ...tnfieldswithoutcomparator
2015-08-13 23:26:40,198 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] submitted hadoop job: job_local_0032
2015-08-13 23:26:40,198 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [first] tracking url: http://localhost:8080/
2015-08-13 23:26:40,201 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs+rhs-cross-rev.txt
2015-08-13 23:26:40,221 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:40,221 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:40,226 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs+rhs-cross-rev.txt"]
2015-08-13 23:26:40,227 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(first)[by:[{1}:'num']]
2015-08-13 23:26:40,229 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:40,230 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 149, total: 745, max: 745
2015-08-13 23:26:40,231 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:40,231 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 149, total: 745, max: 745
2015-08-13 23:26:40,243 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:40,243 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:40,249 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(first)[by:[{1}:'num']]
2015-08-13 23:26:40,249 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['num', 'lower', 'upper']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/firstnfieldswithoutcomparator"]
2015-08-13 23:26:40,270 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/firstnfieldswithoutcomparator/_temporary
2015-08-13 23:26:40,279 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/firstnfieldswithoutcomparator
2015-08-13 23:26:40,294 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:40,295 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:40,311 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name] starting
2015-08-13 23:26:40,311 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:40,312 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:40,312 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  sink: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false178"]
2015-08-13 23:26:40,312 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  parallel execution is enabled: false
2015-08-13 23:26:40,312 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  starting jobs: 1
2015-08-13 23:26:40,312 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [name]  allocating threads: 1
2015-08-13 23:26:40,313 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] starting step: (1/1) ...tform/multimerge+false178
2015-08-13 23:26:40,342 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] submitted hadoop job: job_local_0033
2015-08-13 23:26:40,342 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [name] tracking url: http://localhost:8080/
2015-08-13 23:26:40,345 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:40,430 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:40,431 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:40,438 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:40,438 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-13 23:26:40,440 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:40,441 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 34, total: 745, max: 745
2015-08-13 23:26:40,442 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:40,442 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 34, total: 745, max: 745
2015-08-13 23:26:40,443 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:40,443 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 34, total: 745, max: 745
2015-08-13 23:26:40,444 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:40,444 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 33, total: 745, max: 745
2015-08-13 23:26:40,456 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt
2015-08-13 23:26:40,486 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:40,486 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:40,495 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:40,495 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-13 23:26:40,500 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:40,500 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 163, total: 746, max: 746
2015-08-13 23:26:40,501 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:40,502 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 163, total: 746, max: 746
2015-08-13 23:26:40,503 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:40,503 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 163, total: 746, max: 746
2015-08-13 23:26:40,504 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:40,504 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 163, total: 746, max: 746
2015-08-13 23:26:40,518 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:40,518 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:40,526 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(name)[by: multi-lhs:[{1}:'char'] multi-rhs:[{1}:'char']]
2015-08-13 23:26:40,526 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'sum', 'count', 'average']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false178"]
2015-08-13 23:26:40,547 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/multimerge+false178/_temporary
2015-08-13 23:26:40,566 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/multimerge+false178
2015-08-13 23:26:40,581 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:40,582 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:40,626 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...] starting
2015-08-13 23:26:40,627 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.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:40,627 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.1.x/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergethreeway"]
2015-08-13 23:26:40,627 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  parallel execution is enabled: false
2015-08-13 23:26:40,627 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  starting jobs: 5
2015-08-13 23:26:40,628 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count-lhs*source*count...]  allocating threads: 1
2015-08-13 23:26:40,630 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (1/5)
2015-08-13 23:26:40,658 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local_0034
2015-08-13 23:26:40,658 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-13 23:26:40,661 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:40,681 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:40,681 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:40,686 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:40,686 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(source)[by:[{1}:'char']]
2015-08-13 23:26:40,687 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:40,688 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 43, total: 746, max: 746
2015-08-13 23:26:40,688 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:40,689 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 43, total: 746, max: 746
2015-08-13 23:26:40,689 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 5, with capacity: 2
2015-08-13 23:26:40,689 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 43, total: 746, max: 746
2015-08-13 23:26:40,690 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 7, with capacity: 2
2015-08-13 23:26:40,690 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 42, total: 746, max: 746
2015-08-13 23:26:40,700 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:40,700 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:40,704 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(source)[by:[{1}:'char']]
2015-08-13 23:26:40,705 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][9686166572/source/]
2015-08-13 23:26:40,721 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (3/5)
2015-08-13 23:26:40,748 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local_0035
2015-08-13 23:26:40,749 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-13 23:26:40,752 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/9686166572_source_41994722EC174FB4AF5593A2460A964D/part-00000
2015-08-13 23:26:40,780 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:40,781 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:40,786 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][9686166572/source/]
2015-08-13 23:26:40,786 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count-lhs)[by:[{1}:'char']]
2015-08-13 23:26:40,787 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:40,787 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 164, total: 745, max: 745
2015-08-13 23:26:40,789 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:40,789 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 164, total: 745, max: 745
2015-08-13 23:26:40,799 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:40,799 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:40,803 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count-lhs)[by:[{1}:'char']]
2015-08-13 23:26:40,803 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][4875237403/count-lhs/]
2015-08-13 23:26:40,813 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (4/5)
2015-08-13 23:26:40,842 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local_0036
2015-08-13 23:26:40,842 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-13 23:26:40,845 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/9686166572_source_41994722EC174FB4AF5593A2460A964D/part-00000
2015-08-13 23:26:40,864 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:40,865 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:40,870 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][9686166572/source/]
2015-08-13 23:26:40,870 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count-rhs)[by:[{1}:'char']]
2015-08-13 23:26:40,871 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2015-08-13 23:26:40,871 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 56, total: 745, max: 745
2015-08-13 23:26:40,872 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2015-08-13 23:26:40,872 INFO  cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 56, total: 745, max: 745
2015-08-13 23:26:40,881 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:40,882 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:40,886 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count-rhs)[by:[{1}:'char']]
2015-08-13 23:26:40,886 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'count']]"][6123045286/count-rhs/]
2015-08-13 23:26:40,903 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (2/5)
2015-08-13 23:26:40,933 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local_0037
2015-08-13 23:26:40,933 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-13 23:26:40,937 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/9686166572_source_41994722EC174FB4AF5593A2460A964D/part-00000
2015-08-13 23:26:40,967 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:40,968 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:40,974 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][9686166572/source/]
2015-08-13 23:26:40,974 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(source*count-rhs)[by: source:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-13 23:26:40,982 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/6123045286_count_rhs_4E3D61E4293F43CBA7048BE63053CFCD/part-00000
2015-08-13 23:26:41,001 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:41,002 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:41,007 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][6123045286/count-rhs/]
2015-08-13 23:26:41,007 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(source*count-rhs)[by: source:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-13 23:26:41,022 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:41,022 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:41,026 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(source*count-rhs)[by: source:[{1}:'char'] count-rhs:[{1}:'char']]
2015-08-13 23:26:41,027 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[['char', 'num', 'char2', 'count']]"][8773505991/source_count-rhs/]
2015-08-13 23:26:41,035 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-13 23:26:41,036 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-13 23:26:41,049 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] starting step: (5/5) ...m/samesourcemergethreeway
2015-08-13 23:26:41,078 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] submitted hadoop job: job_local_0038
2015-08-13 23:26:41,078 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count-lhs*source*count...] tracking url: http://localhost:8080/
2015-08-13 23:26:41,082 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/8773505991_source_count_rhs_E120C2DBF381448C80233E7EF1EB47BD/part-00000
2015-08-13 23:26:41,111 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:41,111 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:41,117 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'num', 'char2', 'count']]"][8773505991/source_count-rhs/]
2015-08-13 23:26:41,117 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(count-lhs*source*count-rhs)[by: count-lhs:[{1}:'char'] source*count-rhs:[{1}:'char']]
2015-08-13 23:26:41,126 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/4875237403_count_lhs_81D3D1940BCC4F67B55D85109D8DEDDE/part-00000
2015-08-13 23:26:41,146 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:41,146 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:41,152 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[['char', 'count']]"][4875237403/count-lhs/]
2015-08-13 23:26:41,153 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(count-lhs*source*count-rhs)[by: count-lhs:[{1}:'char'] source*count-rhs:[{1}:'char']]
2015-08-13 23:26:41,166 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:41,167 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:41,172 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(count-lhs*source*count-rhs)[by: count-lhs:[{1}:'char'] source*count-rhs:[{1}:'char']]
2015-08-13 23:26:41,173 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['char', 'count']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergethreeway"]
2015-08-13 23:26:41,175 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-13 23:26:41,176 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-08-13 23:26:41,196 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/samesourcemergethreeway/_temporary
2015-08-13 23:26:41,214 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/samesourcemergethreeway
2015-08-13 23:26:41,228 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:41,228 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:41,244 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs] starting
2015-08-13 23:26:41,244 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:41,244 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:41,244 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  sink: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/uniquemerge-nondeterministic"]
2015-08-13 23:26:41,245 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  parallel execution is enabled: false
2015-08-13 23:26:41,245 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  starting jobs: 1
2015-08-13 23:26:41,245 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [lhs+rhs]  allocating threads: 1
2015-08-13 23:26:41,246 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [lhs+rhs] starting step: (1/1) ...quemerge-nondeterministic
2015-08-13 23:26:41,274 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [lhs+rhs] submitted hadoop job: job_local_0039
2015-08-13 23:26:41,274 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [lhs+rhs] tracking url: http://localhost:8080/
2015-08-13 23:26:41,277 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:41,306 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:41,307 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:41,311 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:41,312 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-08-13 23:26:41,326 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt
2015-08-13 23:26:41,345 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:41,345 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:41,349 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/rhs.txt"]
2015-08-13 23:26:41,350 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-08-13 23:26:41,364 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:41,365 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:41,370 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-08-13 23:26:41,370 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/uniquemerge-nondeterministic"]
2015-08-13 23:26:41,390 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/uniquemerge-nondeterministic/_temporary
2015-08-13 23:26:41,399 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/uniquemerge-nondeterministic
2015-08-13 23:26:41,409 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:41,410 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:41,419 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape] starting
2015-08-13 23:26:41,419 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:41,419 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  sink: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/unique"]
2015-08-13 23:26:41,419 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  parallel execution is enabled: false
2015-08-13 23:26:41,419 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  starting jobs: 1
2015-08-13 23:26:41,420 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [shape]  allocating threads: 1
2015-08-13 23:26:41,420 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] starting step: (1/1) ...blyhelpersplatform/unique
2015-08-13 23:26:41,447 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] submitted hadoop job: job_local_0040
2015-08-13 23:26:41,448 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [shape] tracking url: http://localhost:8080/
2015-08-13 23:26:41,451 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:41,481 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:41,482 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:41,487 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:41,487 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(shape)[by:[{1}:'num']]
2015-08-13 23:26:41,499 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:41,499 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:41,503 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(shape)[by:[{1}:'num']]
2015-08-13 23:26:41,503 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['item']->['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/unique"]
2015-08-13 23:26:41,522 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/unique/_temporary
2015-08-13 23:26:41,532 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/unique
2015-08-13 23:26:41,544 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-08-13 23:26:41,544 INFO  planner.HadoopPlanner (HadoopPlanner.java:initialize(226)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.7.1/e28a477e50cd8946adea60fa2bb90b57eaf07ef3/cascading-hadoop-2.7.1.jar
2015-08-13 23:26:41,555 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count] starting
2015-08-13 23:26:41,556 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:41,556 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  sink: Hfs["TextDelimited[['notnull', 'null']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/countnullnotnull"]
2015-08-13 23:26:41,556 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  parallel execution is enabled: false
2015-08-13 23:26:41,556 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  starting jobs: 1
2015-08-13 23:26:41,556 INFO  flow.Flow (BaseFlow.java:logInfo(1370)) - [count]  allocating threads: 1
2015-08-13 23:26:41,557 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] starting step: (1/1) ...platform/countnullnotnull
2015-08-13 23:26:41,587 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] submitted hadoop job: job_local_0041
2015-08-13 23:26:41,588 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(895)) - [count] tracking url: http://localhost:8080/
2015-08-13 23:26:41,591 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt
2015-08-13 23:26:41,611 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.7.1
2015-08-13 23:26:41,611 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-08-13 23:26:41,617 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/classes/test/data/lhs.txt"]
2015-08-13 23:26:41,618 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(count)[by:[{?}:NONE]]
2015-08-13 23:26:41,631 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.7.1
2015-08-13 23:26:41,632 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-08-13 23:26:41,637 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(count)[by:[{?}:NONE]]
2015-08-13 23:26:41,638 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextDelimited[['notnull', 'null']]"]["/opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/countnullnotnull"]
2015-08-13 23:26:41,649 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output/hadoop/assemblyhelpersplatform/countnullnotnull/_temporary
2015-08-13 23:26:41,666 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/8c57748d0461e126/apache-1.1.x/build/test/output//hadoop/assemblyhelpersplatform/countnullnotnull