2016-05-18 01:33:39,162 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 01:33:39,178 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.BufferPipesPlatformTest, with platform: hadoop
2016-05-18 01:33:39,202 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(127)) - not using cluster
2016-05-18 01:33:39,417 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 01:33:39,505 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:33:39,506 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 01:33:39,606 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 5B4689B701D043F988125224DF8E8F9A
2016-05-18 01:33:39,774 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.124
2016-05-18 01:33:39,777 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:33:39,777 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 01:33:39,970 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 01:33:39,972 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:33:39,973 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt"]
2016-05-18 01:33:39,974 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testIdentityBuffer/identity"]
2016-05-18 01:33:39,974 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:33:39,975 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:33:39,976 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:33:39,978 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...stIdentityBuffer/identity
2016-05-18 01:33:40,013 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2016-05-18 01:33:40,047 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2016-05-18 01:33:40,229 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0001
2016-05-18 01:33:40,230 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:33:40,296 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt
2016-05-18 01:33:40,446 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:33:40,446 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:33:40,459 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D53954286FDD4BF38DC64DF6E121C83C, ordinal: 0
2016-05-18 01:33:40,496 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt"]
2016-05-18 01:33:40,496 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 01:33:40,497 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D53954286FDD4BF38DC64DF6E121C83C, mem on start (mb), free: 87, total: 223, max: 672
2016-05-18 01:33:40,511 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D53954286FDD4BF38DC64DF6E121C83C, mem on close (mb), free: 87, total: 223, max: 672
2016-05-18 01:33:43,285 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:33:43,285 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:33:43,298 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DFD8F8A7CBD84A6F88740F4D2350DEE7, ordinal: 1
2016-05-18 01:33:43,302 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 01:33:43,302 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testIdentityBuffer/identity"]
2016-05-18 01:33:43,302 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DFD8F8A7CBD84A6F88740F4D2350DEE7, mem on start (mb), free: 85, total: 223, max: 672
2016-05-18 01:33:43,320 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DFD8F8A7CBD84A6F88740F4D2350DEE7, mem on close (mb), free: 84, total: 223, max: 672
2016-05-18 01:33:46,288 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testIdentityBuffer/identity/_temporary
2016-05-18 01:33:46,289 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:06.314
2016-05-18 01:33:46,325 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/bufferpipesplatform/testIdentityBuffer/identity
2016-05-18 01:33:46,348 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:33:46,348 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 01:33:46,413 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.059
2016-05-18 01:33:46,415 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:33:46,415 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 01:33:46,444 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:33:46,444 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt"]
2016-05-18 01:33:46,444 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferForward/firstn"]
2016-05-18 01:33:46,445 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:33:46,445 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:33:46,445 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:33:46,446 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...irstNBufferForward/firstn
2016-05-18 01:33:46,549 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0002
2016-05-18 01:33:46,551 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:33:46,557 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt
2016-05-18 01:33:46,652 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:33:46,652 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:33:46,661 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: BE0B5D85E71F42D78BA44AF81AE187A0, ordinal: 0
2016-05-18 01:33:46,662 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt"]
2016-05-18 01:33:46,662 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 01:33:46,662 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BE0B5D85E71F42D78BA44AF81AE187A0, mem on start (mb), free: 66, total: 318, max: 672
2016-05-18 01:33:46,667 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: BE0B5D85E71F42D78BA44AF81AE187A0, mem on close (mb), free: 66, total: 318, max: 672
2016-05-18 01:33:49,563 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:33:49,564 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:33:49,581 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: BA2F59CCB4F8421EAD931DB048828EC2, ordinal: 1
2016-05-18 01:33:49,582 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 01:33:49,582 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferForward/firstn"]
2016-05-18 01:33:49,582 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BA2F59CCB4F8421EAD931DB048828EC2, mem on start (mb), free: 65, total: 318, max: 672
2016-05-18 01:33:49,593 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: BA2F59CCB4F8421EAD931DB048828EC2, mem on close (mb), free: 65, total: 318, max: 672
2016-05-18 01:33:52,568 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferForward/firstn/_temporary
2016-05-18 01:33:52,569 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:06.123
2016-05-18 01:33:52,607 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/bufferpipesplatform/testFirstNBufferForward/firstn
2016-05-18 01:33:52,657 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:33:52,658 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 01:33:52,771 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.102
2016-05-18 01:33:52,773 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:33:52,774 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 01:33:52,802 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:33:52,802 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt"]
2016-05-18 01:33:52,802 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer/simple"]
2016-05-18 01:33:52,803 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:33:52,803 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:33:52,803 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:33:52,804 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...m/testSimpleBuffer/simple
2016-05-18 01:33:52,845 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0003
2016-05-18 01:33:52,846 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:33:52,851 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt
2016-05-18 01:33:52,948 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:33:52,948 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:33:52,957 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C57F2849C3FB4EBFAB2C40AA50CA0D6B, ordinal: 0
2016-05-18 01:33:52,958 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt"]
2016-05-18 01:33:52,959 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 01:33:52,959 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C57F2849C3FB4EBFAB2C40AA50CA0D6B, mem on start (mb), free: 106, total: 412, max: 672
2016-05-18 01:33:52,963 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C57F2849C3FB4EBFAB2C40AA50CA0D6B, mem on close (mb), free: 106, total: 412, max: 672
2016-05-18 01:33:55,856 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:33:55,856 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:33:55,866 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E4A321346E6449ADBE9082C7F4959325, ordinal: 1
2016-05-18 01:33:55,867 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 01:33:55,868 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer/simple"]
2016-05-18 01:33:55,868 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E4A321346E6449ADBE9082C7F4959325, mem on start (mb), free: 105, total: 412, max: 672
2016-05-18 01:33:55,875 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E4A321346E6449ADBE9082C7F4959325, mem on close (mb), free: 105, total: 412, max: 672
2016-05-18 01:33:58,861 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer/simple/_temporary
2016-05-18 01:33:58,862 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:06.059
2016-05-18 01:33:58,884 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/bufferpipesplatform/testSimpleBuffer/simple
2016-05-18 01:33:58,896 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:33:58,897 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 01:33:58,986 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.084
2016-05-18 01:33:58,988 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:33:58,988 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 01:33:59,016 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting
2016-05-18 01:33:59,017 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/upper.txt"]
2016-05-18 01:33:59,017 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower.txt"]
2016-05-18 01:33:59,017 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testJoinerClosure/cogroup"]
2016-05-18 01:33:59,017 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] parallel execution of steps is enabled: false
2016-05-18 01:33:59,018 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executing total steps: 1
2016-05-18 01:33:59,018 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] allocating management threads: 1
2016-05-18 01:33:59,018 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting step: (1/1) ...testJoinerClosure/cogroup
2016-05-18 01:33:59,071 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] submitted hadoop job: job_local_0004
2016-05-18 01:33:59,072 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] tracking url: http://localhost:8080/
2016-05-18 01:33:59,077 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/upper.txt
2016-05-18 01:33:59,176 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:33:59,177 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:33:59,187 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AA22D50270384A268F81062F9DA61F5B, ordinal: 0
2016-05-18 01:33:59,189 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/upper.txt"]
2016-05-18 01:33:59,189 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 01:33:59,189 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AA22D50270384A268F81062F9DA61F5B, mem on start (mb), free: 88, total: 507, max: 672
2016-05-18 01:33:59,192 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AA22D50270384A268F81062F9DA61F5B, mem on close (mb), free: 88, total: 507, max: 672
2016-05-18 01:34:02,078 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower.txt
2016-05-18 01:34:02,176 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:34:02,176 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:34:02,185 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AA22D50270384A268F81062F9DA61F5B, ordinal: 0
2016-05-18 01:34:02,186 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower.txt"]
2016-05-18 01:34:02,186 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 01:34:02,186 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AA22D50270384A268F81062F9DA61F5B, mem on start (mb), free: 50, total: 570, max: 672
2016-05-18 01:34:02,188 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AA22D50270384A268F81062F9DA61F5B, mem on close (mb), free: 49, total: 570, max: 672
2016-05-18 01:34:05,089 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:34:05,089 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:34:05,099 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F653539C3ADE41DE95D02737DCEF79A8, ordinal: 1
2016-05-18 01:34:05,100 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 01:34:05,100 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testJoinerClosure/cogroup"]
2016-05-18 01:34:05,100 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F653539C3ADE41DE95D02737DCEF79A8, mem on start (mb), free: 48, total: 570, max: 672
2016-05-18 01:34:05,113 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 01:34:05,113 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 01:34:05,119 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F653539C3ADE41DE95D02737DCEF79A8, mem on close (mb), free: 48, total: 570, max: 672
2016-05-18 01:34:08,094 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testJoinerClosure/cogroup/_temporary
2016-05-18 01:34:08,095 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] completed in: 00:09.078
2016-05-18 01:34:08,117 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/bufferpipesplatform/testJoinerClosure/cogroup
2016-05-18 01:34:08,132 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:34:08,132 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 01:34:08,190 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.053
2016-05-18 01:34:08,192 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:34:08,192 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 01:34:08,216 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:34:08,216 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt"]
2016-05-18 01:34:08,217 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer2/simple2"]
2016-05-18 01:34:08,217 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:34:08,217 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:34:08,218 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:34:08,220 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...testSimpleBuffer2/simple2
2016-05-18 01:34:08,259 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0005
2016-05-18 01:34:08,260 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:34:08,265 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt
2016-05-18 01:34:08,531 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:34:08,531 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:34:08,542 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: B3333F59D9EB494C86F6C9C5CF54BB6D, ordinal: 0
2016-05-18 01:34:08,543 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt"]
2016-05-18 01:34:08,543 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 01:34:08,543 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B3333F59D9EB494C86F6C9C5CF54BB6D, mem on start (mb), free: 94, total: 201, max: 672
2016-05-18 01:34:08,546 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: B3333F59D9EB494C86F6C9C5CF54BB6D, mem on close (mb), free: 93, total: 201, max: 672
2016-05-18 01:34:11,269 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:34:11,270 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:34:11,280 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DE26598EACA44705A7B123AEF93E2457, ordinal: 1
2016-05-18 01:34:11,281 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 01:34:11,281 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer2/simple2"]
2016-05-18 01:34:11,281 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DE26598EACA44705A7B123AEF93E2457, mem on start (mb), free: 91, total: 201, max: 672
2016-05-18 01:34:11,291 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DE26598EACA44705A7B123AEF93E2457, mem on close (mb), free: 91, total: 201, max: 672
2016-05-18 01:34:14,279 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer2/simple2/_temporary
2016-05-18 01:34:14,280 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:06.063
2016-05-18 01:34:14,305 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/bufferpipesplatform/testSimpleBuffer2/simple2
2016-05-18 01:34:14,319 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:34:14,320 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 01:34:14,373 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.047
2016-05-18 01:34:14,374 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:34:14,374 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 01:34:14,396 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:34:14,396 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 01:34:14,397 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer3/simple3"]
2016-05-18 01:34:14,397 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:34:14,397 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:34:14,397 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:34:14,398 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...testSimpleBuffer3/simple3
2016-05-18 01:34:14,462 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0006
2016-05-18 01:34:14,463 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:34:14,467 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower+upper.txt
2016-05-18 01:34:14,484 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:34:14,484 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:34:14,492 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D154FD73E34D4DD98EC3A7AC06DCB8B8, ordinal: 0
2016-05-18 01:34:14,492 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line' | long, String]->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 01:34:14,493 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 01:34:14,493 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D154FD73E34D4DD98EC3A7AC06DCB8B8, mem on start (mb), free: 86, total: 204, max: 672
2016-05-18 01:34:14,495 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D154FD73E34D4DD98EC3A7AC06DCB8B8, mem on close (mb), free: 86, total: 204, max: 672
2016-05-18 01:34:17,472 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:34:17,472 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:34:17,479 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E3CD0C2B334443F0A4B6303BBA2E4EF3, ordinal: 1
2016-05-18 01:34:17,480 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 01:34:17,480 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer3/simple3"]
2016-05-18 01:34:17,480 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E3CD0C2B334443F0A4B6303BBA2E4EF3, mem on start (mb), free: 85, total: 204, max: 672
2016-05-18 01:34:17,486 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E3CD0C2B334443F0A4B6303BBA2E4EF3, mem on close (mb), free: 85, total: 204, max: 672
2016-05-18 01:34:20,477 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer3/simple3/_temporary
2016-05-18 01:34:20,478 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:06.080
2016-05-18 01:34:20,495 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/bufferpipesplatform/testSimpleBuffer3/simple3
2016-05-18 01:34:20,512 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:34:20,512 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 01:34:20,555 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.038
2016-05-18 01:34:20,556 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:34:20,557 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 01:34:20,572 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:34:20,573 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt"]
2016-05-18 01:34:20,573 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn"]
2016-05-18 01:34:20,574 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:34:20,574 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:34:20,574 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:34:20,575 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...irstNBufferReverse/firstn
2016-05-18 01:34:20,605 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0007
2016-05-18 01:34:20,605 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:34:20,609 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt
2016-05-18 01:34:20,623 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:34:20,623 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:34:20,629 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DDC7D1AE2CF44E2BAA201EFBABFA0109, ordinal: 0
2016-05-18 01:34:20,630 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt"]
2016-05-18 01:34:20,630 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 01:34:20,630 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DDC7D1AE2CF44E2BAA201EFBABFA0109, mem on start (mb), free: 190, total: 313, max: 672
2016-05-18 01:34:20,633 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DDC7D1AE2CF44E2BAA201EFBABFA0109, mem on close (mb), free: 190, total: 313, max: 672
2016-05-18 01:34:23,613 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:34:23,613 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:34:23,622 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: C74160E138E2423A841FA70ABC0CE645, ordinal: 1
2016-05-18 01:34:23,623 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 01:34:23,624 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn"]
2016-05-18 01:34:23,625 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C74160E138E2423A841FA70ABC0CE645, mem on start (mb), free: 187, total: 313, max: 672
2016-05-18 01:34:23,631 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: C74160E138E2423A841FA70ABC0CE645, mem on close (mb), free: 187, total: 313, max: 672
2016-05-18 01:34:26,615 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn/_temporary
2016-05-18 01:34:26,616 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:06.043
2016-05-18 01:34:26,631 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn
2016-05-18 01:34:26,641 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:34:26,642 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 01:34:26,671 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: ILLEGAL, in: 00:00.024
2016-05-18 01:34:26,672 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, found assembly to be malformed
2016-05-18 01:34:26,683 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 01:34:26,684 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(176)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/3.1.0/86eabf0febb15d07d5285b321b1f6b06e25aa664/cascading-hadoop-3.1.0.jar
2016-05-18 01:34:26,723 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.036
2016-05-18 01:34:26,724 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 01:34:26,724 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 01:34:26,740 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 01:34:26,740 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt"]
2016-05-18 01:34:26,740 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBuffer/firstn"]
2016-05-18 01:34:26,741 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 01:34:26,741 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 01:34:26,741 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 01:34:26,742 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...m/testFirstNBuffer/firstn
2016-05-18 01:34:26,788 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0008
2016-05-18 01:34:26,788 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 01:34:26,794 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt
2016-05-18 01:34:26,818 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 01:34:26,818 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 01:34:26,827 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D49DF7F478754F13A2CFDA7070AF0DC0, ordinal: 0
2016-05-18 01:34:26,828 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/classes/test/data/lhs.txt"]
2016-05-18 01:34:26,829 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 01:34:26,829 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D49DF7F478754F13A2CFDA7070AF0DC0, mem on start (mb), free: 200, total: 313, max: 672
2016-05-18 01:34:26,832 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D49DF7F478754F13A2CFDA7070AF0DC0, mem on close (mb), free: 200, total: 313, max: 672
2016-05-18 01:34:29,797 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 01:34:29,798 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 01:34:29,804 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: AEFE8922A2C94F08AA2D8DE611EA687B, ordinal: 1
2016-05-18 01:34:29,805 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 01:34:29,805 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBuffer/firstn"]
2016-05-18 01:34:29,806 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AEFE8922A2C94F08AA2D8DE611EA687B, mem on start (mb), free: 198, total: 313, max: 672
2016-05-18 01:34:29,810 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: AEFE8922A2C94F08AA2D8DE611EA687B, mem on close (mb), free: 198, total: 313, max: 672
2016-05-18 01:34:32,804 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBuffer/firstn/_temporary
2016-05-18 01:34:32,805 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:06.064
2016-05-18 01:34:32,825 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.0.x/build/test/output//hadoop/bufferpipesplatform/testFirstNBuffer/firstn