2016-05-17 23:13:47,134 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-17 23:13:47,149 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.function.FunctionPlatformTest, with platform: hadoop
2016-05-17 23:13:47,171 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(127)) - not using cluster
2016-05-17 23:13:47,393 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-17 23:13:47,439 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2016-05-17 23:13:47,439 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 174, total: 223, max: 672
2016-05-17 23:13:47,439 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-05-17 23:13:47,440 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2016-05-17 23:13:47,440 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 174, total: 223, max: 672
2016-05-17 23:13:47,440 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-05-17 23:13:47,518 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:13:47,519 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-17 23:13:47,632 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: E94ECF6FEBC94399B8B0597652610001
2016-05-17 23:13:47,784 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [formatter] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.113
2016-05-17 23:13:47,787 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [formatter] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 23:13:47,787 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [formatter] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 23:13:47,978 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-17 23:13:47,979 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [formatter] starting
2016-05-17 23:13:47,980 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [formatter] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/classes/test/data/upper.txt"]
2016-05-17 23:13:47,981 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [formatter] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/test/output/hadoop/functionplatform/testFieldFormatter/formatter"]
2016-05-17 23:13:47,981 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [formatter] parallel execution of steps is enabled: false
2016-05-17 23:13:47,981 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [formatter] executing total steps: 1
2016-05-17 23:13:47,981 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [formatter] allocating management threads: 1
2016-05-17 23:13:47,982 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [formatter] starting step: (1/1) ...tFieldFormatter/formatter
2016-05-17 23:13:48,019 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-05-17 23:13:48,230 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [formatter] submitted hadoop job: job_local_0001
2016-05-17 23:13:48,231 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [formatter] tracking url: http://localhost:8080/
2016-05-17 23:13:48,294 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/classes/test/data/upper.txt
2016-05-17 23:13:48,307 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:13:48,308 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:13:48,322 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D7AE6B6FB3A54C9B9C341F3383B41F91, ordinal: 0
2016-05-17 23:13:48,350 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/classes/test/data/upper.txt"]
2016-05-17 23:13:48,351 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/test/output/hadoop/functionplatform/testFieldFormatter/formatter"]
2016-05-17 23:13:48,351 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D7AE6B6FB3A54C9B9C341F3383B41F91, mem on start (mb), free: 189, total: 223, max: 672
2016-05-17 23:13:48,361 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D7AE6B6FB3A54C9B9C341F3383B41F91, mem on close (mb), free: 188, total: 223, max: 672
2016-05-17 23:13:51,277 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/test/output/hadoop/functionplatform/testFieldFormatter/formatter/_temporary
2016-05-17 23:13:51,279 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [formatter] completed in: 00:03.297
2016-05-17 23:13:51,317 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/test/output//hadoop/functionplatform/testFieldFormatter/formatter
2016-05-17 23:13:51,320 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2016-05-17 23:13:51,321 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 185, total: 223, max: 672
2016-05-17 23:13:51,321 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-05-17 23:13:51,322 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2016-05-17 23:13:51,323 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 185, total: 223, max: 672
2016-05-17 23:13:51,323 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-05-17 23:13:51,347 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:13:51,348 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-17 23:13:51,428 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [apache] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.072
2016-05-17 23:13:51,430 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [apache] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-17 23:13:51,431 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [apache] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 23:13:51,463 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [apache] starting
2016-05-17 23:13:51,464 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [apache] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/classes/test/data/apache.200.txt"]
2016-05-17 23:13:51,464 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [apache] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/test/output/hadoop/functionplatform/testInsert/insert"]
2016-05-17 23:13:51,465 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [apache] parallel execution of steps is enabled: false
2016-05-17 23:13:51,466 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [apache] executing total steps: 1
2016-05-17 23:13:51,466 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [apache] allocating management threads: 1
2016-05-17 23:13:51,468 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [apache] starting step: (1/1) ...latform/testInsert/insert
2016-05-17 23:13:51,540 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [apache] submitted hadoop job: job_local_0002
2016-05-17 23:13:51,540 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [apache] tracking url: http://localhost:8080/
2016-05-17 23:13:51,546 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/classes/test/data/apache.200.txt
2016-05-17 23:13:51,683 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:13:51,684 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:13:51,698 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D32C53CA85B14ED0A186398702A47F93, ordinal: 0
2016-05-17 23:13:51,705 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/classes/test/data/apache.200.txt"]
2016-05-17 23:13:51,706 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(apache)[by:[{1}:'A']]
2016-05-17 23:13:51,706 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D32C53CA85B14ED0A186398702A47F93, mem on start (mb), free: 73, total: 223, max: 672
2016-05-17 23:13:51,737 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D32C53CA85B14ED0A186398702A47F93, mem on close (mb), free: 73, total: 223, max: 672
2016-05-17 23:13:54,561 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-17 23:13:54,561 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-17 23:13:54,572 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D69B6A29B58948FC91E8F775C23F01BE, ordinal: 1
2016-05-17 23:13:54,574 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(apache)[by:[{1}:'A']]
2016-05-17 23:13:54,574 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/test/output/hadoop/functionplatform/testInsert/insert"]
2016-05-17 23:13:54,575 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D69B6A29B58948FC91E8F775C23F01BE, mem on start (mb), free: 71, total: 223, max: 672
2016-05-17 23:13:54,604 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D69B6A29B58948FC91E8F775C23F01BE, mem on close (mb), free: 71, total: 223, max: 672
2016-05-17 23:13:57,557 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/test/output/hadoop/functionplatform/testInsert/insert/_temporary
2016-05-17 23:13:57,558 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [apache] completed in: 00:06.093
2016-05-17 23:13:57,595 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/test/output//hadoop/functionplatform/testInsert/insert
2016-05-17 23:13:57,613 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-17 23:13:57,613 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-17 23:13:57,660 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [setvalue] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.042
2016-05-17 23:13:57,661 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [setvalue] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-05-17 23:13:57,662 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [setvalue] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-17 23:13:57,678 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [setvalue] starting
2016-05-17 23:13:57,678 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [setvalue] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/classes/test/data/upper.txt"]
2016-05-17 23:13:57,679 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [setvalue] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/test/output/hadoop/functionplatform/testSetValue/setvalue"]
2016-05-17 23:13:57,679 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [setvalue] parallel execution of steps is enabled: false
2016-05-17 23:13:57,679 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [setvalue] executing total steps: 1
2016-05-17 23:13:57,680 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [setvalue] allocating management threads: 1
2016-05-17 23:13:57,680 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [setvalue] starting step: (1/1) ...orm/testSetValue/setvalue
2016-05-17 23:13:57,758 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [setvalue] submitted hadoop job: job_local_0003
2016-05-17 23:13:57,758 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [setvalue] tracking url: http://localhost:8080/
2016-05-17 23:13:57,764 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/classes/test/data/upper.txt
2016-05-17 23:13:57,769 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-17 23:13:57,770 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-17 23:13:57,806 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A68314D6AF88472DAED01E7E1E36869F, ordinal: 0
2016-05-17 23:13:57,807 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/classes/test/data/upper.txt"]
2016-05-17 23:13:57,807 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/test/output/hadoop/functionplatform/testSetValue/setvalue"]
2016-05-17 23:13:57,807 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A68314D6AF88472DAED01E7E1E36869F, mem on start (mb), free: 119, total: 223, max: 672
2016-05-17 23:13:57,811 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A68314D6AF88472DAED01E7E1E36869F, mem on close (mb), free: 119, total: 223, max: 672
2016-05-17 23:14:00,770 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/test/output/hadoop/functionplatform/testSetValue/setvalue/_temporary
2016-05-17 23:14:00,770 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [setvalue] completed in: 00:03.091
2016-05-17 23:14:00,799 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-0.20.205.0/build/test/output//hadoop/functionplatform/testSetValue/setvalue