2016-01-15 02:23:13,269 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-15 02:23:13,298 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.function.FunctionPlatformTest, with platform: hadoop2-mr1
2016-01-15 02:23:13,330 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-01-15 02:23:14,095 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-01-15 02:23:14,236 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-15 02:23:14,285 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2016-01-15 02:23:14,285 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 190, total: 223, max: 672
2016-01-15 02:23:14,286 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-15 02:23:14,286 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2016-01-15 02:23:14,287 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 190, total: 223, max: 672
2016-01-15 02:23:14,287 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-15 02:23:14,406 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-15 02:23:14,409 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-15 02:23:14,514 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 5E789A4D7E26429CB07BFA523F4D545A
2016-01-15 02:23:14,704 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.131
2016-01-15 02:23:14,708 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-15 02:23:14,710 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-15 02:23:14,854 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-15 02:23:14,855 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] starting
2016-01-15 02:23:14,856 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/classes/test/data/upper.txt"]
2016-01-15 02:23:14,857 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/test/output/hadoop2-mr1/functionplatform/testFieldFormatter/formatter"]
2016-01-15 02:23:14,857 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] parallel execution of steps is enabled: false
2016-01-15 02:23:14,857 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] executing total steps: 1
2016-01-15 02:23:14,858 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] allocating management threads: 1
2016-01-15 02:23:14,859 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] starting step: (1/1) ...tFieldFormatter/formatter
2016-01-15 02:23:15,512 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] submitted hadoop job: job_local1455787673_0001
2016-01-15 02:23:15,513 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] tracking url: http://localhost:8080/
2016-01-15 02:23:15,585 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/classes/test/data/upper.txt
2016-01-15 02:23:15,602 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-15 02:23:15,603 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-15 02:23:15,614 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A6A7FF2CC1EC4137A1D9CB95879C9E61, ordinal: 0
2016-01-15 02:23:15,641 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/classes/test/data/upper.txt"]
2016-01-15 02:23:15,641 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/test/output/hadoop2-mr1/functionplatform/testFieldFormatter/formatter"]
2016-01-15 02:23:15,642 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A6A7FF2CC1EC4137A1D9CB95879C9E61, mem on start (mb), free: 169, total: 223, max: 672
2016-01-15 02:23:15,652 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A6A7FF2CC1EC4137A1D9CB95879C9E61, mem on close (mb), free: 169, total: 223, max: 672
2016-01-15 02:23:15,700 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/test/output/hadoop2-mr1/functionplatform/testFieldFormatter/formatter/_temporary
2016-01-15 02:23:15,700 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [formatter] completed in: 00:00.844
2016-01-15 02:23:15,794 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/test/output//hadoop2-mr1/functionplatform/testFieldFormatter/formatter
2016-01-15 02:23:15,798 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 1, with capacity: 2
2016-01-15 02:23:15,798 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 223, max: 672
2016-01-15 02:23:15,799 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-15 02:23:15,800 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(105)) - flushed keys num times: 3, with capacity: 2
2016-01-15 02:23:15,800 INFO cache.LRUHashMapCache (LRUHashMapCache.java:removeEldestEntry(106)) - mem on flush (mb), free: 211, total: 223, max: 672
2016-01-15 02:23:15,801 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-15 02:23:15,841 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-15 02:23:15,842 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-15 02:23:15,921 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.065
2016-01-15 02:23:15,923 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-15 02:23:15,924 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-15 02:23:15,958 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] starting
2016-01-15 02:23:15,958 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/classes/test/data/apache.200.txt"]
2016-01-15 02:23:15,958 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/test/output/hadoop2-mr1/functionplatform/testInsert/insert"]
2016-01-15 02:23:15,959 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] parallel execution of steps is enabled: false
2016-01-15 02:23:15,960 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] executing total steps: 1
2016-01-15 02:23:15,960 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] allocating management threads: 1
2016-01-15 02:23:15,960 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] starting step: (1/1) ...latform/testInsert/insert
2016-01-15 02:23:16,116 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] submitted hadoop job: job_local911288226_0002
2016-01-15 02:23:16,116 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] tracking url: http://localhost:8080/
2016-01-15 02:23:16,124 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/classes/test/data/apache.200.txt
2016-01-15 02:23:16,253 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-15 02:23:16,253 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-15 02:23:16,265 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BEDBBE9C00904626907A265732570858, ordinal: 0
2016-01-15 02:23:16,271 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/classes/test/data/apache.200.txt"]
2016-01-15 02:23:16,271 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(apache)[by:[{1}:'A']]
2016-01-15 02:23:16,272 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BEDBBE9C00904626907A265732570858, mem on start (mb), free: 72, total: 223, max: 672
2016-01-15 02:23:16,295 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BEDBBE9C00904626907A265732570858, mem on close (mb), free: 72, total: 223, max: 672
2016-01-15 02:23:16,406 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-15 02:23:16,406 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-15 02:23:16,420 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: FAC470AED35C465EABD7E891EDB26313, ordinal: 1
2016-01-15 02:23:16,422 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(apache)[by:[{1}:'A']]
2016-01-15 02:23:16,423 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/test/output/hadoop2-mr1/functionplatform/testInsert/insert"]
2016-01-15 02:23:16,423 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FAC470AED35C465EABD7E891EDB26313, mem on start (mb), free: 59, total: 223, max: 672
2016-01-15 02:23:16,462 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FAC470AED35C465EABD7E891EDB26313, mem on close (mb), free: 58, total: 223, max: 672
2016-01-15 02:23:16,496 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/test/output/hadoop2-mr1/functionplatform/testInsert/insert/_temporary
2016-01-15 02:23:16,496 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [apache] completed in: 00:00.537
2016-01-15 02:23:16,607 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/test/output//hadoop2-mr1/functionplatform/testInsert/insert
2016-01-15 02:23:16,639 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-15 02:23:16,640 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(174)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.0.4/6099926be810c2c62f4bd24f369d52cdd84cf31d/cascading-hadoop2-mr1-3.0.4.jar
2016-01-15 02:23:16,708 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.056
2016-01-15 02:23:16,710 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 1
2016-01-15 02:23:16,711 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-15 02:23:16,741 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] starting
2016-01-15 02:23:16,741 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/classes/test/data/upper.txt"]
2016-01-15 02:23:16,742 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/test/output/hadoop2-mr1/functionplatform/testSetValue/setvalue"]
2016-01-15 02:23:16,742 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] parallel execution of steps is enabled: false
2016-01-15 02:23:16,742 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] executing total steps: 1
2016-01-15 02:23:16,742 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] allocating management threads: 1
2016-01-15 02:23:16,743 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] starting step: (1/1) ...orm/testSetValue/setvalue
2016-01-15 02:23:16,939 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] submitted hadoop job: job_local276520634_0003
2016-01-15 02:23:16,944 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] tracking url: http://localhost:8080/
2016-01-15 02:23:16,951 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/classes/test/data/upper.txt
2016-01-15 02:23:16,959 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-15 02:23:16,959 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-15 02:23:16,968 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: ECD0452DDFBA4126BD2DBB70179F969E, ordinal: 0
2016-01-15 02:23:16,969 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/classes/test/data/upper.txt"]
2016-01-15 02:23:16,969 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/test/output/hadoop2-mr1/functionplatform/testSetValue/setvalue"]
2016-01-15 02:23:16,970 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: ECD0452DDFBA4126BD2DBB70179F969E, mem on start (mb), free: 118, total: 281, max: 672
2016-01-15 02:23:16,973 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: ECD0452DDFBA4126BD2DBB70179F969E, mem on close (mb), free: 118, total: 281, max: 672
2016-01-15 02:23:16,992 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/test/output/hadoop2-mr1/functionplatform/testSetValue/setvalue/_temporary
2016-01-15 02:23:16,993 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [setvalue] completed in: 00:00.251
2016-01-15 02:23:17,045 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/aa7cf7440ab7c2d9/apache-2.6.x/build/test/output//hadoop2-mr1/functionplatform/testSetValue/setvalue