2016-05-18 11:11:16,346 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 11:11:16,366 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.BufferPipesPlatformTest, with platform: hadoop2-mr1
2016-05-18 11:11:16,389 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(119)) - not using cluster
2016-05-18 11:11:17,050 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 11:11:17,180 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 11:11:17,295 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 11:11:17,297 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 11:11:17,372 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: ADEA2A4CED90499AA26CDA492D5EBD3C
2016-05-18 11:11:17,549 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.107
2016-05-18 11:11:17,552 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 11:11:17,553 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 11:11:17,701 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 11:11:17,702 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 11:11:17,703 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.7.x/build/classes/test/data/lhs.txt"]
2016-05-18 11:11:17,703 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testIdentityBuffer/identity"]
2016-05-18 11:11:17,704 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 11:11:17,705 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 11:11:17,705 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 11:11:17,706 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...stIdentityBuffer/identity
2016-05-18 11:11:18,423 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local301096112_0001
2016-05-18 11:11:18,423 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 11:11:18,511 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lhs.txt
2016-05-18 11:11:18,660 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 11:11:18,660 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 11:11:18,671 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FD995267CCB4441FBD7BA8C72CE931A7, ordinal: 0
2016-05-18 11:11:18,705 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.7.x/build/classes/test/data/lhs.txt"]
2016-05-18 11:11:18,705 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 11:11:18,706 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FD995267CCB4441FBD7BA8C72CE931A7, mem on start (mb), free: 116, total: 281, max: 672
2016-05-18 11:11:18,715 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FD995267CCB4441FBD7BA8C72CE931A7, mem on close (mb), free: 116, total: 281, max: 672
2016-05-18 11:11:18,806 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 11:11:18,806 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 11:11:18,818 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: C073DF3DE5EF418A93758E4324E79AD9, ordinal: 1
2016-05-18 11:11:18,822 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 11:11:18,822 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testIdentityBuffer/identity"]
2016-05-18 11:11:18,822 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C073DF3DE5EF418A93758E4324E79AD9, mem on start (mb), free: 104, total: 281, max: 672
2016-05-18 11:11:18,847 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C073DF3DE5EF418A93758E4324E79AD9, mem on close (mb), free: 102, total: 281, max: 672
2016-05-18 11:11:18,882 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testIdentityBuffer/identity/_temporary
2016-05-18 11:11:18,882 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:01.178
2016-05-18 11:11:18,969 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testIdentityBuffer/identity
2016-05-18 11:11:19,005 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 11:11:19,005 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 11:11:19,083 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.067
2016-05-18 11:11:19,085 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 11:11:19,085 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 11:11:19,118 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 11:11:19,119 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lhs.txt"]
2016-05-18 11:11:19,119 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBufferForward/firstn"]
2016-05-18 11:11:19,119 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 11:11:19,119 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 11:11:19,120 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 11:11:19,120 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...irstNBufferForward/firstn
2016-05-18 11:11:19,308 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local957108135_0002
2016-05-18 11:11:19,309 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 11:11:19,314 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lhs.txt
2016-05-18 11:11:19,418 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 11:11:19,418 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 11:11:19,428 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: F3ABB1A882084D4D91C35B7B2D8D8845, ordinal: 0
2016-05-18 11:11:19,429 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lhs.txt"]
2016-05-18 11:11:19,429 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 11:11:19,429 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F3ABB1A882084D4D91C35B7B2D8D8845, mem on start (mb), free: 150, total: 382, max: 672
2016-05-18 11:11:19,433 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: F3ABB1A882084D4D91C35B7B2D8D8845, mem on close (mb), free: 150, total: 382, max: 672
2016-05-18 11:11:19,450 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 11:11:19,451 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 11:11:19,470 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: C2C9ECFE51E0443F80A10BB0A140CB41, ordinal: 1
2016-05-18 11:11:19,471 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 11:11:19,472 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBufferForward/firstn"]
2016-05-18 11:11:19,472 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C2C9ECFE51E0443F80A10BB0A140CB41, mem on start (mb), free: 146, total: 382, max: 672
2016-05-18 11:11:19,485 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C2C9ECFE51E0443F80A10BB0A140CB41, mem on close (mb), free: 145, total: 382, max: 672
2016-05-18 11:11:19,510 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBufferForward/firstn/_temporary
2016-05-18 11:11:19,511 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.392
2016-05-18 11:11:19,602 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testFirstNBufferForward/firstn
2016-05-18 11:11:19,639 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 11:11:19,639 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 11:11:19,739 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.088
2016-05-18 11:11:19,741 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 11:11:19,742 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 11:11:19,775 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 11:11:19,775 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.7.x/build/classes/test/data/lhs.txt"]
2016-05-18 11:11:19,776 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer/simple"]
2016-05-18 11:11:19,776 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 11:11:19,776 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 11:11:19,777 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 11:11:19,778 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...m/testSimpleBuffer/simple
2016-05-18 11:11:20,015 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1540923585_0003
2016-05-18 11:11:20,016 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 11:11:20,022 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lhs.txt
2016-05-18 11:11:20,117 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 11:11:20,117 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 11:11:20,125 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CAD37AF759D3439FA4D28CE2A1BA3434, ordinal: 0
2016-05-18 11:11:20,125 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.7.x/build/classes/test/data/lhs.txt"]
2016-05-18 11:11:20,126 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 11:11:20,126 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CAD37AF759D3439FA4D28CE2A1BA3434, mem on start (mb), free: 83, total: 482, max: 672
2016-05-18 11:11:20,128 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CAD37AF759D3439FA4D28CE2A1BA3434, mem on close (mb), free: 83, total: 482, max: 672
2016-05-18 11:11:20,145 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 11:11:20,145 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 11:11:20,156 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: C8261BF81D444BE29505B0CA5CD9C4EB, ordinal: 1
2016-05-18 11:11:20,156 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 11:11:20,157 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer/simple"]
2016-05-18 11:11:20,157 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C8261BF81D444BE29505B0CA5CD9C4EB, mem on start (mb), free: 78, total: 482, max: 672
2016-05-18 11:11:20,171 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C8261BF81D444BE29505B0CA5CD9C4EB, mem on close (mb), free: 77, total: 482, max: 672
2016-05-18 11:11:20,199 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer/simple/_temporary
2016-05-18 11:11:20,199 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.424
2016-05-18 11:11:20,264 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testSimpleBuffer/simple
2016-05-18 11:11:20,290 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 11:11:20,291 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 11:11:20,359 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.063
2016-05-18 11:11:20,361 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 11:11:20,361 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 11:11:20,413 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting
2016-05-18 11:11:20,413 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/upper.txt"]
2016-05-18 11:11:20,414 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lower.txt"]
2016-05-18 11:11:20,414 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testJoinerClosure/cogroup"]
2016-05-18 11:11:20,415 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] parallel execution of steps is enabled: false
2016-05-18 11:11:20,415 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executing total steps: 1
2016-05-18 11:11:20,415 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] allocating management threads: 1
2016-05-18 11:11:20,416 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting step: (1/1) ...testJoinerClosure/cogroup
2016-05-18 11:11:20,549 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] submitted hadoop job: job_local871614504_0004
2016-05-18 11:11:20,550 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] tracking url: http://localhost:8080/
2016-05-18 11:11:20,557 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lower.txt
2016-05-18 11:11:20,591 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 11:11:20,592 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 11:11:20,601 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E7E603C13C52463B877A7AAC9CE3B7A6, ordinal: 0
2016-05-18 11:11:20,602 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lower.txt"]
2016-05-18 11:11:20,602 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 11:11:20,603 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E7E603C13C52463B877A7AAC9CE3B7A6, mem on start (mb), free: 137, total: 598, max: 672
2016-05-18 11:11:20,605 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E7E603C13C52463B877A7AAC9CE3B7A6, mem on close (mb), free: 137, total: 598, max: 672
2016-05-18 11:11:20,614 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/upper.txt
2016-05-18 11:11:20,645 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 11:11:20,647 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 11:11:20,661 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E7E603C13C52463B877A7AAC9CE3B7A6, ordinal: 0
2016-05-18 11:11:20,662 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/upper.txt"]
2016-05-18 11:11:20,662 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 11:11:20,663 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E7E603C13C52463B877A7AAC9CE3B7A6, mem on start (mb), free: 185, total: 596, max: 672
2016-05-18 11:11:20,666 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E7E603C13C52463B877A7AAC9CE3B7A6, mem on close (mb), free: 185, total: 596, max: 672
2016-05-18 11:11:20,686 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 11:11:20,686 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 11:11:20,694 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A615CA88713345CF976CA8E2EB0F7142, ordinal: 1
2016-05-18 11:11:20,695 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 11:11:20,695 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testJoinerClosure/cogroup"]
2016-05-18 11:11:20,696 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A615CA88713345CF976CA8E2EB0F7142, mem on start (mb), free: 178, total: 596, max: 672
2016-05-18 11:11:20,712 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 11:11:20,712 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 11:11:20,719 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A615CA88713345CF976CA8E2EB0F7142, mem on close (mb), free: 176, total: 596, max: 672
2016-05-18 11:11:20,746 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testJoinerClosure/cogroup/_temporary
2016-05-18 11:11:20,746 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] completed in: 00:00.333
2016-05-18 11:11:20,802 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testJoinerClosure/cogroup
2016-05-18 11:11:20,823 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 11:11:20,824 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 11:11:20,868 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.039
2016-05-18 11:11:20,869 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 11:11:20,869 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 11:11:20,888 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 11:11:20,889 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.7.x/build/classes/test/data/lhs.txt"]
2016-05-18 11:11:20,890 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer2/simple2"]
2016-05-18 11:11:20,890 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 11:11:20,890 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 11:11:20,890 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 11:11:20,892 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...testSimpleBuffer2/simple2
2016-05-18 11:11:21,033 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1499190331_0005
2016-05-18 11:11:21,034 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 11:11:21,041 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lhs.txt
2016-05-18 11:11:21,072 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 11:11:21,072 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 11:11:21,083 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D652621ACABD431B93E9DC5A57B5FA35, ordinal: 0
2016-05-18 11:11:21,083 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.7.x/build/classes/test/data/lhs.txt"]
2016-05-18 11:11:21,084 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 11:11:21,084 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D652621ACABD431B93E9DC5A57B5FA35, mem on start (mb), free: 187, total: 597, max: 672
2016-05-18 11:11:21,087 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D652621ACABD431B93E9DC5A57B5FA35, mem on close (mb), free: 187, total: 597, max: 672
2016-05-18 11:11:21,112 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 11:11:21,113 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 11:11:21,126 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B0A479D112F24FF1AD55570751EDEC3C, ordinal: 1
2016-05-18 11:11:21,127 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 11:11:21,127 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer2/simple2"]
2016-05-18 11:11:21,127 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B0A479D112F24FF1AD55570751EDEC3C, mem on start (mb), free: 179, total: 597, max: 672
2016-05-18 11:11:21,138 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B0A479D112F24FF1AD55570751EDEC3C, mem on close (mb), free: 176, total: 597, max: 672
2016-05-18 11:11:21,161 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer2/simple2/_temporary
2016-05-18 11:11:21,161 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.272
2016-05-18 11:11:21,216 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testSimpleBuffer2/simple2
2016-05-18 11:11:21,233 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 11:11:21,233 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 11:11:21,272 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.035
2016-05-18 11:11:21,273 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 11:11:21,273 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 11:11:21,288 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 11:11:21,289 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.7.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 11:11:21,289 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer3/simple3"]
2016-05-18 11:11:21,290 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 11:11:21,290 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 11:11:21,290 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 11:11:21,291 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...testSimpleBuffer3/simple3
2016-05-18 11:11:21,404 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local475811355_0006
2016-05-18 11:11:21,404 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 11:11:21,409 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lower+upper.txt
2016-05-18 11:11:21,437 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 11:11:21,438 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 11:11:21,444 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E8C9EAB335DE410CBBDB85057E063B58, ordinal: 0
2016-05-18 11:11:21,445 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.7.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 11:11:21,445 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 11:11:21,445 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E8C9EAB335DE410CBBDB85057E063B58, mem on start (mb), free: 179, total: 589, max: 672
2016-05-18 11:11:21,447 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E8C9EAB335DE410CBBDB85057E063B58, mem on close (mb), free: 179, total: 589, max: 672
2016-05-18 11:11:21,463 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 11:11:21,463 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 11:11:21,470 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: C3449AA0A62A47BF9659387C4F867966, ordinal: 1
2016-05-18 11:11:21,471 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 11:11:21,471 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer3/simple3"]
2016-05-18 11:11:21,472 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C3449AA0A62A47BF9659387C4F867966, mem on start (mb), free: 172, total: 589, max: 672
2016-05-18 11:11:21,482 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C3449AA0A62A47BF9659387C4F867966, mem on close (mb), free: 169, total: 589, max: 672
2016-05-18 11:11:21,504 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testSimpleBuffer3/simple3/_temporary
2016-05-18 11:11:21,505 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.215
2016-05-18 11:11:21,552 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testSimpleBuffer3/simple3
2016-05-18 11:11:21,572 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 11:11:21,573 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 11:11:21,610 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.032
2016-05-18 11:11:21,611 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 11:11:21,611 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 11:11:21,626 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 11:11:21,626 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lhs.txt"]
2016-05-18 11:11:21,627 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBufferReverse/firstn"]
2016-05-18 11:11:21,628 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 11:11:21,628 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 11:11:21,628 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 11:11:21,629 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...irstNBufferReverse/firstn
2016-05-18 11:11:21,741 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1266337874_0007
2016-05-18 11:11:21,741 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 11:11:21,746 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lhs.txt
2016-05-18 11:11:21,767 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 11:11:21,768 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 11:11:21,775 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E24D3E1E8123497B9F230874545FC11D, ordinal: 0
2016-05-18 11:11:21,776 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lhs.txt"]
2016-05-18 11:11:21,776 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 11:11:21,776 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E24D3E1E8123497B9F230874545FC11D, mem on start (mb), free: 185, total: 595, max: 672
2016-05-18 11:11:21,779 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E24D3E1E8123497B9F230874545FC11D, mem on close (mb), free: 185, total: 595, max: 672
2016-05-18 11:11:21,797 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 11:11:21,797 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 11:11:21,805 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DD02CFC9E3AA45FF89ACCB0F865C4478, ordinal: 1
2016-05-18 11:11:21,806 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 11:11:21,806 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBufferReverse/firstn"]
2016-05-18 11:11:21,806 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DD02CFC9E3AA45FF89ACCB0F865C4478, mem on start (mb), free: 179, total: 595, max: 672
2016-05-18 11:11:21,819 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DD02CFC9E3AA45FF89ACCB0F865C4478, mem on close (mb), free: 176, total: 595, max: 672
2016-05-18 11:11:21,845 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBufferReverse/firstn/_temporary
2016-05-18 11:11:21,845 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.218
2016-05-18 11:11:21,894 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testFirstNBufferReverse/firstn
2016-05-18 11:11:21,912 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 11:11:21,912 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 11:11:21,933 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: ILLEGAL, in: 00:00.016
2016-05-18 11:11:21,933 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, found assembly to be malformed
2016-05-18 11:11:21,950 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 11:11:21,951 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 11:11:21,984 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.029
2016-05-18 11:11:21,985 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 11:11:21,985 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 11:11:21,999 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 11:11:21,999 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lhs.txt"]
2016-05-18 11:11:21,999 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBuffer/firstn"]
2016-05-18 11:11:22,000 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 11:11:22,000 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 11:11:22,000 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 11:11:22,001 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...m/testFirstNBuffer/firstn
2016-05-18 11:11:22,123 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local452920487_0008
2016-05-18 11:11:22,123 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 11:11:22,129 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lhs.txt
2016-05-18 11:11:22,151 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 11:11:22,152 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 11:11:22,158 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: FA59D0F658854C4FB216F70604AE6787, ordinal: 0
2016-05-18 11:11:22,159 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/classes/test/data/lhs.txt"]
2016-05-18 11:11:22,159 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 11:11:22,159 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FA59D0F658854C4FB216F70604AE6787, mem on start (mb), free: 175, total: 585, max: 672
2016-05-18 11:11:22,162 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: FA59D0F658854C4FB216F70604AE6787, mem on close (mb), free: 175, total: 585, max: 672
2016-05-18 11:11:22,176 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 11:11:22,177 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 11:11:22,183 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B796CCEC33B84746B6817AB1848C10A7, ordinal: 1
2016-05-18 11:11:22,184 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 11:11:22,184 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBuffer/firstn"]
2016-05-18 11:11:22,185 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B796CCEC33B84746B6817AB1848C10A7, mem on start (mb), free: 169, total: 585, max: 672
2016-05-18 11:11:22,194 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B796CCEC33B84746B6817AB1848C10A7, mem on close (mb), free: 166, total: 585, max: 672
2016-05-18 11:11:22,214 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output/hadoop2-mr1/bufferpipesplatform/testFirstNBuffer/firstn/_temporary
2016-05-18 11:11:22,214 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.215
2016-05-18 11:11:22,262 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/9c1cc778dcd1fc2f/apache-2.7.x/build/test/output//hadoop2-mr1/bufferpipesplatform/testFirstNBuffer/firstn