Class cascading.BufferPipesPlatformTest

9

tests

0

failures

0

ignored

4.085s

duration

100%

successful

Tests

Test Duration Result
testFirstNBuffer 0.311s passed
testFirstNBufferForward 0.493s passed
testFirstNBufferReverse 0.210s passed
testIdentityBuffer 1.615s passed
testJoinerClosure 0.491s passed
testJoinerClosureFail 0.035s passed
testSimpleBuffer 0.401s passed
testSimpleBuffer2 0.279s passed
testSimpleBuffer3 0.250s passed

Standard output

2016-05-18 05:23:36,829 INFO  platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 05:23:36,846 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.BufferPipesPlatformTest, with platform: hadoop
2016-05-18 05:23:36,873 INFO  hadoop.HadoopPlatform (HadoopPlatform.java:setUp(127)) - not using cluster
2016-05-18 05:23:37,123 INFO  platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides: 
2016-05-18 05:23:37,234 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:23:37,236 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 05:23:37,359 INFO  property.AppProps (AppProps.java:getAppID(177)) - using app.id: B5C8BD6BA8FC44FA92E4BDF2222CAEB2
2016-05-18 05:23:37,542 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.139
2016-05-18 05:23:37,546 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 05:23:37,546 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 05:23:37,736 INFO  util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 05:23:37,737 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:23:37,738 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.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:23:37,738 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testIdentityBuffer/identity"]
2016-05-18 05:23:37,739 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-18 05:23:37,739 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-18 05:23:37,741 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-18 05:23:37,742 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...stIdentityBuffer/identity
2016-05-18 05:23:37,778 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 05:23:37,839 WARN  snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2016-05-18 05:23:38,046 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local703417877_0001
2016-05-18 05:23:38,048 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:23:38,133 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt
2016-05-18 05:23:38,285 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:23:38,285 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:23:38,298 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E230D184753543C89E2DE4F728C3D97D, ordinal: 0
2016-05-18 05:23:38,335 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.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:23:38,335 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 05:23:38,336 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E230D184753543C89E2DE4F728C3D97D, mem on start (mb), free: 81, total: 223, max: 672
2016-05-18 05:23:38,348 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E230D184753543C89E2DE4F728C3D97D, mem on close (mb), free: 81, total: 223, max: 672
2016-05-18 05:23:38,382 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:23:38,382 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:23:38,396 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F9AAD80BE1DC4286AC5FD61EAA1BA82B, ordinal: 1
2016-05-18 05:23:38,400 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 05:23:38,400 INFO  hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testIdentityBuffer/identity"]
2016-05-18 05:23:38,400 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F9AAD80BE1DC4286AC5FD61EAA1BA82B, mem on start (mb), free: 79, total: 223, max: 672
2016-05-18 05:23:38,419 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F9AAD80BE1DC4286AC5FD61EAA1BA82B, mem on close (mb), free: 78, total: 223, max: 672
2016-05-18 05:23:38,435 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testIdentityBuffer/identity/_temporary
2016-05-18 05:23:38,436 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.696
2016-05-18 05:23:38,483 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/bufferpipesplatform/testIdentityBuffer/identity
2016-05-18 05:23:38,520 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:23:38,521 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 05:23:38,618 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.088
2016-05-18 05:23:38,620 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 05:23:38,621 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 05:23:38,656 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:23:38,656 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:23:38,657 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferForward/firstn"]
2016-05-18 05:23:38,657 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-18 05:23:38,657 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-18 05:23:38,658 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-18 05:23:38,658 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...irstNBufferForward/firstn
2016-05-18 05:23:38,746 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local355895771_0002
2016-05-18 05:23:38,747 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:23:38,752 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt
2016-05-18 05:23:38,871 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:23:38,871 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:23:38,881 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: EC3FA9084AE14AE7B246F1B72560EE0D, ordinal: 0
2016-05-18 05:23:38,882 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:23:38,882 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 05:23:38,883 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EC3FA9084AE14AE7B246F1B72560EE0D, mem on start (mb), free: 114, total: 318, max: 672
2016-05-18 05:23:38,890 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EC3FA9084AE14AE7B246F1B72560EE0D, mem on close (mb), free: 114, total: 318, max: 672
2016-05-18 05:23:38,904 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:23:38,904 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:23:38,920 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D134A785D8EA479B954319FA167C6230, ordinal: 1
2016-05-18 05:23:38,921 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 05:23:38,922 INFO  hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferForward/firstn"]
2016-05-18 05:23:38,922 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D134A785D8EA479B954319FA167C6230, mem on start (mb), free: 113, total: 318, max: 672
2016-05-18 05:23:38,932 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D134A785D8EA479B954319FA167C6230, mem on close (mb), free: 112, total: 318, max: 672
2016-05-18 05:23:38,946 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferForward/firstn/_temporary
2016-05-18 05:23:38,947 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.290
2016-05-18 05:23:38,979 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/bufferpipesplatform/testFirstNBufferForward/firstn
2016-05-18 05:23:38,996 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:23:38,996 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 05:23:39,099 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.096
2016-05-18 05:23:39,102 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 05:23:39,102 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 05:23:39,137 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:23:39,138 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.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:23:39,138 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer/simple"]
2016-05-18 05:23:39,138 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-18 05:23:39,139 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-18 05:23:39,139 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-18 05:23:39,140 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...m/testSimpleBuffer/simple
2016-05-18 05:23:39,198 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local927938956_0003
2016-05-18 05:23:39,199 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:23:39,204 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt
2016-05-18 05:23:39,302 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:23:39,302 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:23:39,311 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A05FEBC2C09343B7A0B4AFB56983273F, ordinal: 0
2016-05-18 05:23:39,312 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.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:23:39,313 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 05:23:39,313 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A05FEBC2C09343B7A0B4AFB56983273F, mem on start (mb), free: 94, total: 414, max: 672
2016-05-18 05:23:39,316 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A05FEBC2C09343B7A0B4AFB56983273F, mem on close (mb), free: 94, total: 414, max: 672
2016-05-18 05:23:39,328 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:23:39,329 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:23:39,339 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: ABADEA5D59E24C86A4A63D413DBBEEC2, ordinal: 1
2016-05-18 05:23:39,340 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 05:23:39,340 INFO  hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer/simple"]
2016-05-18 05:23:39,341 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: ABADEA5D59E24C86A4A63D413DBBEEC2, mem on start (mb), free: 93, total: 414, max: 672
2016-05-18 05:23:39,349 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: ABADEA5D59E24C86A4A63D413DBBEEC2, mem on close (mb), free: 93, total: 414, max: 672
2016-05-18 05:23:39,362 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer/simple/_temporary
2016-05-18 05:23:39,362 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.225
2016-05-18 05:23:39,381 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/bufferpipesplatform/testSimpleBuffer/simple
2016-05-18 05:23:39,398 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:23:39,398 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 05:23:39,484 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.079
2016-05-18 05:23:39,486 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 05:23:39,486 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 05:23:39,513 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting
2016-05-18 05:23:39,514 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/upper.txt"]
2016-05-18 05:23:39,514 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower.txt"]
2016-05-18 05:23:39,515 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper]  sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testJoinerClosure/cogroup"]
2016-05-18 05:23:39,515 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper]  parallel execution of steps is enabled: false
2016-05-18 05:23:39,515 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper]  executing total steps: 1
2016-05-18 05:23:39,516 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper]  allocating management threads: 1
2016-05-18 05:23:39,517 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting step: (1/1) ...testJoinerClosure/cogroup
2016-05-18 05:23:39,566 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] submitted hadoop job: job_local963920538_0004
2016-05-18 05:23:39,566 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] tracking url: http://localhost:8080/
2016-05-18 05:23:39,570 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/upper.txt
2016-05-18 05:23:39,666 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:23:39,666 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:23:39,675 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C6EE95A74C334B2AA8EA7DA09F2A36C1, ordinal: 0
2016-05-18 05:23:39,676 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/upper.txt"]
2016-05-18 05:23:39,676 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 05:23:39,676 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C6EE95A74C334B2AA8EA7DA09F2A36C1, mem on start (mb), free: 74, total: 509, max: 672
2016-05-18 05:23:39,678 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C6EE95A74C334B2AA8EA7DA09F2A36C1, mem on close (mb), free: 74, total: 509, max: 672
2016-05-18 05:23:39,686 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower.txt
2016-05-18 05:23:39,781 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:23:39,781 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:23:39,790 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C6EE95A74C334B2AA8EA7DA09F2A36C1, ordinal: 0
2016-05-18 05:23:39,791 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower.txt"]
2016-05-18 05:23:39,791 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 05:23:39,791 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C6EE95A74C334B2AA8EA7DA09F2A36C1, mem on start (mb), free: 35, total: 572, max: 672
2016-05-18 05:23:39,792 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C6EE95A74C334B2AA8EA7DA09F2A36C1, mem on close (mb), free: 35, total: 572, max: 672
2016-05-18 05:23:39,809 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:23:39,809 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:23:39,818 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E02A95FF3FE84A4DA9D8E89EF755E98B, ordinal: 1
2016-05-18 05:23:39,819 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 05:23:39,819 INFO  hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testJoinerClosure/cogroup"]
2016-05-18 05:23:39,819 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E02A95FF3FE84A4DA9D8E89EF755E98B, mem on start (mb), free: 34, total: 572, max: 672
2016-05-18 05:23:39,832 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 05:23:39,832 INFO  collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 05:23:39,837 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E02A95FF3FE84A4DA9D8E89EF755E98B, mem on close (mb), free: 33, total: 572, max: 672
2016-05-18 05:23:39,852 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testJoinerClosure/cogroup/_temporary
2016-05-18 05:23:39,853 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper]  completed in: 00:00.339
2016-05-18 05:23:39,873 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/bufferpipesplatform/testJoinerClosure/cogroup
2016-05-18 05:23:39,883 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:23:39,884 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 05:23:39,944 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.041
2016-05-18 05:23:39,946 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 05:23:39,946 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 05:23:39,972 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:23:39,972 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.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:23:39,973 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer2/simple2"]
2016-05-18 05:23:39,973 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-18 05:23:39,974 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-18 05:23:39,974 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-18 05:23:39,975 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...testSimpleBuffer2/simple2
2016-05-18 05:23:40,013 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local238194076_0005
2016-05-18 05:23:40,015 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:23:40,021 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt
2016-05-18 05:23:40,071 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:23:40,071 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:23:40,079 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D5331291B1304B3CBB2EAED062C5EC7F, ordinal: 0
2016-05-18 05:23:40,080 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.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:23:40,080 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 05:23:40,080 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D5331291B1304B3CBB2EAED062C5EC7F, mem on start (mb), free: 48, total: 630, max: 672
2016-05-18 05:23:40,084 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D5331291B1304B3CBB2EAED062C5EC7F, mem on close (mb), free: 48, total: 630, max: 672
2016-05-18 05:23:40,096 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:23:40,096 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:23:40,104 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E30F2ECED7A34C639705D842E942864E, ordinal: 1
2016-05-18 05:23:40,105 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 05:23:40,105 INFO  hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer2/simple2"]
2016-05-18 05:23:40,105 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E30F2ECED7A34C639705D842E942864E, mem on start (mb), free: 46, total: 630, max: 672
2016-05-18 05:23:40,112 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E30F2ECED7A34C639705D842E942864E, mem on close (mb), free: 45, total: 630, max: 672
2016-05-18 05:23:40,131 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer2/simple2/_temporary
2016-05-18 05:23:40,132 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.159
2016-05-18 05:23:40,152 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/bufferpipesplatform/testSimpleBuffer2/simple2
2016-05-18 05:23:40,168 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:23:40,169 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 05:23:40,222 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.048
2016-05-18 05:23:40,223 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 05:23:40,223 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 05:23:40,240 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:23:40,240 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.2.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 05:23:40,241 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer3/simple3"]
2016-05-18 05:23:40,241 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-18 05:23:40,242 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-18 05:23:40,242 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-18 05:23:40,243 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...testSimpleBuffer3/simple3
2016-05-18 05:23:40,303 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local1073759390_0006
2016-05-18 05:23:40,305 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:23:40,309 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lower+upper.txt
2016-05-18 05:23:40,326 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:23:40,327 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:23:40,333 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: EB1E90E80BF2418D84E231236B536AEF, ordinal: 0
2016-05-18 05:23:40,334 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.2.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 05:23:40,335 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 05:23:40,335 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EB1E90E80BF2418D84E231236B536AEF, mem on start (mb), free: 46, total: 630, max: 672
2016-05-18 05:23:40,337 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: EB1E90E80BF2418D84E231236B536AEF, mem on close (mb), free: 46, total: 630, max: 672
2016-05-18 05:23:40,350 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:23:40,350 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:23:40,357 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: A49AC729ADF84C269FBD41A98C146887, ordinal: 1
2016-05-18 05:23:40,358 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 05:23:40,358 INFO  hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer3/simple3"]
2016-05-18 05:23:40,358 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A49AC729ADF84C269FBD41A98C146887, mem on start (mb), free: 45, total: 630, max: 672
2016-05-18 05:23:40,364 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: A49AC729ADF84C269FBD41A98C146887, mem on close (mb), free: 45, total: 630, max: 672
2016-05-18 05:23:40,381 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer3/simple3/_temporary
2016-05-18 05:23:40,381 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.140
2016-05-18 05:23:40,403 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/bufferpipesplatform/testSimpleBuffer3/simple3
2016-05-18 05:23:40,414 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:23:40,414 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 05:23:40,454 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.036
2016-05-18 05:23:40,455 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 05:23:40,456 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 05:23:40,472 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:23:40,472 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:23:40,472 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn"]
2016-05-18 05:23:40,473 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-18 05:23:40,473 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-18 05:23:40,473 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-18 05:23:40,473 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...irstNBufferReverse/firstn
2016-05-18 05:23:40,523 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local877193040_0007
2016-05-18 05:23:40,524 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:23:40,530 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt
2016-05-18 05:23:40,545 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:23:40,546 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:23:40,552 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DDB2E157921444B583CA4065C88A5E7D, ordinal: 0
2016-05-18 05:23:40,553 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:23:40,553 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 05:23:40,554 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DDB2E157921444B583CA4065C88A5E7D, mem on start (mb), free: 161, total: 745, max: 745
2016-05-18 05:23:40,557 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DDB2E157921444B583CA4065C88A5E7D, mem on close (mb), free: 161, total: 745, max: 745
2016-05-18 05:23:40,567 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:23:40,567 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:23:40,574 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E23C0FF42124491FAA6D3FBA15061D41, ordinal: 1
2016-05-18 05:23:40,574 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 05:23:40,575 INFO  hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn"]
2016-05-18 05:23:40,575 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E23C0FF42124491FAA6D3FBA15061D41, mem on start (mb), free: 160, total: 745, max: 745
2016-05-18 05:23:40,579 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E23C0FF42124491FAA6D3FBA15061D41, mem on close (mb), free: 159, total: 745, max: 745
2016-05-18 05:23:40,597 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn/_temporary
2016-05-18 05:23:40,598 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.125
2016-05-18 05:23:40,614 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn
2016-05-18 05:23:40,623 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:23:40,624 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 05:23:40,648 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: ILLEGAL, in: 00:00.020
2016-05-18 05:23:40,649 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, found assembly to be malformed
2016-05-18 05:23:40,659 INFO  util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 05:23:40,659 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 05:23:40,701 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.037
2016-05-18 05:23:40,702 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 05:23:40,702 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 05:23:40,723 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 05:23:40,723 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:23:40,723 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBuffer/firstn"]
2016-05-18 05:23:40,724 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  parallel execution of steps is enabled: false
2016-05-18 05:23:40,724 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  executing total steps: 1
2016-05-18 05:23:40,724 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  allocating management threads: 1
2016-05-18 05:23:40,725 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...m/testFirstNBuffer/firstn
2016-05-18 05:23:40,769 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local2087489112_0008
2016-05-18 05:23:40,770 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 05:23:40,777 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt
2016-05-18 05:23:40,875 INFO  hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 05:23:40,875 INFO  hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 05:23:40,881 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: AA0779250F574C83A206D9E6A7134A03, ordinal: 0
2016-05-18 05:23:40,882 INFO  hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/classes/test/data/lhs.txt"]
2016-05-18 05:23:40,882 INFO  hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 05:23:40,882 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AA0779250F574C83A206D9E6A7134A03, mem on start (mb), free: 41, total: 745, max: 745
2016-05-18 05:23:40,885 INFO  hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: AA0779250F574C83A206D9E6A7134A03, mem on close (mb), free: 41, total: 745, max: 745
2016-05-18 05:23:40,899 INFO  hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 05:23:40,899 INFO  hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 05:23:40,910 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DD1A1353EADA4E6DADE1EAA22DC035DE, ordinal: 1
2016-05-18 05:23:40,910 INFO  hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 05:23:40,911 INFO  hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBuffer/firstn"]
2016-05-18 05:23:40,911 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DD1A1353EADA4E6DADE1EAA22DC035DE, mem on start (mb), free: 40, total: 745, max: 745
2016-05-18 05:23:40,917 INFO  hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DD1A1353EADA4E6DADE1EAA22DC035DE, mem on close (mb), free: 39, total: 745, max: 745
2016-05-18 05:23:40,934 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBuffer/firstn/_temporary
2016-05-18 05:23:40,935 INFO  flow.Flow (BaseFlow.java:logInfo(1504)) - [test]  completed in: 00:00.211
2016-05-18 05:23:40,960 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.2.x/build/test/output//hadoop/bufferpipesplatform/testFirstNBuffer/firstn