2016-01-14 23:50:07,371 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 23:50:07,387 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.function.FunctionPlatformTest, with platform: hadoop
2016-01-14 23:50:07,411 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(127)) - not using cluster
2016-01-14 23:50:07,645 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 23:50:07,692 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2016-01-14 23:50:07,693 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 175, total: 223, max: 672
2016-01-14 23:50:07,693 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 33% of max mem, to better utilize unused memory consider increasing the cache size
2016-01-14 23:50:07,694 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2016-01-14 23:50:07,694 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 175, total: 223, max: 672
2016-01-14 23:50:07,695 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 33% of max mem, to better utilize unused memory consider increasing the cache size
2016-01-14 23:50:07,787 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:50:07,790 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 23:50:07,904 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: AEDF6A5DD158455E9EF2F8CCF99229BF
2016-01-14 23:50:08,058 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.113
2016-01-14 23:50:08,060 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 23:50:08,061 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 23:50:08,229 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 23:50:08,231 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] starting
2016-01-14 23:50:08,232 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/classes/test/data/upper.txt"]
2016-01-14 23:50:08,232 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output/hadoop/functionplatform/testFieldFormatter/formatter"]
2016-01-14 23:50:08,233 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] parallel execution of steps is enabled: false
2016-01-14 23:50:08,233 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] executing total steps: 1
2016-01-14 23:50:08,233 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] allocating management threads: 1
2016-01-14 23:50:08,234 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] starting step: (1/1) ...tFieldFormatter/formatter
2016-01-14 23:50:08,269 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-01-14 23:50:08,326 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2016-01-14 23:50:08,561 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] submitted hadoop job: job_local1512349751_0001
2016-01-14 23:50:08,562 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] tracking url: http://localhost:8080/
2016-01-14 23:50:08,678 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/classes/test/data/upper.txt
2016-01-14 23:50:08,692 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 23:50:08,692 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 23:50:08,704 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DCD46EA9271C4BCE9880F1F6C1708BD9, ordinal: 0
2016-01-14 23:50:08,734 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/classes/test/data/upper.txt"]
2016-01-14 23:50:08,734 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output/hadoop/functionplatform/testFieldFormatter/formatter"]
2016-01-14 23:50:08,735 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DCD46EA9271C4BCE9880F1F6C1708BD9, mem on start (mb), free: 185, total: 223, max: 672
2016-01-14 23:50:08,746 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DCD46EA9271C4BCE9880F1F6C1708BD9, mem on close (mb), free: 185, total: 223, max: 672
2016-01-14 23:50:08,769 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output/hadoop/functionplatform/testFieldFormatter/formatter/_temporary
2016-01-14 23:50:08,771 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] completed in: 00:00.536
2016-01-14 23:50:08,816 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output//hadoop/functionplatform/testFieldFormatter/formatter
2016-01-14 23:50:08,818 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2016-01-14 23:50:08,819 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 181, total: 223, max: 672
2016-01-14 23:50:08,819 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 33% of max mem, to better utilize unused memory consider increasing the cache size
2016-01-14 23:50:08,819 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2016-01-14 23:50:08,820 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 181, total: 223, max: 672
2016-01-14 23:50:08,820 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(111)) - total mem is 33% of max mem, to better utilize unused memory consider increasing the cache size
2016-01-14 23:50:08,844 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:50:08,844 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 23:50:08,921 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.070
2016-01-14 23:50:08,922 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 23:50:08,923 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 23:50:08,952 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] starting
2016-01-14 23:50:08,953 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/classes/test/data/apache.200.txt"]
2016-01-14 23:50:08,953 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output/hadoop/functionplatform/testInsert/insert"]
2016-01-14 23:50:08,953 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] parallel execution of steps is enabled: false
2016-01-14 23:50:08,953 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] executing total steps: 1
2016-01-14 23:50:08,954 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] allocating management threads: 1
2016-01-14 23:50:08,954 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] starting step: (1/1) ...latform/testInsert/insert
2016-01-14 23:50:09,071 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] submitted hadoop job: job_local907378160_0002
2016-01-14 23:50:09,071 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] tracking url: http://localhost:8080/
2016-01-14 23:50:09,079 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/classes/test/data/apache.200.txt
2016-01-14 23:50:09,213 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 23:50:09,213 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 23:50:09,230 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C5F29F9259E04E67A636DB6A62341FDB, ordinal: 0
2016-01-14 23:50:09,239 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/classes/test/data/apache.200.txt"]
2016-01-14 23:50:09,239 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(apache)[by:[{1}:'A']]
2016-01-14 23:50:09,239 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C5F29F9259E04E67A636DB6A62341FDB, mem on start (mb), free: 68, total: 223, max: 672
2016-01-14 23:50:09,278 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C5F29F9259E04E67A636DB6A62341FDB, mem on close (mb), free: 68, total: 223, max: 672
2016-01-14 23:50:09,315 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 23:50:09,315 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 23:50:09,324 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A5BC4EDC76AE4433976491B66CFFE045, ordinal: 1
2016-01-14 23:50:09,327 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(apache)[by:[{1}:'A']]
2016-01-14 23:50:09,327 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output/hadoop/functionplatform/testInsert/insert"]
2016-01-14 23:50:09,327 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A5BC4EDC76AE4433976491B66CFFE045, mem on start (mb), free: 66, total: 223, max: 672
2016-01-14 23:50:09,355 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A5BC4EDC76AE4433976491B66CFFE045, mem on close (mb), free: 66, total: 223, max: 672
2016-01-14 23:50:09,367 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output/hadoop/functionplatform/testInsert/insert/_temporary
2016-01-14 23:50:09,367 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] completed in: 00:00.415
2016-01-14 23:50:09,429 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output//hadoop/functionplatform/testInsert/insert
2016-01-14 23:50:09,458 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 23:50:09,459 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.0.4/ab50b225eb80fe7b8e59368476a4bfb0fa1a0ef5/cascading-hadoop-3.0.4.jar
2016-01-14 23:50:09,546 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.080
2016-01-14 23:50:09,548 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-14 23:50:09,548 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 23:50:09,572 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] starting
2016-01-14 23:50:09,574 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/classes/test/data/upper.txt"]
2016-01-14 23:50:09,574 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output/hadoop/functionplatform/testSetValue/setvalue"]
2016-01-14 23:50:09,576 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] parallel execution of steps is enabled: false
2016-01-14 23:50:09,576 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] executing total steps: 1
2016-01-14 23:50:09,577 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] allocating management threads: 1
2016-01-14 23:50:09,578 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] starting step: (1/1) ...orm/testSetValue/setvalue
2016-01-14 23:50:09,647 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] submitted hadoop job: job_local601221069_0003
2016-01-14 23:50:09,647 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] tracking url: http://localhost:8080/
2016-01-14 23:50:09,655 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/classes/test/data/upper.txt
2016-01-14 23:50:09,661 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 23:50:09,662 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 23:50:09,676 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D22126A29EB14DFF8ED825E30DC0CCD6, ordinal: 0
2016-01-14 23:50:09,677 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/classes/test/data/upper.txt"]
2016-01-14 23:50:09,677 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output/hadoop/functionplatform/testSetValue/setvalue"]
2016-01-14 23:50:09,678 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D22126A29EB14DFF8ED825E30DC0CCD6, mem on start (mb), free: 112, total: 223, max: 672
2016-01-14 23:50:09,681 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D22126A29EB14DFF8ED825E30DC0CCD6, mem on close (mb), free: 112, total: 223, max: 672
2016-01-14 23:50:09,700 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output/hadoop/functionplatform/testSetValue/setvalue/_temporary
2016-01-14 23:50:09,700 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] completed in: 00:00.127
2016-01-14 23:50:09,730 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-1.2.x/build/test/output//hadoop/functionplatform/testSetValue/setvalue