2016-05-18 08:04:16,473 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 08:04:16,495 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.BufferPipesPlatformTest, with platform: hadoop2-mr1
2016-05-18 08:04:16,523 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-05-18 08:04:17,303 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-05-18 08:04:17,507 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 08:04:17,647 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:04:17,650 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:04:17,748 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 727EF2DAB2064F9DBE61BCB7C4BD6602
2016-05-18 08:04:17,941 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.136
2016-05-18 08:04:17,944 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 08:04:17,944 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:04:18,106 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 08:04:18,107 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 08:04:18,108 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt"]
2016-05-18 08:04:18,108 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testIdentityBuffer/identity"]
2016-05-18 08:04:18,109 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 08:04:18,111 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 08:04:18,111 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 08:04:18,112 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...stIdentityBuffer/identity
2016-05-18 08:04:18,866 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local938328459_0001
2016-05-18 08:04:18,866 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 08:04:18,945 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt
2016-05-18 08:04:19,101 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:04:19,102 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:04:19,114 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F983720A6DA1476F9475099816ED421D, ordinal: 0
2016-05-18 08:04:19,149 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt"]
2016-05-18 08:04:19,149 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 08:04:19,150 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F983720A6DA1476F9475099816ED421D, mem on start (mb), free: 119, total: 281, max: 672
2016-05-18 08:04:19,160 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F983720A6DA1476F9475099816ED421D, mem on close (mb), free: 119, total: 281, max: 672
2016-05-18 08:04:19,249 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 08:04:19,250 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 08:04:19,262 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D4314A3FFB27458C966C87D28B2124EA, ordinal: 1
2016-05-18 08:04:19,266 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 08:04:19,266 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testIdentityBuffer/identity"]
2016-05-18 08:04:19,266 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D4314A3FFB27458C966C87D28B2124EA, mem on start (mb), free: 107, total: 281, max: 672
2016-05-18 08:04:19,285 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D4314A3FFB27458C966C87D28B2124EA, mem on close (mb), free: 106, total: 281, max: 672
2016-05-18 08:04:19,329 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testIdentityBuffer/identity/_temporary
2016-05-18 08:04:19,330 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:01.221
2016-05-18 08:04:19,415 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testIdentityBuffer/identity
2016-05-18 08:04:19,451 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:04:19,451 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:04:19,525 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.062
2016-05-18 08:04:19,526 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 08:04:19,526 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:04:19,558 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 08:04:19,558 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt"]
2016-05-18 08:04:19,559 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBufferForward/firstn"]
2016-05-18 08:04:19,559 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 08:04:19,560 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 08:04:19,560 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 08:04:19,561 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...irstNBufferForward/firstn
2016-05-18 08:04:19,747 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1420173912_0002
2016-05-18 08:04:19,748 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 08:04:19,756 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt
2016-05-18 08:04:19,782 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:04:19,783 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:04:19,791 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D638670D08B4445493E1B8781E3DCF16, ordinal: 0
2016-05-18 08:04:19,792 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt"]
2016-05-18 08:04:19,792 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 08:04:19,792 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D638670D08B4445493E1B8781E3DCF16, mem on start (mb), free: 58, total: 281, max: 672
2016-05-18 08:04:19,795 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D638670D08B4445493E1B8781E3DCF16, mem on close (mb), free: 58, total: 281, max: 672
2016-05-18 08:04:19,814 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 08:04:19,816 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 08:04:19,826 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: C8837AF4A2C74536832E321C59F5BCF2, ordinal: 1
2016-05-18 08:04:19,827 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 08:04:19,827 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBufferForward/firstn"]
2016-05-18 08:04:19,827 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C8837AF4A2C74536832E321C59F5BCF2, mem on start (mb), free: 54, total: 281, max: 672
2016-05-18 08:04:19,839 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C8837AF4A2C74536832E321C59F5BCF2, mem on close (mb), free: 53, total: 281, max: 672
2016-05-18 08:04:19,876 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBufferForward/firstn/_temporary
2016-05-18 08:04:19,877 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.318
2016-05-18 08:04:19,965 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testFirstNBufferForward/firstn
2016-05-18 08:04:19,990 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:04:19,991 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:04:20,084 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.082
2016-05-18 08:04:20,086 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 08:04:20,087 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:04:20,121 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 08:04:20,121 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt"]
2016-05-18 08:04:20,122 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer/simple"]
2016-05-18 08:04:20,123 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 08:04:20,123 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 08:04:20,123 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 08:04:20,124 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...m/testSimpleBuffer/simple
2016-05-18 08:04:20,339 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local777284822_0003
2016-05-18 08:04:20,343 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 08:04:20,352 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt
2016-05-18 08:04:20,398 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:04:20,398 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:04:20,406 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E0690C5E105D48F38AEF26F251689FCA, ordinal: 0
2016-05-18 08:04:20,407 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt"]
2016-05-18 08:04:20,407 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 08:04:20,408 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E0690C5E105D48F38AEF26F251689FCA, mem on start (mb), free: 116, total: 397, max: 672
2016-05-18 08:04:20,410 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E0690C5E105D48F38AEF26F251689FCA, mem on close (mb), free: 116, total: 397, max: 672
2016-05-18 08:04:20,429 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 08:04:20,429 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 08:04:20,441 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F78492DEFC4D423B8AA630BC2AB712D8, ordinal: 1
2016-05-18 08:04:20,442 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 08:04:20,443 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer/simple"]
2016-05-18 08:04:20,443 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F78492DEFC4D423B8AA630BC2AB712D8, mem on start (mb), free: 108, total: 397, max: 672
2016-05-18 08:04:20,453 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F78492DEFC4D423B8AA630BC2AB712D8, mem on close (mb), free: 107, total: 397, max: 672
2016-05-18 08:04:20,477 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer/simple/_temporary
2016-05-18 08:04:20,478 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.356
2016-05-18 08:04:20,542 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testSimpleBuffer/simple
2016-05-18 08:04:20,567 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:04:20,567 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:04:20,637 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.064
2016-05-18 08:04:20,639 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 08:04:20,639 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:04:20,668 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting
2016-05-18 08:04:20,668 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/upper.txt"]
2016-05-18 08:04:20,669 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lower.txt"]
2016-05-18 08:04:20,669 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testJoinerClosure/cogroup"]
2016-05-18 08:04:20,670 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] parallel execution of steps is enabled: false
2016-05-18 08:04:20,670 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executing total steps: 1
2016-05-18 08:04:20,671 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] allocating management threads: 1
2016-05-18 08:04:20,671 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting step: (1/1) ...testJoinerClosure/cogroup
2016-05-18 08:04:20,831 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] submitted hadoop job: job_local613666006_0004
2016-05-18 08:04:20,831 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] tracking url: http://localhost:8080/
2016-05-18 08:04:20,838 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lower.txt
2016-05-18 08:04:20,855 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:04:20,855 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:04:20,864 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A87A364FB18D45A8B3DC332B11D187DC, ordinal: 0
2016-05-18 08:04:20,865 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lower.txt"]
2016-05-18 08:04:20,865 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 08:04:20,866 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A87A364FB18D45A8B3DC332B11D187DC, mem on start (mb), free: 167, total: 397, max: 672
2016-05-18 08:04:20,867 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A87A364FB18D45A8B3DC332B11D187DC, mem on close (mb), free: 167, total: 397, max: 672
2016-05-18 08:04:20,875 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/upper.txt
2016-05-18 08:04:20,912 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:04:20,913 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:04:20,925 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A87A364FB18D45A8B3DC332B11D187DC, ordinal: 0
2016-05-18 08:04:20,925 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/upper.txt"]
2016-05-18 08:04:20,926 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 08:04:20,926 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A87A364FB18D45A8B3DC332B11D187DC, mem on start (mb), free: 65, total: 397, max: 672
2016-05-18 08:04:20,928 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A87A364FB18D45A8B3DC332B11D187DC, mem on close (mb), free: 65, total: 397, max: 672
2016-05-18 08:04:20,948 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 08:04:20,948 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 08:04:20,956 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A9D466692B74463BA9D2A0966155C445, ordinal: 1
2016-05-18 08:04:20,957 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 08:04:20,958 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testJoinerClosure/cogroup"]
2016-05-18 08:04:20,958 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A9D466692B74463BA9D2A0966155C445, mem on start (mb), free: 57, total: 397, max: 672
2016-05-18 08:04:20,972 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 08:04:20,973 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 08:04:20,979 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A9D466692B74463BA9D2A0966155C445, mem on close (mb), free: 54, total: 397, max: 672
2016-05-18 08:04:21,015 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testJoinerClosure/cogroup/_temporary
2016-05-18 08:04:21,016 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] completed in: 00:00.347
2016-05-18 08:04:21,068 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testJoinerClosure/cogroup
2016-05-18 08:04:21,087 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:04:21,087 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:04:21,132 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.040
2016-05-18 08:04:21,134 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 08:04:21,134 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:04:21,157 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 08:04:21,157 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt"]
2016-05-18 08:04:21,157 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer2/simple2"]
2016-05-18 08:04:21,158 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 08:04:21,158 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 08:04:21,158 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 08:04:21,160 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...testSimpleBuffer2/simple2
2016-05-18 08:04:21,270 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local2096429651_0005
2016-05-18 08:04:21,271 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 08:04:21,280 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt
2016-05-18 08:04:21,295 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:04:21,295 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:04:21,303 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A5307E18EC5F4D10875A29700D379F34, ordinal: 0
2016-05-18 08:04:21,305 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt"]
2016-05-18 08:04:21,305 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 08:04:21,305 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A5307E18EC5F4D10875A29700D379F34, mem on start (mb), free: 116, total: 392, max: 672
2016-05-18 08:04:21,308 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A5307E18EC5F4D10875A29700D379F34, mem on close (mb), free: 116, total: 392, max: 672
2016-05-18 08:04:21,323 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 08:04:21,323 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 08:04:21,331 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D631B839AD2F4710B19B25FD06810553, ordinal: 1
2016-05-18 08:04:21,331 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 08:04:21,332 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer2/simple2"]
2016-05-18 08:04:21,332 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D631B839AD2F4710B19B25FD06810553, mem on start (mb), free: 108, total: 392, max: 672
2016-05-18 08:04:21,340 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D631B839AD2F4710B19B25FD06810553, mem on close (mb), free: 107, total: 392, max: 672
2016-05-18 08:04:21,368 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer2/simple2/_temporary
2016-05-18 08:04:21,369 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.210
2016-05-18 08:04:21,424 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testSimpleBuffer2/simple2
2016-05-18 08:04:21,447 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:04:21,447 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:04:21,496 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.043
2016-05-18 08:04:21,497 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 08:04:21,498 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:04:21,513 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 08:04:21,513 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 08:04:21,514 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer3/simple3"]
2016-05-18 08:04:21,514 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 08:04:21,514 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 08:04:21,514 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 08:04:21,514 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...testSimpleBuffer3/simple3
2016-05-18 08:04:21,628 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1136880758_0006
2016-05-18 08:04:21,629 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 08:04:21,633 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lower+upper.txt
2016-05-18 08:04:21,647 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:04:21,647 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:04:21,653 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DBEA5F17BEBD4AC5900100EED3893E23, ordinal: 0
2016-05-18 08:04:21,654 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 08:04:21,654 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 08:04:21,654 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DBEA5F17BEBD4AC5900100EED3893E23, mem on start (mb), free: 161, total: 388, max: 672
2016-05-18 08:04:21,656 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DBEA5F17BEBD4AC5900100EED3893E23, mem on close (mb), free: 161, total: 388, max: 672
2016-05-18 08:04:21,672 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 08:04:21,672 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 08:04:21,679 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E9977F088417449D94D66BD501CC3670, ordinal: 1
2016-05-18 08:04:21,680 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 08:04:21,680 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer3/simple3"]
2016-05-18 08:04:21,680 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E9977F088417449D94D66BD501CC3670, mem on start (mb), free: 153, total: 388, max: 672
2016-05-18 08:04:21,688 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E9977F088417449D94D66BD501CC3670, mem on close (mb), free: 152, total: 388, max: 672
2016-05-18 08:04:21,708 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer3/simple3/_temporary
2016-05-18 08:04:21,709 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.195
2016-05-18 08:04:21,756 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testSimpleBuffer3/simple3
2016-05-18 08:04:21,772 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:04:21,773 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:04:21,817 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.040
2016-05-18 08:04:21,817 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 08:04:21,818 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:04:21,839 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 08:04:21,839 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt"]
2016-05-18 08:04:21,839 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBufferReverse/firstn"]
2016-05-18 08:04:21,839 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 08:04:21,840 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 08:04:21,840 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 08:04:21,840 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...irstNBufferReverse/firstn
2016-05-18 08:04:21,934 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1445552249_0007
2016-05-18 08:04:21,934 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 08:04:21,939 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt
2016-05-18 08:04:21,960 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:04:21,961 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:04:21,968 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C1CA915C0B804DFD9BE6AD368BDE409E, ordinal: 0
2016-05-18 08:04:21,969 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt"]
2016-05-18 08:04:21,969 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 08:04:21,969 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C1CA915C0B804DFD9BE6AD368BDE409E, mem on start (mb), free: 181, total: 393, max: 672
2016-05-18 08:04:21,971 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C1CA915C0B804DFD9BE6AD368BDE409E, mem on close (mb), free: 181, total: 393, max: 672
2016-05-18 08:04:21,986 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 08:04:21,987 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 08:04:21,993 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: EE10F14FFFC148E3B05414EB0C34E4BC, ordinal: 1
2016-05-18 08:04:21,993 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 08:04:21,994 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBufferReverse/firstn"]
2016-05-18 08:04:21,994 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: EE10F14FFFC148E3B05414EB0C34E4BC, mem on start (mb), free: 174, total: 393, max: 672
2016-05-18 08:04:22,005 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: EE10F14FFFC148E3B05414EB0C34E4BC, mem on close (mb), free: 172, total: 393, max: 672
2016-05-18 08:04:22,024 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBufferReverse/firstn/_temporary
2016-05-18 08:04:22,025 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.185
2016-05-18 08:04:22,074 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testFirstNBufferReverse/firstn
2016-05-18 08:04:22,091 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:04:22,091 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:04:22,114 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: ILLEGAL, in: 00:00.019
2016-05-18 08:04:22,115 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, found assembly to be malformed
2016-05-18 08:04:22,131 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 08:04:22,131 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/3.1.0/fdadb6ac788ea19f3412b9569a43a7635318b0c5/cascading-hadoop2-mr1-3.1.0.jar
2016-05-18 08:04:22,169 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.033
2016-05-18 08:04:22,170 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 08:04:22,170 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, result was selected using: 'default comparator: selects plan with fewest steps and fewest nodes'
2016-05-18 08:04:22,190 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 08:04:22,190 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt"]
2016-05-18 08:04:22,191 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBuffer/firstn"]
2016-05-18 08:04:22,191 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 08:04:22,191 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 08:04:22,191 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 08:04:22,193 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...m/testFirstNBuffer/firstn
2016-05-18 08:04:22,297 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1580392496_0008
2016-05-18 08:04:22,297 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 08:04:22,303 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt
2016-05-18 08:04:22,323 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 08:04:22,324 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 08:04:22,330 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B760AF6A469A47C58CC40A8CB6F1F622, ordinal: 0
2016-05-18 08:04:22,330 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/classes/test/data/lhs.txt"]
2016-05-18 08:04:22,330 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 08:04:22,330 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B760AF6A469A47C58CC40A8CB6F1F622, mem on start (mb), free: 170, total: 383, max: 672
2016-05-18 08:04:22,332 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B760AF6A469A47C58CC40A8CB6F1F622, mem on close (mb), free: 170, total: 383, max: 672
2016-05-18 08:04:22,346 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 08:04:22,347 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 08:04:22,353 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B4CA8889E4114ABF9163AAB7A42FDC71, ordinal: 1
2016-05-18 08:04:22,353 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 08:04:22,354 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBuffer/firstn"]
2016-05-18 08:04:22,354 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B4CA8889E4114ABF9163AAB7A42FDC71, mem on start (mb), free: 163, total: 383, max: 672
2016-05-18 08:04:22,361 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B4CA8889E4114ABF9163AAB7A42FDC71, mem on close (mb), free: 162, total: 383, max: 672
2016-05-18 08:04:22,377 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBuffer/firstn/_temporary
2016-05-18 08:04:22,377 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.186
2016-05-18 08:04:22,422 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.6.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testFirstNBuffer/firstn