2016-05-18 03:50:59,303 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(197)) - found 1 test platforms from classpath
2016-05-18 03:50:59,320 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(246)) - adding test: cascading.BufferPipesPlatformTest, with platform: hadoop
2016-05-18 03:50:59,348 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(127)) - not using cluster
2016-05-18 03:50:59,602 INFO platform.TestPlatform (TestPlatform.java:getGlobalProperties(75)) - platform property overrides:
2016-05-18 03:50:59,708 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:50:59,711 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 03:50:59,831 INFO property.AppProps (AppProps.java:getAppID(177)) - using app.id: 1D17E2C4538A48D1BD2AA486B1BA2E43
2016-05-18 03:51:00,021 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.144
2016-05-18 03:51:00,025 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 03:51:00,025 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 03:51:00,216 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 3.1.0
2016-05-18 03:51:00,218 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 03:51:00,219 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.1.x/build/classes/test/data/lhs.txt"]
2016-05-18 03:51:00,220 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testIdentityBuffer/identity"]
2016-05-18 03:51:00,220 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 03:51:00,221 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 03:51:00,221 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 03:51:00,222 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...stIdentityBuffer/identity
2016-05-18 03:51:00,263 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 03:51:00,322 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2016-05-18 03:51:00,576 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0001
2016-05-18 03:51:00,577 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 03:51:00,664 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lhs.txt
2016-05-18 03:51:00,877 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:51:00,878 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:51:00,898 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: CC1737D57C1F4CBAB2FA97724353780C, ordinal: 0
2016-05-18 03:51:00,937 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.1.x/build/classes/test/data/lhs.txt"]
2016-05-18 03:51:00,938 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 03:51:00,939 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CC1737D57C1F4CBAB2FA97724353780C, mem on start (mb), free: 81, total: 223, max: 672
2016-05-18 03:51:00,953 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: CC1737D57C1F4CBAB2FA97724353780C, mem on close (mb), free: 81, total: 223, max: 672
2016-05-18 03:51:00,986 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:51:00,987 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:51:01,003 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: F9C720A92C8C4AC9B708C13368316369, ordinal: 1
2016-05-18 03:51:01,008 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 03:51:01,009 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testIdentityBuffer/identity"]
2016-05-18 03:51:01,009 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F9C720A92C8C4AC9B708C13368316369, mem on start (mb), free: 79, total: 223, max: 672
2016-05-18 03:51:01,030 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: F9C720A92C8C4AC9B708C13368316369, mem on close (mb), free: 78, total: 223, max: 672
2016-05-18 03:51:01,044 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testIdentityBuffer/identity/_temporary
2016-05-18 03:51:01,046 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.825
2016-05-18 03:51:01,089 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/bufferpipesplatform/testIdentityBuffer/identity
2016-05-18 03:51:01,121 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:51:01,122 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 03:51:01,220 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.086
2016-05-18 03:51:01,221 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 03:51:01,222 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 03:51:01,265 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 03:51:01,265 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lhs.txt"]
2016-05-18 03:51:01,266 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferForward/firstn"]
2016-05-18 03:51:01,266 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 03:51:01,267 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 03:51:01,267 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 03:51:01,268 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...irstNBufferForward/firstn
2016-05-18 03:51:01,393 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0002
2016-05-18 03:51:01,394 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 03:51:01,399 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lhs.txt
2016-05-18 03:51:01,519 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:51:01,519 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:51:01,528 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E719DD5EEEBA4D269DDE050333A68CE5, ordinal: 0
2016-05-18 03:51:01,529 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lhs.txt"]
2016-05-18 03:51:01,529 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 03:51:01,529 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E719DD5EEEBA4D269DDE050333A68CE5, mem on start (mb), free: 114, total: 318, max: 672
2016-05-18 03:51:01,536 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E719DD5EEEBA4D269DDE050333A68CE5, mem on close (mb), free: 114, total: 318, max: 672
2016-05-18 03:51:01,549 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:51:01,549 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:51:01,566 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B8A037B333F54C50A2CD3C1CD9CE4151, ordinal: 1
2016-05-18 03:51:01,568 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 03:51:01,568 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferForward/firstn"]
2016-05-18 03:51:01,569 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B8A037B333F54C50A2CD3C1CD9CE4151, mem on start (mb), free: 113, total: 318, max: 672
2016-05-18 03:51:01,579 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B8A037B333F54C50A2CD3C1CD9CE4151, mem on close (mb), free: 112, total: 318, max: 672
2016-05-18 03:51:01,596 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferForward/firstn/_temporary
2016-05-18 03:51:01,596 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.331
2016-05-18 03:51:01,640 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/bufferpipesplatform/testFirstNBufferForward/firstn
2016-05-18 03:51:01,667 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:51:01,668 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 03:51:01,739 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.065
2016-05-18 03:51:01,741 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 03:51:01,741 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 03:51:01,766 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 03:51:01,766 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.1.x/build/classes/test/data/lhs.txt"]
2016-05-18 03:51:01,767 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer/simple"]
2016-05-18 03:51:01,767 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 03:51:01,768 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 03:51:01,769 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 03:51:01,769 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...m/testSimpleBuffer/simple
2016-05-18 03:51:01,814 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0003
2016-05-18 03:51:01,815 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 03:51:01,819 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lhs.txt
2016-05-18 03:51:01,914 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:51:01,915 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:51:01,924 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D0A8B52430E44DCB82B76AE8934C9BFA, ordinal: 0
2016-05-18 03:51:01,925 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.1.x/build/classes/test/data/lhs.txt"]
2016-05-18 03:51:01,925 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 03:51:01,925 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D0A8B52430E44DCB82B76AE8934C9BFA, mem on start (mb), free: 93, total: 414, max: 672
2016-05-18 03:51:01,928 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D0A8B52430E44DCB82B76AE8934C9BFA, mem on close (mb), free: 93, total: 414, max: 672
2016-05-18 03:51:01,939 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:51:01,939 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:51:01,950 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E5F8685EAA354329911A8C36F2D4EBA4, ordinal: 1
2016-05-18 03:51:01,951 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 03:51:01,951 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer/simple"]
2016-05-18 03:51:01,952 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E5F8685EAA354329911A8C36F2D4EBA4, mem on start (mb), free: 92, total: 414, max: 672
2016-05-18 03:51:01,959 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E5F8685EAA354329911A8C36F2D4EBA4, mem on close (mb), free: 91, total: 414, max: 672
2016-05-18 03:51:01,967 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer/simple/_temporary
2016-05-18 03:51:01,967 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.201
2016-05-18 03:51:01,987 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/bufferpipesplatform/testSimpleBuffer/simple
2016-05-18 03:51:01,999 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:51:02,000 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 03:51:02,068 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.062
2016-05-18 03:51:02,070 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 03:51:02,070 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 03:51:02,098 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting
2016-05-18 03:51:02,099 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/upper.txt"]
2016-05-18 03:51:02,100 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lower.txt"]
2016-05-18 03:51:02,100 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testJoinerClosure/cogroup"]
2016-05-18 03:51:02,101 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] parallel execution of steps is enabled: false
2016-05-18 03:51:02,101 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executing total steps: 1
2016-05-18 03:51:02,102 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] allocating management threads: 1
2016-05-18 03:51:02,103 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] starting step: (1/1) ...testJoinerClosure/cogroup
2016-05-18 03:51:02,164 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] submitted hadoop job: job_local_0004
2016-05-18 03:51:02,165 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] tracking url: http://localhost:8080/
2016-05-18 03:51:02,170 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lower.txt
2016-05-18 03:51:02,274 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:51:02,274 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:51:02,283 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DF99302957E542748B2FED52215DC001, ordinal: 0
2016-05-18 03:51:02,285 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lower.txt"]
2016-05-18 03:51:02,285 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 03:51:02,286 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DF99302957E542748B2FED52215DC001, mem on start (mb), free: 72, total: 509, max: 672
2016-05-18 03:51:02,287 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DF99302957E542748B2FED52215DC001, mem on close (mb), free: 72, total: 509, max: 672
2016-05-18 03:51:02,295 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/upper.txt
2016-05-18 03:51:02,390 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:51:02,391 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:51:02,405 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: DF99302957E542748B2FED52215DC001, ordinal: 0
2016-05-18 03:51:02,407 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/upper.txt"]
2016-05-18 03:51:02,407 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 03:51:02,407 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DF99302957E542748B2FED52215DC001, mem on start (mb), free: 33, total: 572, max: 672
2016-05-18 03:51:02,410 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: DF99302957E542748B2FED52215DC001, mem on close (mb), free: 33, total: 572, max: 672
2016-05-18 03:51:02,425 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:51:02,425 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:51:02,433 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: D8D9F79CF94E490CA0EB01D087C93CE5, ordinal: 1
2016-05-18 03:51:02,434 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2016-05-18 03:51:02,435 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testJoinerClosure/cogroup"]
2016-05-18 03:51:02,435 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D8D9F79CF94E490CA0EB01D087C93CE5, mem on start (mb), free: 32, total: 572, max: 672
2016-05-18 03:51:02,447 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(89)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 03:51:02,447 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(94)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2016-05-18 03:51:02,454 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: D8D9F79CF94E490CA0EB01D087C93CE5, mem on close (mb), free: 31, total: 572, max: 672
2016-05-18 03:51:02,469 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testJoinerClosure/cogroup/_temporary
2016-05-18 03:51:02,470 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] completed in: 00:00.371
2016-05-18 03:51:02,507 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/bufferpipesplatform/testJoinerClosure/cogroup
2016-05-18 03:51:02,517 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:51:02,518 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 03:51:02,570 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.047
2016-05-18 03:51:02,572 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 03:51:02,573 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 03:51:02,596 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 03:51:02,597 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.1.x/build/classes/test/data/lhs.txt"]
2016-05-18 03:51:02,597 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer2/simple2"]
2016-05-18 03:51:02,598 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 03:51:02,598 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 03:51:02,599 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 03:51:02,600 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...testSimpleBuffer2/simple2
2016-05-18 03:51:02,645 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0005
2016-05-18 03:51:02,645 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 03:51:02,651 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lhs.txt
2016-05-18 03:51:02,703 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:51:02,703 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:51:02,711 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: D9AAA87602B344948960931CBECAB066, ordinal: 0
2016-05-18 03:51:02,712 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.1.x/build/classes/test/data/lhs.txt"]
2016-05-18 03:51:02,712 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 03:51:02,713 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D9AAA87602B344948960931CBECAB066, mem on start (mb), free: 48, total: 630, max: 672
2016-05-18 03:51:02,716 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: D9AAA87602B344948960931CBECAB066, mem on close (mb), free: 48, total: 630, max: 672
2016-05-18 03:51:02,727 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:51:02,727 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:51:02,735 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: B77836CAD587435FB7DC0E551384366A, ordinal: 1
2016-05-18 03:51:02,736 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 03:51:02,737 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer2/simple2"]
2016-05-18 03:51:02,737 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B77836CAD587435FB7DC0E551384366A, mem on start (mb), free: 46, total: 630, max: 672
2016-05-18 03:51:02,744 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: B77836CAD587435FB7DC0E551384366A, mem on close (mb), free: 46, total: 630, max: 672
2016-05-18 03:51:02,754 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer2/simple2/_temporary
2016-05-18 03:51:02,755 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.158
2016-05-18 03:51:02,775 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/bufferpipesplatform/testSimpleBuffer2/simple2
2016-05-18 03:51:02,787 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:51:02,788 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 03:51:02,831 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.039
2016-05-18 03:51:02,833 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 03:51:02,834 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 03:51:02,850 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 03:51:02,851 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.1.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 03:51:02,851 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer3/simple3"]
2016-05-18 03:51:02,852 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 03:51:02,852 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 03:51:02,852 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 03:51:02,853 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...testSimpleBuffer3/simple3
2016-05-18 03:51:02,911 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0006
2016-05-18 03:51:02,914 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 03:51:02,917 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lower+upper.txt
2016-05-18 03:51:02,932 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:51:02,932 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:51:02,939 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: A54119A488DE41CCA924BF71FF0E25F6, ordinal: 0
2016-05-18 03:51:02,940 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.1.x/build/classes/test/data/lower+upper.txt"]
2016-05-18 03:51:02,940 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 03:51:02,941 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A54119A488DE41CCA924BF71FF0E25F6, mem on start (mb), free: 47, total: 630, max: 672
2016-05-18 03:51:02,944 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: A54119A488DE41CCA924BF71FF0E25F6, mem on close (mb), free: 47, total: 630, max: 672
2016-05-18 03:51:02,956 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:51:02,956 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:51:02,965 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: FADEE7FA16CB49DE8260303269C161D4, ordinal: 1
2016-05-18 03:51:02,966 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 03:51:02,966 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer3/simple3"]
2016-05-18 03:51:02,966 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FADEE7FA16CB49DE8260303269C161D4, mem on start (mb), free: 46, total: 630, max: 672
2016-05-18 03:51:02,972 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: FADEE7FA16CB49DE8260303269C161D4, mem on close (mb), free: 45, total: 630, max: 672
2016-05-18 03:51:02,986 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testSimpleBuffer3/simple3/_temporary
2016-05-18 03:51:02,987 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.136
2016-05-18 03:51:03,004 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/bufferpipesplatform/testSimpleBuffer3/simple3
2016-05-18 03:51:03,014 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:51:03,015 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 03:51:03,053 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.034
2016-05-18 03:51:03,056 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 03:51:03,056 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 03:51:03,073 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 03:51:03,074 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lhs.txt"]
2016-05-18 03:51:03,074 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn"]
2016-05-18 03:51:03,074 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 03:51:03,074 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 03:51:03,075 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 03:51:03,075 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...irstNBufferReverse/firstn
2016-05-18 03:51:03,123 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0007
2016-05-18 03:51:03,123 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 03:51:03,128 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lhs.txt
2016-05-18 03:51:03,143 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:51:03,143 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:51:03,149 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: C25EDD0107CB41A283E0095A2DEA5097, ordinal: 0
2016-05-18 03:51:03,150 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lhs.txt"]
2016-05-18 03:51:03,150 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 03:51:03,151 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C25EDD0107CB41A283E0095A2DEA5097, mem on start (mb), free: 161, total: 745, max: 745
2016-05-18 03:51:03,154 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: C25EDD0107CB41A283E0095A2DEA5097, mem on close (mb), free: 161, total: 745, max: 745
2016-05-18 03:51:03,164 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:51:03,164 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:51:03,171 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: DECAA7DD7B2C4E6F9CF51B3E3ED775A3, ordinal: 1
2016-05-18 03:51:03,171 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 03:51:03,172 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn"]
2016-05-18 03:51:03,172 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DECAA7DD7B2C4E6F9CF51B3E3ED775A3, mem on start (mb), free: 159, total: 745, max: 745
2016-05-18 03:51:03,178 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: DECAA7DD7B2C4E6F9CF51B3E3ED775A3, mem on close (mb), free: 158, total: 745, max: 745
2016-05-18 03:51:03,196 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn/_temporary
2016-05-18 03:51:03,196 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.122
2016-05-18 03:51:03,212 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/bufferpipesplatform/testFirstNBufferReverse/firstn
2016-05-18 03:51:03,221 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:51:03,222 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 03:51:03,242 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] executed rule registry: MapReduceHadoopRuleRegistry, completed as: ILLEGAL, in: 00:00.016
2016-05-18 03:51:03,244 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [lower*upper] rule registry: MapReduceHadoopRuleRegistry, found assembly to be malformed
2016-05-18 03:51:03,255 INFO util.Util (Util.java:findMainClass(1374)) - using default application jar, may cause class not found exceptions on the cluster
2016-05-18 03:51:03,256 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 03:51:03,291 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executed rule registry: MapReduceHadoopRuleRegistry, completed as: SUCCESS, in: 00:00.030
2016-05-18 03:51:03,293 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] rule registry: MapReduceHadoopRuleRegistry, supports assembly with steps: 1, nodes: 2
2016-05-18 03:51:03,294 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 03:51:03,312 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting
2016-05-18 03:51:03,313 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] source: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lhs.txt"]
2016-05-18 03:51:03,313 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] sink: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBuffer/firstn"]
2016-05-18 03:51:03,313 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] parallel execution of steps is enabled: false
2016-05-18 03:51:03,314 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] executing total steps: 1
2016-05-18 03:51:03,314 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] allocating management threads: 1
2016-05-18 03:51:03,315 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] starting step: (1/1) ...m/testFirstNBuffer/firstn
2016-05-18 03:51:03,364 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] submitted hadoop job: job_local_0008
2016-05-18 03:51:03,365 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] tracking url: http://localhost:8080/
2016-05-18 03:51:03,371 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lhs.txt
2016-05-18 03:51:03,470 INFO hadoop.FlowMapper (FlowMapper.java:configure(75)) - cascading version: 3.1.0
2016-05-18 03:51:03,470 INFO hadoop.FlowMapper (FlowMapper.java:configure(76)) - child jvm opts: -Xmx200m
2016-05-18 03:51:03,477 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - flow node id: E837BC00289F4DA3898B17A9CB3D4546, ordinal: 0
2016-05-18 03:51:03,478 INFO hadoop.FlowMapper (FlowMapper.java:configure(94)) - sourcing from: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/classes/test/data/lhs.txt"]
2016-05-18 03:51:03,478 INFO hadoop.FlowMapper (FlowMapper.java:configure(97)) - sinking to: GroupBy(test)[by:[{1}:'num']]
2016-05-18 03:51:03,479 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E837BC00289F4DA3898B17A9CB3D4546, mem on start (mb), free: 40, total: 745, max: 745
2016-05-18 03:51:03,481 INFO hadoop.FlowMapper (LogUtil.java:logMemory(59)) - flow node id: E837BC00289F4DA3898B17A9CB3D4546, mem on close (mb), free: 40, total: 745, max: 745
2016-05-18 03:51:03,492 INFO hadoop.FlowReducer (FlowReducer.java:configure(83)) - cascading version: 3.1.0
2016-05-18 03:51:03,492 INFO hadoop.FlowReducer (FlowReducer.java:configure(84)) - child jvm opts: -Xmx200m
2016-05-18 03:51:03,500 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - flow node id: E26FD8BC4FE541F59B70B1616C20C7E4, ordinal: 1
2016-05-18 03:51:03,501 INFO hadoop.FlowReducer (FlowReducer.java:configure(104)) - sourcing from: GroupBy(test)[by:[{1}:'num']]
2016-05-18 03:51:03,501 INFO hadoop.FlowReducer (FlowReducer.java:configure(107)) - sinking to: Hfs["TextDelimited[['num', 'lower']]"]["/opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBuffer/firstn"]
2016-05-18 03:51:03,501 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E26FD8BC4FE541F59B70B1616C20C7E4, mem on start (mb), free: 38, total: 745, max: 745
2016-05-18 03:51:03,507 INFO hadoop.FlowReducer (LogUtil.java:logMemory(59)) - flow node id: E26FD8BC4FE541F59B70B1616C20C7E4, mem on close (mb), free: 37, total: 745, max: 745
2016-05-18 03:51:03,519 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(226)) - deleting temp path /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output/hadoop/bufferpipesplatform/testFirstNBuffer/firstn/_temporary
2016-05-18 03:51:03,519 INFO flow.Flow (BaseFlow.java:logInfo(1504)) - [test] completed in: 00:00.206
2016-05-18 03:51:03,544 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(189)) - copying to local /opt/buildAgent-8.0.3/work/ddea2c91addb6250/apache-1.1.x/build/test/output//hadoop/bufferpipesplatform/testFirstNBuffer/firstn