2016-01-14 16:52:24,033 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(195)) - found 1 test platforms from classpath
2016-01-14 16:52:24,049 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(244)) - adding test: cascading.BufferPipesPlatformTest, with platform: hadoop
2016-01-14 16:52:24,073 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(127)) - not using cluster
2016-01-14 16:52:24,294 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(73)) - platform property overrides:
2016-01-14 16:52:24,400 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:52:24,401 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 16:52:24,513 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 0400DA71210A42CC90914E876E10BD15
2016-01-14 16:52:24,683 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.128
2016-01-14 16:52:24,687 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:52:24,687 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:52:24,906 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.0.4
2016-01-14 16:52:24,907 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 16:52:24,908 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2016-01-14 16:52:24,908 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testIdentityBuffer/identity"]
2016-01-14 16:52:24,909 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 16:52:24,909 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 16:52:24,911 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 16:52:24,914 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...stIdentityBuffer/identity
2016-01-14 16:52:24,950 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 16:52:25,204 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local_0001
2016-01-14 16:52:25,205 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 16:52:25,264 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt
2016-01-14 16:52:25,394 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 16:52:25,396 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 16:52:25,410 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E7C737DFD0784FBEB36AA5011309BFD7, ordinal: 0
2016-01-14 16:52:25,458 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2016-01-14 16:52:25,458 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-01-14 16:52:25,459 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E7C737DFD0784FBEB36AA5011309BFD7, mem on start (mb), free: 88, total: 223, max: 672
2016-01-14 16:52:25,471 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E7C737DFD0784FBEB36AA5011309BFD7, mem on close (mb), free: 87, total: 223, max: 672
2016-01-14 16:52:28,259 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 16:52:28,259 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 16:52:28,273 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DCE922C08C81456B8195BA71B5AAF928, ordinal: 1
2016-01-14 16:52:28,278 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-01-14 16:52:28,279 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testIdentityBuffer/identity"]
2016-01-14 16:52:28,279 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DCE922C08C81456B8195BA71B5AAF928, mem on start (mb), free: 85, total: 223, max: 672
2016-01-14 16:52:28,298 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DCE922C08C81456B8195BA71B5AAF928, mem on close (mb), free: 85, total: 223, max: 672
2016-01-14 16:52:31,265 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testIdentityBuffer/identity/_temporary
2016-01-14 16:52:31,267 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:06.357
2016-01-14 16:52:31,315 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/bufferpipesplatform/testIdentityBuffer/identity
2016-01-14 16:52:31,341 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:52:31,341 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 16:52:31,436 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.088
2016-01-14 16:52:31,438 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:52:31,439 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:52:31,480 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 16:52:31,481 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2016-01-14 16:52:31,481 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferForward/firstn"]
2016-01-14 16:52:31,483 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 16:52:31,483 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 16:52:31,483 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 16:52:31,486 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...irstNBufferForward/firstn
2016-01-14 16:52:31,576 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local_0002
2016-01-14 16:52:31,577 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 16:52:31,580 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt
2016-01-14 16:52:31,677 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 16:52:31,677 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 16:52:31,686 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C194C3A200A947668BFE4A70CAA8E707, ordinal: 0
2016-01-14 16:52:31,687 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2016-01-14 16:52:31,687 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-01-14 16:52:31,688 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C194C3A200A947668BFE4A70CAA8E707, mem on start (mb), free: 67, total: 318, max: 672
2016-01-14 16:52:31,693 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C194C3A200A947668BFE4A70CAA8E707, mem on close (mb), free: 67, total: 318, max: 672
2016-01-14 16:52:34,585 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 16:52:34,586 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 16:52:34,600 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F101073C045341A9AD694FB43FF67ED4, ordinal: 1
2016-01-14 16:52:34,601 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-01-14 16:52:34,601 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferForward/firstn"]
2016-01-14 16:52:34,601 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F101073C045341A9AD694FB43FF67ED4, mem on start (mb), free: 66, total: 318, max: 672
2016-01-14 16:52:34,608 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F101073C045341A9AD694FB43FF67ED4, mem on close (mb), free: 66, total: 318, max: 672
2016-01-14 16:52:37,595 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferForward/firstn/_temporary
2016-01-14 16:52:37,596 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:06.114
2016-01-14 16:52:37,630 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/bufferpipesplatform/testFirstNBufferForward/firstn
2016-01-14 16:52:37,652 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:52:37,653 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 16:52:37,781 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.120
2016-01-14 16:52:37,784 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:52:37,784 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:52:37,827 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 16:52:37,827 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2016-01-14 16:52:37,828 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer/simple"]
2016-01-14 16:52:37,829 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 16:52:37,829 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 16:52:37,829 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 16:52:37,830 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...m/testSimpleBuffer/simple
2016-01-14 16:52:37,899 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local_0003
2016-01-14 16:52:37,900 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 16:52:37,905 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt
2016-01-14 16:52:38,002 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 16:52:38,002 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 16:52:38,013 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B5B81FAF2DF74B8FBBDFA104C738BF8F, ordinal: 0
2016-01-14 16:52:38,014 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2016-01-14 16:52:38,014 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-01-14 16:52:38,015 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B5B81FAF2DF74B8FBBDFA104C738BF8F, mem on start (mb), free: 109, total: 414, max: 672
2016-01-14 16:52:38,017 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B5B81FAF2DF74B8FBBDFA104C738BF8F, mem on close (mb), free: 109, total: 414, max: 672
2016-01-14 16:52:40,909 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 16:52:40,910 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 16:52:40,920 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E4EAF1EE4FEF4C25A07AF0D27FAB9AE5, ordinal: 1
2016-01-14 16:52:40,921 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-01-14 16:52:40,921 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer/simple"]
2016-01-14 16:52:40,921 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E4EAF1EE4FEF4C25A07AF0D27FAB9AE5, mem on start (mb), free: 108, total: 414, max: 672
2016-01-14 16:52:40,927 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E4EAF1EE4FEF4C25A07AF0D27FAB9AE5, mem on close (mb), free: 108, total: 414, max: 672
2016-01-14 16:52:43,912 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer/simple/_temporary
2016-01-14 16:52:43,913 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:06.085
2016-01-14 16:52:43,935 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/bufferpipesplatform/testSimpleBuffer/simple
2016-01-14 16:52:43,947 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:52:43,948 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 16:52:44,018 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.065
2016-01-14 16:52:44,020 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:52:44,020 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:52:44,052 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] starting
2016-01-14 16:52:44,053 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/upper.txt"]
2016-01-14 16:52:44,053 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2016-01-14 16:52:44,053 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testJoinerClosure/cogroup"]
2016-01-14 16:52:44,053 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] parallel execution of steps is enabled: false
2016-01-14 16:52:44,054 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executing total steps: 1
2016-01-14 16:52:44,054 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] allocating management threads: 1
2016-01-14 16:52:44,054 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] starting step: (1/1) ...testJoinerClosure/cogroup
2016-01-14 16:52:44,097 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] submitted hadoop job: job_local_0004
2016-01-14 16:52:44,098 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] tracking url: http://localhost:8080/
2016-01-14 16:52:44,103 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lower.txt
2016-01-14 16:52:44,201 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 16:52:44,201 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 16:52:44,211 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B29CD046CE9A417ABFBADED9FBBB2396, ordinal: 0
2016-01-14 16:52:44,212 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lower.txt"]
2016-01-14 16:52:44,212 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-01-14 16:52:44,213 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B29CD046CE9A417ABFBADED9FBBB2396, mem on start (mb), free: 91, total: 509, max: 672
2016-01-14 16:52:44,215 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B29CD046CE9A417ABFBADED9FBBB2396, mem on close (mb), free: 91, total: 509, max: 672
2016-01-14 16:52:47,105 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/upper.txt
2016-01-14 16:52:47,200 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 16:52:47,200 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 16:52:47,209 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B29CD046CE9A417ABFBADED9FBBB2396, ordinal: 0
2016-01-14 16:52:47,210 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/upper.txt"]
2016-01-14 16:52:47,210 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-01-14 16:52:47,210 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B29CD046CE9A417ABFBADED9FBBB2396, mem on start (mb), free: 53, total: 572, max: 672
2016-01-14 16:52:47,212 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B29CD046CE9A417ABFBADED9FBBB2396, mem on close (mb), free: 53, total: 572, max: 672
2016-01-14 16:52:50,113 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 16:52:50,113 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 16:52:50,122 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: C1ED5A8EBAF947F2A0E375D39ED58FD8, ordinal: 1
2016-01-14 16:52:50,123 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-01-14 16:52:50,123 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testJoinerClosure/cogroup"]
2016-01-14 16:52:50,123 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C1ED5A8EBAF947F2A0E375D39ED58FD8, mem on start (mb), free: 52, total: 572, max: 672
2016-01-14 16:52:50,133 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 16:52:50,134 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-01-14 16:52:50,140 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C1ED5A8EBAF947F2A0E375D39ED58FD8, mem on close (mb), free: 51, total: 572, max: 672
2016-01-14 16:52:53,116 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testJoinerClosure/cogroup/_temporary
2016-01-14 16:52:53,117 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] completed in: 00:09.064
2016-01-14 16:52:53,136 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/bufferpipesplatform/testJoinerClosure/cogroup
2016-01-14 16:52:53,147 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:52:53,148 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 16:52:53,196 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.043
2016-01-14 16:52:53,197 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:52:53,198 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:52:53,216 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 16:52:53,216 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2016-01-14 16:52:53,216 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer2/simple2"]
2016-01-14 16:52:53,218 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 16:52:53,218 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 16:52:53,218 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 16:52:53,220 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...testSimpleBuffer2/simple2
2016-01-14 16:52:53,257 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local_0005
2016-01-14 16:52:53,258 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 16:52:53,263 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt
2016-01-14 16:52:53,506 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 16:52:53,507 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 16:52:53,515 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F992B04D920049B28E554D71F8F7E492, ordinal: 0
2016-01-14 16:52:53,515 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2016-01-14 16:52:53,516 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-01-14 16:52:53,516 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F992B04D920049B28E554D71F8F7E492, mem on start (mb), free: 140, total: 247, max: 672
2016-01-14 16:52:53,520 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F992B04D920049B28E554D71F8F7E492, mem on close (mb), free: 140, total: 247, max: 672
2016-01-14 16:52:56,267 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 16:52:56,267 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 16:52:56,279 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: CD79913B8C9A49609FBFE7F8244DFA77, ordinal: 1
2016-01-14 16:52:56,280 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-01-14 16:52:56,280 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer2/simple2"]
2016-01-14 16:52:56,280 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CD79913B8C9A49609FBFE7F8244DFA77, mem on start (mb), free: 139, total: 247, max: 672
2016-01-14 16:52:56,286 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: CD79913B8C9A49609FBFE7F8244DFA77, mem on close (mb), free: 139, total: 247, max: 672
2016-01-14 16:52:59,272 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer2/simple2/_temporary
2016-01-14 16:52:59,272 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:06.055
2016-01-14 16:52:59,298 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/bufferpipesplatform/testSimpleBuffer2/simple2
2016-01-14 16:52:59,312 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:52:59,313 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 16:52:59,362 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.044
2016-01-14 16:52:59,365 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:52:59,365 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:52:59,387 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 16:52:59,388 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lower+upper.txt"]
2016-01-14 16:52:59,388 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer3/simple3"]
2016-01-14 16:52:59,391 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 16:52:59,391 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 16:52:59,391 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 16:52:59,393 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...testSimpleBuffer3/simple3
2016-01-14 16:52:59,466 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local_0006
2016-01-14 16:52:59,468 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 16:52:59,474 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lower+upper.txt
2016-01-14 16:52:59,573 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 16:52:59,573 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 16:52:59,581 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F9760293C73445B6B0DFF56811DBF1AA, ordinal: 0
2016-01-14 16:52:59,582 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lower+upper.txt"]
2016-01-14 16:52:59,582 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-01-14 16:52:59,582 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F9760293C73445B6B0DFF56811DBF1AA, mem on start (mb), free: 123, total: 343, max: 672
2016-01-14 16:52:59,586 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F9760293C73445B6B0DFF56811DBF1AA, mem on close (mb), free: 123, total: 343, max: 672
2016-01-14 16:53:02,477 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 16:53:02,478 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 16:53:02,485 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A47FE813FFA143BE9481C3DD0BC04CA3, ordinal: 1
2016-01-14 16:53:02,486 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-01-14 16:53:02,487 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer3/simple3"]
2016-01-14 16:53:02,487 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A47FE813FFA143BE9481C3DD0BC04CA3, mem on start (mb), free: 122, total: 343, max: 672
2016-01-14 16:53:02,491 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A47FE813FFA143BE9481C3DD0BC04CA3, mem on close (mb), free: 121, total: 343, max: 672
2016-01-14 16:53:05,482 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer3/simple3/_temporary
2016-01-14 16:53:05,482 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:06.094
2016-01-14 16:53:05,499 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/bufferpipesplatform/testSimpleBuffer3/simple3
2016-01-14 16:53:05,507 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:53:05,508 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 16:53:05,543 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.032
2016-01-14 16:53:05,546 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:53:05,546 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:53:05,562 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 16:53:05,562 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2016-01-14 16:53:05,562 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn"]
2016-01-14 16:53:05,562 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 16:53:05,562 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 16:53:05,563 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 16:53:05,563 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...irstNBufferReverse/firstn
2016-01-14 16:53:05,598 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local_0007
2016-01-14 16:53:05,598 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 16:53:05,602 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt
2016-01-14 16:53:05,699 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 16:53:05,699 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 16:53:05,709 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FECF5F15D72444129D5BDAC99E09912C, ordinal: 0
2016-01-14 16:53:05,710 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2016-01-14 16:53:05,710 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-01-14 16:53:05,711 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FECF5F15D72444129D5BDAC99E09912C, mem on start (mb), free: 106, total: 438, max: 672
2016-01-14 16:53:05,714 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FECF5F15D72444129D5BDAC99E09912C, mem on close (mb), free: 106, total: 438, max: 672
2016-01-14 16:53:08,606 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 16:53:08,607 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 16:53:08,615 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: AFE6C10024DF4170B73C9FC519377E23, ordinal: 1
2016-01-14 16:53:08,616 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-01-14 16:53:08,616 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn"]
2016-01-14 16:53:08,616 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AFE6C10024DF4170B73C9FC519377E23, mem on start (mb), free: 105, total: 438, max: 672
2016-01-14 16:53:08,621 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AFE6C10024DF4170B73C9FC519377E23, mem on close (mb), free: 105, total: 438, max: 672
2016-01-14 16:53:11,615 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn/_temporary
2016-01-14 16:53:11,616 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:06.053
2016-01-14 16:53:11,630 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn
2016-01-14 16:53:11,648 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:53:11,648 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 16:53:11,671 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: ILLEGAL, in: 00:00.020
2016-01-14 16:53:11,672 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, found assembly to be malformed
2016-01-14 16:53:11,687 INFO util.Util (Util.java:findMainClass(1327)) - using default application jar, may cause class not found exceptions on the cluster
2016-01-14 16:53:11,688 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 16:53:11,733 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.039
2016-01-14 16:53:11,734 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-01-14 16:53:11,734 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-01-14 16:53:11,749 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting
2016-01-14 16:53:11,750 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2016-01-14 16:53:11,750 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testFirstNBuffer/firstn"]
2016-01-14 16:53:11,750 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] parallel execution of steps is enabled: false
2016-01-14 16:53:11,750 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] executing total steps: 1
2016-01-14 16:53:11,750 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] allocating management threads: 1
2016-01-14 16:53:11,752 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] starting step: (1/1) ...m/testFirstNBuffer/firstn
2016-01-14 16:53:11,782 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] submitted hadoop job: job_local_0008
2016-01-14 16:53:11,782 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] tracking url: http://localhost:8080/
2016-01-14 16:53:11,788 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt
2016-01-14 16:53:11,893 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.0.4
2016-01-14 16:53:11,894 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-01-14 16:53:11,900 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AD307CA67F1449008D17CD2E1445EDBC, ordinal: 0
2016-01-14 16:53:11,900 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/classes/test/data/lhs.txt"]
2016-01-14 16:53:11,901 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-01-14 16:53:11,901 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AD307CA67F1449008D17CD2E1445EDBC, mem on start (mb), free: 136, total: 534, max: 672
2016-01-14 16:53:11,904 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AD307CA67F1449008D17CD2E1445EDBC, mem on close (mb), free: 136, total: 534, max: 672
2016-01-14 16:53:14,791 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.0.4
2016-01-14 16:53:14,792 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-01-14 16:53:14,799 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: BF20996990484B19828BB6DCFD0A141C, ordinal: 1
2016-01-14 16:53:14,799 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-01-14 16:53:14,799 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testFirstNBuffer/firstn"]
2016-01-14 16:53:14,799 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BF20996990484B19828BB6DCFD0A141C, mem on start (mb), free: 135, total: 534, max: 672
2016-01-14 16:53:14,804 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BF20996990484B19828BB6DCFD0A141C, mem on close (mb), free: 135, total: 534, max: 672
2016-01-14 16:53:17,798 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output/hadoop/bufferpipesplatform/testFirstNBuffer/firstn/_temporary
2016-01-14 16:53:17,799 INFO flow.Flow (BaseFlow.java:logInfo(1433)) - [test] completed in: 00:06.049
2016-01-14 16:53:17,814 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/d1e2e77517c04a30/apache-0.20.205.0/build/test/output//hadoop/bufferpipesplatform/testFirstNBuffer/firstn