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